Incoherent logger output streams

[thomasgoodfellow]

The default seal5 logger (logging.py) logs both to stdout and .seal5/logs/seal5.log, however many of the daughter modules log directly to the Python default of stderr (because they get the Python logger directly):

logger = logging.getLogger("seal5_converter")

This means that their output is visible in the terminal but not captured in the log file.

As a user the distinction between different seal5 components is rather arbitrary, e.g. that the LLVM file compilations are in stdout + file but the details of transformations are only in stderr, and will also be subject to change (more daughter processes for better parallelism, etc). I’d prefer that it was coherent, i.e. in a single stream and strongly chronological (redirecting stderr to stdout and redirecting stdout to a file would usually achieve this, however the pipe redirection used when launching the daughter processes prevents it).

Since seal5 already has an explicit log file the easiest option could be simply using that:

-logger = logging.getLogger("seal5_converter")
+from seal5.logging import get_logger
+logger = get_logger()

That does have the mild drawback of losing the specificity of the “detect_inouts” entity name (not that this is usually visible?), but maybe that could be supported as an optional parameter to seal5.get_logger()

[thomasgoodfellow]

FWIW I have a crude patch of substituting the seal5.logger::get_logger() as above everywhere, which seems to work

[PhilippvK]

@thomasgoodfellow I can also live with a single unnamed logger. We should check the fmtstring though, and consider printing the file names to identify the source of the logging statements. Ideally this would be available in the logging file on disk but not n the stdout as it could get way to verbose…

[PhilippvK]

Feel free to provide/submit the patch, I am happy to apply/merge it!

[PhilippvK]

I am not sure what will happen if we just seal5.logger::get_logger() in subprocesses, because that function relies on logging levels and files which are configured in the settings.yml which is usually not available in the transforms… I think the idea of the current approach was to capture the stdout of the non-seal5 loggers in the subprocess and then forward it to stdout&file with the configured levels. The desired verbosity could be passed to the subprocesses by the --log flag available in all transforms.

I think I need to have another look at this to figure out which approach works best for both python- and subprocess-based passes.

[thomasgoodfellow]

Agreed; looking at the subprocess.Popen() handling it certainly seems that stderr should have been captured. I'll take another look