PSyclone sets log level for root logger, not the PSyclone logger

[hiker]

The PSyclone command line options (and their default, especially logging off) are set on the root level python logger, NOT the PSyclone logger. As a result, by default PSyclone will disable all logging output, which resulted in logging message from application scripts (information about errors) being suppressed.

Instead, PSyclone should only set the logger details for PSyclone based logger (which will allow the application to decide what to do with their logging).

Marking this as bug, since it apparently causes LFRic transmutation scripts to hide all error messages, and there might be quite a few of them :(

[hiker]

We also need to think what to do about fparser logging. It might be useful to set this to the same level as psyclone? Or maybe add another command line option?

[hiker]

@arporter , @sergisiso , @LonelyCat124 two questions:

1. what is the preferred output format? ATM I am using

   '%(name)s - %(levelname)s - %(message)s'   --> which produces e.g.
   psyclone.configuration - ERROR - Attempt to overwrite unknown configuration option: 'a=b'.
   

   but I could also add exact time of the event?
2. what is the preferred way of handling fparser logging? I could either set this to the same level (and same output file if requested) as the PSyclone logging. Or I could add separate command line option to manage fparser logging.

[LonelyCat124]

My understanding was using __name__ should get the relevant logger? Instead of logger_psyclone = logging.getLogger("psyclone") everything I saw suggested best practice was to use logging.getLogger(__name__) always. But I see that the level could be set incorrectly globally. I'm not sure we should change the fparser log level in PSyclone, if we need that updating we maybe need to do something in fparser to enable that.

I was also happy enough with the default format (i.e. BASIC_FORMAT = "%(levelname)s:%(name)s:%(message)s" ) - is there any reason to change it?

Edit:
Think maybe I'd seen some basic introduction stuff so switching to logging.getLogger("psyclone") is probably fine, but it needs to be changed in a lot of places now.

[hiker]

Loggers in python are hierarchical. So, if you have logging.getLogger(__name__), the name might be psyclone.psyir.nodes.node (or so). The loggers pass events up the hierarchy, so anything logged from psyclone.psyir.nodes.node will go to psyclone.psyir.nodes, the psyclone.psyir, then psyclone. So, the psyclone logger is the top-level logger for everything in PSyclone.

After the hierarchical loggers comes the default/root logger. What was done previously was to disable/change the root logger. This than affect any logging message, not only PSyclone, but also fparser, and the application scripts called from PSyclone. A log message from a scrip would either be immediately sent to the root logger (logger.warning(...) etc), or (unless they defined their own log handler) end up at the root logger.

I have changed generator.py to set up the psyclone top-level logger, and leave the root logger unmodified. Any message handled by the psyclone logger will not go to the root logger, so the psyclone logger will discard messages, and/or log them to stderr or a file.

Everything else should indeed use getLogger(__name__) (which will always have psyclone as top-level). And it would allow us (if we ever need it), to say treat messages from psyclone.psyir different from messages from psyclone.domain.lfric (or whatever). Very likely an overkill, but it's the proper way to use them.

And __name__ in generator would give psyclone.generator, so it would only affect messages from this file itself.

Thanks to Fab for teaching me all about logging (well, more precisely to odd handling in Fab which made log messages disappear).

Re format: no preference. While playing with options and what else can be done, I noticed the time stamp - and it look incredible professional :) But then I realised that it is likely also entirely useless :)

I'll remove the format, and will handle fparser and psyclone log levels identical, feel free to comment in the PR :)

[hiker]

I was also happy enough with the default format (i.e. BASIC_FORMAT = "%(levelname)s:%(name)s:%(message)s" ) - is there any reason to change it?

Ah, now I remember: the default is different, the handler will just use %(message)s, i.e. no level or name at all. I'll set it to your suggested default.