Logging and printing are completely decoupled

[Baharis]

Currently, Instamatic has at least three different text feedback mechanisms to inform user about the current status of Instamatic:

• The terminal instamatic was run from (includes stdout and stderr) – receives information from print statements and exceptions;
• The console widget (includes stdout and stderr) – captures sys.__stderr__ and sys.__stdout__, ends up being a subset of terminal information;
• The main Instamatic log file (include log function calls) – captures any log.info, log.warn calls but not stdout nor stderr.

Since information that is logged never appears in the consoles and vice versa, there is often a risk that the user will not be aware of important issues going on Instamatic. Vice versa, the print statements and errors that make it to the visible GUI can be absent from log. Because of that, using a handy regex ^\s*log.*\n^\s*print we can find some places where print and log functions are duplicated (mostly in server declarations):

    log.info(f'Indexing server (DIALS) listening on {HOST}:{PORT}')
    log.info(f'Running command: {EXE}')
    print(f'Indexing server (DIALS) listening on {HOST}:{PORT}')
    print(f'Running command: {EXE}')

    logger.info('Connection to microscope released')
    print('Connection to microscope released')

    log.info(f'TEM server listening on {HOST}:{PORT}')
    print(f'TEM server listening on {HOST}:{PORT}')

When removing the foreign debug statements from the log in #111, I had an idea and found a potential way to unify the print statements. With some handlers and decorators implemented, there would never be a reason to use a print statement. All log statements could be captured into the stdout / stderr stream, to the Console widget, and to a file handler passing them to the log file. They could be configured in such a way that warnings are displayed in console, info + debug logged only. Or, with -v, maybe info could be also shown in Instamatic gui and debug reserved for log only? I do not know – but I was wondering whether this is something that would be considered a code improvement, or maybe is there is y'all eyes a valid reason to keep print and log separate?

[stefsmeets]

The thinking here is that the logger captures verbose information that are not immediately relevant, but can be looked at at a later stage for debugging. The print statements (which are redirected to the gui) are used to notify the user of the program flow.

The print statements also transfer nicely for interactive use and in a jupyter notebook.

[Baharis]

I was thinking about cases where the information needs to be doubled since it is useful both in print and in log. Maybe a log.warn or log.error should be also automatically included in print, for example in JoelMicroscope.setStagePosition:

            if x is not None and abs(nx - x) > 150:
                logger.warning(f'stage.x -> requested: {x}, got: {nx}')

As for print statements, the logging statements would write to the standard output. This can be achieved by logging.getLogger().addHandler(logging.StreamHandler()) (see SO) or something similar. print could be even alias for log.info or log.warn.

I can see though that this could cause problems. I imagine myself asking myself: "how do I now log a warning without printing it to the console"...

This thought came to me when I was writing something on the side branch and got slightly confused. In fact I might be overthinking it and looking for holes where there are none. I wanted to float the idea, but given even I am not fully sure about it right now, I will close the issue for the time being.