Repository navigation
logging level consistency #1108
Description
There are still some logging annoyances that make it hard to A) see actual errors in e.g. unittest logging but also B) difficult to decide what to do WRT tuf logging in an application:
- tuf logs things as errors even when things are working fine: e.g. tuf.download and tuf.client.updater do this when a N.root.json is not found
- tuf logs things as errors when it has correctly found a security issue: e.g. BadSignatureError from tuf.client.updater. This one is more debatable but I'd argue the correct response is an exception for the application to handle and no ERROR output: tuf is working exactly as expected in this case
There have been some improvements in this #1083, #1039, #1093, #983 but the core issue is still there: In my opinion ERROR and CRITICAL should only be used when tuf is in an error state, not when it has correctly identified a security issue.
For testing this I suggest modifying e.g. test_update.py:
if __name__ == '__main__':
verbose = '-v' in sys.argv or '--verbose' in sys.argv
loglevel = logging.DEBUG if verbose else logging.ERROR
logging.basicConfig()
tuf.log.set_log_level(loglevel)
unittest.main()
and running python3 test_updater.py TestUpdater (this will only print ERROR and higher levels)
Activity
sechkova commentedon Aug 13, 2020
I am in favour of reworking
tuf.log.pyin general with proper logging settings for a library: logging hierarchy, handlers, formatters, log level etc. and then extend this to the tests and add options for controlling the verbosity on a manual test run.Found another old issue related to this #750
p.s. When I use the word rework I don't mean we should wait for the great TUF rework, I think this can be done on the current codebase.
jku commentedon Aug 13, 2020
tuf.log might have a use case, but to me it looks like application functionality put into a library... As an example if an application for some reason wanted to log only tuf logs into a file it could just do
so
tuf.log.enable_file_logging()saves two lines... The more important point is that I think applications don't want what tuf.log.enable_file_logging() does: they want all of the application logging in one single file so will have to set their own file handler anywayEDIT: This is not an area of expertise for me: I might not understand how Python logging is supposed to work
sechkova commentedon Aug 13, 2020
I was referring to this doc: https://docs.python.org/3/howto/logging.html#configuring-logging-for-a-library.
I imagine we need some sort of common logging configuration in tuf and a documentation for its usage by the applications (this may also mean getting rid of tuf.log and replacing it with some config?) and eventually a way of enabling a verbose debugging output for developers convenience.
Saying this also as a non-expert on Python logging ...
jku commentedon Aug 13, 2020
The actual log level fixes should be fairly quick fixes: there's only 8 instances of
logger.error()in sources and 6 instances in tests that would need to be reviewed. There's 16logger.warning()s as a bonus review task but that's less important.