Create Logging Capabilities and Improve Exception Handling

[timronan]

It seems that all of the logging for Aurora is being print to stdout rather than being written to a logger. There does not seem to be a central logging system in Aurora. A logging system should be developed and used throughout the Aurora pipeline.

[timronan]

aurora/aurora/transfer_function/base.py Example:

         if self.tf_header is None:
             print("header needed to allocate transfer function arrays")
             raise Exception

This print statement should be embedding in the exception. Furthermore, generic exception should be avoided because they can alter the stack trace.
https://stackoverflow.com/questions/2052390/manually-raising-throwing-an-exception-in-python

[kkappler]

@timronan I agree. I have also encountered issues with loggers sometimes slowing down the processing and garbling when running in parallel so we should choose carefully and test performance impact.

I've heard good stuff about this package
https://github.com/Delgan/loguru

an alternative is structlog
https://pypi.org/project/structlog/

or just build from scratch using the logging module

[kkappler]

loguru is already available via our dependency on mth5 so we will use that. We will need to:

• select a default format for the logged messages, the existing default is pretty good, but I would like to configure the logger datetime format so instead of 2023-11-05T10:36:26.785479-0800 for example it just gives 2023-11-05T10:36:26 by default.
  This can probably be done via placing a logger config in the topmost init.py file
  I copied the config from mt_metadata/init.py to aurora/init.py, this should be where the change goes
• Embed the logger into classes as self.logger
  In the imports
  from loguru import logger
  and within def init():
  self.logger = logger
• Recursively search print statements and replace with logger. In some cases I have noted the logging level in the print statement, so we can set the logger level based on that. In the other cases, if it is not clear from the context, just replace with logger.info(). Recursve search can be done with

grep -nR --include="*.py" print

[laura-iris]

@kkappler I made some changes to the logging a couple of weeks ago and haven't been able to get back to it until today. Both in the tests and when I try to run operate_aurora.ipynb, there is a new error popping up:

TypeError: cannot pickle '_hashlib.HASH' object

It stems from a call like this one in operate_aurora: run_summary = mth5_run_summary.clone()

Before I dig into it too deeply, is this familiar to you? Any chance it's something you've come across and fixed in another branch?

The failed tests: https://github.com/simpeg/aurora/actions/runs/6909907354/job/18802116101

[kkappler]

@laura-iris I think I have seen that error occasionally but I don't understand it super well, but do have a guess what is causing the error ...

In run_summary.py the logger is being embedded in the class (self.logger = logger.). I suggested doing this to follow the pattern of MTH5 and mt_metadata, but it may not be appropriate in this case ...

RunSummary has a .clone() method which returns a deepcopy of itself. I suspect that returning a deepcopy of the the loguru logger is the issue.

For example, executing:

from loguru import logger
import copy
copy.deepcopy(logger)

results in TypeError: cannot pickle '_io.TextIOWrapper' object.

Two solutions jump out (although there are probably more elegant workarounds)

Solution 1: Do not embed logger in classes that have a clone() method -- just import the logger at the top and call logger.logginglevel(), instead of self.logger.logginglevel() where logging is needed.

Solution 2: Clone differently; Run_summary.clone() could build a RunSummary() object populated with the same info as in self, without using deepcopy. See the copy() method of ChannelTS in mth5/timeseries/channel_ts.py for example (around line 395).

Implementing Solution 1 will be easier, and solves issue #135 -- Create Logging capabilities -- so I would try that first. Solution 2 seems more about better control of aurora objects, and might be interesting to explore.

[laura-iris]

Thanks for the lead Karl, I opted for solution 1, both for runSummary but also for all of aurora for the sake of consistency. And it now passes all of the jobs successfully!