Buffer in-toto logging while testing and show on fail

[lukpueh]

Please fill in the fields below to submit a pull request. The more information
that is provided, the better.

Fixes issue #:
Related to #171

Description of the changes being introduced by the pull request:
In #183 we disabled all logging by replacing in_toto's base logger's StreamHandler with a NullHandler while testing. While this eliminated test log inundation, it was not helpful to troubleshoot failing tests, such as #171 .

Ideally, all logging output is buffered and only displayed in case a test fails. Python's unittest framework provides such a buffer option, which we already use. It does this by overriding sys.stdout and sys.stderr before running tests.

This PR implements a custom logging StreamHandler for our tests that always uses the currently available sys.stderr (e.g. as overridden by unittest) .

Please verify and check that the pull request fulfills the following
requirements:

• The code follows the Code Style Guidelines
• Tests have been added for the bug fix or new feature
• Docs have been added for the bug fix or new feature

[coveralls]

Coverage remained the same at 100.0% when pulling 3df7196 on lukpueh:show-log-on-test-error into ac225cd on in-toto:develop.

[lukpueh]

This PR also adds some additional debug statements to troubleshoot #171 (see 3df7196). They may be removed once #171 is fixed.

[awwad]

Python's logging guidelines for libraries "strongly advise" against defining your own handlers since it can interfere with upstream logging, and recommend the null handler route you seem to have been taking previously. (The same goes for the the Python2 logging guidelines :P) With that said, this is a really neat idea.... Perhaps you should do the overriding in test modules? This is a point that stands for TUF, too.

Comment's a bit early -- still looking, so pardon me if I've missed something there. This PR may be a good opportunity to think through how to do this in an application-friendly, debug-helpful, and not-noisy way.

[lukpueh]

@awwad, thanks for your comment! IMHO, it's very much fine what we are doing here, because it only affects testing and not library use.

However, independently of this PR, we do add a StreamHandler to the in-toto base logger, which, according to the Python guidelines, we probably shouldn't.
I suppose we could change that to add a NullHandler per default and replace it with a
StreamHandler only if in-toto is used from the command line or if settings.DEBUG == True. On the other hand, this does not happen under the hood, but is documented transparently in our log.py module. What do you think?

Btw (not pointing fingers), uptane also has a StreamHandler for any library use and tuf at least when importing using repository_tool.py as a library. :P

[awwad]

The comment's outside of the scope of this PR, but log.py does seem to set a handler for general use](url), no?

Like I said, though, the same goes for TUF: we set non-null handlers. (I guess I'm slightly less worried about Uptane's Python reference implementation's use as a library, but it's true there, too.) I'm inclined to agree that CLI, testing, and debug are the situations in which you (and I) should set non-null handler.

Otherwise, this PR looks good to me. Tidy code 👍

(Also, I like your test output. I wonder if I should adjust the TUF output in a similar way, but I do want to retain detailed docstrings for some test functions, so I guess I'd have to run TextTestRunner differently....)

[lukpueh]

The comment's outside of the scope of this PR, but log.py does seem to set a handler for general use, no?

Exactly, that's what I was referring to above in "independently of this PR bla bla bla...".

On a side note, in the datadog integration we did have a problem with in-toto and TUF logging that came out of nowhere. But the problem was not related to our StreamHandlers but rather to a non-namespaced root StreamHandler (created by pip) to which our logs got propagated, which would have been the case even with a NullHandler in place. :)

I suggest we deal with the log handlers when they become a problem again. Thanks for reviewing!