custom_log not behaving as expected

[tbhallett]

This is a demonstration of an issue that think isn't fixed but has been closed: #629
It may be that I am not understanding the expected behaviour.

[tamuri]

You're right the logic is not right (or, at least, not intuitive). When applying the log configuration, we match the logger name to its name exactly. If there is no match, it chops off the last part of the logger and checks again. It keeps doing this until it reaches the tlo.methods logger which is the * level warning, in your example. So, tlo.methods.demography.detail doesn't match, but matches the supplied tlo.methods.demography and takes the same level. The idea was that "tlo.methods.demography": logging.WARNING would set all the demography loggers to warning.

It sounds like it's best to explicitly set logging levels as configured. We would lose the functionality above, but perhaps that was not very useful anyway because you're unlikely to turn off (i.e. set to warning) all the loggers for one particular module. Rather, it's more useful to turn off all loggers, then explicitly set the ones that are different.

(Thanks for the test - perfect way to demonstrate the problem!)

[tbhallett]

You're right the logic is not right (or, at least, not intuitive). When applying the log configuration, we match the logger name to its name exactly. If there is no match, it chops off the last part of the logger and checks again. It keeps doing this until it reaches the tlo.methods logger which is the * level warning, in your example. So, tlo.methods.demography.detail doesn't match, but matches the supplied tlo.methods.demography and takes the same level. The idea was that "tlo.methods.demography": logging.WARNING would set all the demography loggers to warning.

It sounds like it's best to explicitly set logging levels as configured. We would lose the functionality above, but perhaps that was not very useful anyway because you're unlikely to turn off (i.e. set to warning) all the loggers for one particular module. Rather, it's more useful to turn off all loggers, then explicitly set the ones that are different.

(Thanks for the test - perfect way to demonstrate the problem!)

Thansks; and yes, I'd agree it'd be most intuitive to set each and every logger individually (apart from the wildcard for every logger).

[mnjowe]

@tbhallett and @tamuri . I will be pushing some commits here to complete this PR and close issues #629 and #1064. The following are the files that will be affected by implementing suggestions made in issue #629

• test_analysis

• analysis_tb

• schisto_analysis

• breast_cancer_analyses

• oesophagealcancer_analyses

• other_adult_cancers_analyses

• calc_5y_survival_following_treatment.py

• prostate_cancer_analyses

[mnjowe]

@tbhallett . I can see that in this branch you are not explicitly turning off demography.detail logger BUT you're in your 2 examples in issue #629. What's your final decision on this. Should we turn off demography.detail explicitly when configuring custom levels or not?

[tbhallett]

@tbhallett . I can see that in this branch you are not explicitly turning off demography.detail logger BUT you're in your 2 examples in issue #629. What's your final decision on this. Should we turn off demography.detail explicitly when configuring custom levels or not?

My view is that it shouldn't matter whether or not a logger is implicitly switched (using '*') or explicitly switched (using its exact name). The only thing that should matter is the order --- subsequent instructions take precedence to earlier ones.

[mnjowe]

okay good!

[mnjowe]

Just observed that test analysis in this PR is failing for not explicitly turning off detailed logger in log configuration. I will uncomment this line if its okay by you, set configure_logging() to private and apply changes to all other affected files.