Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Option to show log output when running individual tests #1093

Closed
joshuagl opened this issue Jul 30, 2020 · 4 comments · Fixed by #1145
Closed

Option to show log output when running individual tests #1093

joshuagl opened this issue Jul 30, 2020 · 4 comments · Fixed by #1145
Labels

Comments

@joshuagl
Copy link
Member

In #1083 @sechkova dug into the current logging behaviour and documented that

  1. Executing the tests by aggregate_tests.py buffers the output on a successful run.
  2. Executing a test "by hand", the logging output remains hidden until an error occurs.

IMNSHO we should only buffer individual tests run by hand when the -b command-line option is passed.

@jku
Copy link
Member

jku commented Aug 3, 2020

I'd prefer that the test log level was easily modifiable (like V=DEBUG python3 test_updater.py) so the default could be practically silent but tricky issues were easy to debug.

@joshuagl
Copy link
Member Author

joshuagl commented Aug 4, 2020

That would also be fine, so long as we can toggle easily.

@jku
Copy link
Member

jku commented Aug 6, 2020

2. Executing a test "by hand", the logging output remains hidden until an error occurs.

This is untrue AFAICT: the output is same on error or no error (in an error case there might be more high level output of course, but same logger levels get printed). We do not initialize logging at all when tests are run individually: It think the default is to only print WARNING and above.

We could initialize the logging based on a env variable (or maybe an argv option) in each if __name__ == '__main__': ... but I would expect this was an issue where python folks would have a Best Practice?

@joshuagl joshuagl changed the title Show log output when running individual tests Option to show log output when running individual tests Aug 10, 2020
@jku
Copy link
Member

jku commented Aug 13, 2020

I'll open another issue on logging in general but leaving an example that should work right now here:

if __name__ == '__main__':
  verbose = '-v' in sys.argv or '--verbose' in sys.argv
  loglevel = logging.DEBUG if verbose else logging.CRITICAL
  logging.basicConfig()
  tuf.log.set_log_level(loglevel)

  unittest.main()

Notes:

  • this is only for running test files manually: it does not and should not affect test runners. They set their own logging policies
  • this slightly abuses unittest CLI: '--verbose' is actually unittest argument which we're now using as well
  • had to set default level to CRITICAL since we currently log so much on ERROR (issue logging level consistency #1108 )
  • tuf.log.set_log_level() seems not that useful: I'd just want to set root logger level and expect all components to follow that (and could do logging.getLogger('tuf').setLevel() if I wanted more control) but tuf forces me to call tuf.log.set_log_level() because there is a default that is not logging.NOTSET. Or is this how libraries are supposed to do logging in python?

@jku jku mentioned this issue Sep 15, 2020
3 tasks
jku pushed a commit to jku/python-tuf that referenced this issue Sep 15, 2020
all test_*.py files now accept zero or more '-v' to increase tuf
logging level. The default is now ERROR.

Default == ERROR
"-v"    == WARNING
"-vv"   == INFO
"-vvv"  == DEBUG

Example to run a single test with DEBUG level:
  python3 test_updater.py -vvv TestUpdater.test_4_refresh

Also make test_log.py restore the log level it modifies during test.

Fixes theupdateframework#1093

Signed-off-by: Jussi Kukkonen <jkukkonen@vmware.com>
jku pushed a commit to jku/python-tuf that referenced this issue Sep 15, 2020
all test_*.py files now accept zero or more '-v' to increase tuf
logging level. The default is now ERROR.

default: ERROR
"-v":    ERROR, but unittest prints test names
"-vv":   WARNING
"-vvv":  INFO
"-vvvv": DEBUG

Example to run a single test with DEBUG level:
  python3 test_updater.py -vvvv TestUpdater.test_4_refresh

Also make test_log.py restore the log level it modifies during test.

Fixes theupdateframework#1093

Signed-off-by: Jussi Kukkonen <jkukkonen@vmware.com>
MVrachev pushed a commit to MVrachev/tuf that referenced this issue Sep 28, 2020
all test_*.py files now accept zero or more '-v' to increase tuf
logging level. The default is now ERROR.

default: ERROR
"-v":    ERROR, but unittest prints test names
"-vv":   WARNING
"-vvv":  INFO
"-vvvv": DEBUG

Example to run a single test with DEBUG level:
  python3 test_updater.py -vvvv TestUpdater.test_4_refresh

Also make test_log.py restore the log level it modifies during test.

Fixes theupdateframework#1093

Signed-off-by: Jussi Kukkonen <jkukkonen@vmware.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants