Refactor loggers module

[truth-quark]

The amami logging module is ~200 lines of code, providing custom log formatting with colours & indenting. This is quite a lot of additional code for the feature, which introduces future maintenance.

Core question: what requirements or justification exist for custom log formatting for a command line or scripted tool?

Python's existing logging can be configured as per this example: https://docs.python.org/3/howto/logging.html#configuring-logging

I propose 2 options:

1. Simplify the custom logging as per the example (change msg format & indenting)
2. Remove the custom logging module & use the normal logger = logging.getLogger(__name__) in other modules

---

Other questions:

• Is formatting logging required, especially if the logs will eventually be directed to a file?
  • redirecting formatted logging to a file results in additional escape strings which obscure content

The logging module also has some problems:

• Control flow is included in logging for error & critical logs. Control flow should be moved back to the calling code.
• Several custom logging "methods" are declared outside a logging class, then patched into the logger at runtime. Check the correct fix is to subclass the default logger & override the methods (e.g. https://stackoverflow.com/questions/39492471/how-to-extend-the-logging-logger-class) or adapting the formatters.
• Two custom_warning() funcs exist (this will be automatically fixed if the logger is subclassed as above)

[atteggiani]

• Control flow is included in logging for error & critical logs. Control flow should be moved back to the calling code.

What do you mean by control flow? Can you make a specific reference to the code?

• Several custom logging "methods" are declared outside a logging class, then patched into the logger at runtime. Check the correct fix is to subclass the default logger & override the methods.

Can you please provide an example making specific reference to the code?

• Two custom_warning() funcs exist (this will be automatically fixed if the logger is subclassed as above)

Ooops did not realize that they were called in the same way. Yes, the fix above would solve the issue, but I will still change the name of the latter one to make it more explicative.

[truth-quark]

Control flow is a reference to how the code is executed (e.g. https://en.wikipedia.org/wiki/Control_flow). The custom logging includes sys.exit() calls, making the logging module responsible for exiting:

def custom_critical(self, msg, *args, **kwargs):
    # ... some code ...
    if self.isEnabledFor(logging.DEBUG):
        msg += "\n" + indent(traceback.format_exc(), self.TABS)

    sys.exit(self._log(logging.CRITICAL, msg, args, **kwargs))    # logging controls program exec

The logging module should only concern itself with logging & leave exceptions/exit conditions to high level application logic. Also, if someone wants to log an error & handle it, they can't as the program will exit.

[truth-quark]

• Several custom logging "methods" are declared outside a logging class, then patched into the logger at runtime. Check the correct fix is to subclass the default logger & override the methods.

Can you please provide an example making specific reference to the code?

Yep, here's a function with a method like signature: https://github.com/ACCESS-NRI/amami/blob/dev/amami/loggers/__init__.py#L28-L39

Then it is manually pathed onto the custom logger: https://github.com/ACCESS-NRI/amami/blob/dev/amami/loggers/__init__.py#L175

A neater solution with sub-classing is something like:

class CustomLogger(logging.Logger):
    def debug(...):  # override the default debug
         # custom logging

    def info(...):
         # custom logging

[atteggiani]

Control flow is a reference to how the code is executed (e.g. https://en.wikipedia.org/wiki/Control_flow). The custom logging includes sys.exit() calls, making the logging module responsible for exiting:

def custom_critical(self, msg, *args, **kwargs):
    # ... some code ...
    if self.isEnabledFor(logging.DEBUG):
        msg += "\n" + indent(traceback.format_exc(), self.TABS)

    sys.exit(self._log(logging.CRITICAL, msg, args, **kwargs))    # logging controls program exec

The logging module should only concern itself with logging & leave exceptions/exit conditions to high level application logic. Also, if someone wants to log an error & handle it, they can't as the program will exit.

This was chosen on purpose. I understand your point but:

• If we don't make the logger responsible for exiting we would have to manually call sys.exit() every time we log an error.

• Also, if someone wants to log an error & handle it, they can't as the program will exit.

  If we want to handle an "error" internally, we still use the try block without logging the error. If we want to let the user know about an issue, but still continue with the program, we don't log an error, but a warning.

These are the reasons why I chose this implementation.

[truth-quark]

The logging module should only concern itself with logging & leave exceptions/exit conditions to high level application logic. Also, if someone wants to log an error & handle it, they can't as the program will exit.

This was chosen on purpose. I understand your point but:

• If we don't make the logger responsible for exiting we would have to manually call sys.exit() every time we log an error.

• Also, if someone wants to log an error & handle it, they can't as the program will exit.

  If we want to handle an "error" internally, we still use the try block without logging the error. If we want to let the user know about an issue, but still continue with the program, we don't log an error, but a warning.

These are the reasons why I chose this implementation.

This isn't typical practice & violates elements of software design. e.g. Exit logic in the logger violates the single responsibility principle: https://en.wikipedia.org/wiki/Single-responsibility_principle

There is a solution. The main logic can be refactored to throw exceptions, then implement a single higher level error handler to capture & exit cleanly where required.

[atteggiani]

Yeah I understand your point. Let's maybe discuss some solutions in a meeting.

[truth-quark]

I updated the issue text to reflect additional thoughts on logging. My preference would be to remove custom logging in favour of Python's defaults.

[atteggiani]

Thank you for updating the text. I might have answered a few points already above, but I will repeat the answers so you have them all in one place:

Core question: what requirements or justification exist for custom log formatting for a command line or scripted tool?

Python's existing logging can be configured as per this example: https://docs.python.org/3/howto/logging.html#configuring-logging

I propose 2 options:

Simplify the custom logging as per the example (change msg format & indenting) Remove the custom logging module & use the normal logger = logging.getLogger(name) in other modules

Colours and indentations were implemented to make logged output more clear to the user. The custom formatting is needed for both colours and indentation to be displayed (to my knowledge, the built-in logging configuration does not provide any of those functionalities)

Is formatting logging required, especially if the logs will eventually be directed to a file? redirecting formatted logging to a file results in additional escape strings which obscure content

We need to check how logging to a file will behave. Right now, I think logging messages always logs to the terminal even when STDOUT/STDERR is redirected to a file. This needs to be properly handled. For the formatting, I would keep indentation also when logging to a file. The file should not have escape strings in it. It should have the same formatting as we want in the terminal (e.g. any \n character should be effectively a new line in the file). I think this would already happen, but we need to double-check. For colours, I am not sure if I would keep them or not when logging to a file. In any case, I think the best option is to provide a global option (something like --no-colours) to prevent coloured logs.

Control flow is included in logging for error & critical logs. Control flow should be moved back to the calling code.

I understand this violates the single responsibility principle, but I don't think having to manually add a sys.exit() line after each error logging is a valid solution. We need to find a solution that still automatically exits after logging an error.

Several custom logging "methods" are declared outside a logging class, then patched into the logger at runtime. Check the correct fix is to subclass the default logger & override the methods (e.g. https://stackoverflow.com/questions/39492471/how-to-extend-the-logging-logger-class) or adapting the formatters.

Yes this can be easily done.

Two custom_warning() funcs exist (this will be automatically fixed if the logger is subclassed as above)

This has already been solved by renaming the second function.