[Twisted-Python] stdlib logger, loggerFor and filtering events

[Felipe Dau]

On Fri, Jan 05, 2018 at 09:00:41PM -0800, Glyph wrote:
> Just for the record, you don't need to wait for it to be brought up before asking other questions ;-).

Thanks Glyph, I should have asked these a while ago.

> It might be cool to add that, but, if you don't want the standard library's log format, why are you using the standard library log observer?  And wouldn't this be a job for a https://docs.python.org/3.6/library/logging.html#logging.Formatter <https://docs.python.org/3.6/library/logging.html#logging.Formatter> object in any case; what Twisted should be doing is sending the logs on in a more structured format that works with that?

Honestly, I just wanted to display something to stdout (when using the
GUI) and using stdlib's looked like the right way to do that, but
using sys.stdout directly like in your example below would work as
well. And now that I am looking again at what I did, it is probably
the worst thing to do if you are trying to integrate something: set
the message text to the actual formatted text and set the format to
just '%(message)s'. Anything else that used stdlib's would only
contain the message, losing all the rest of the info.

Considering that I just really wanted to display the logs, is there
any advantage on using stdlib's? If so, I would then use the Formatter
as you pointed out, otherwise, I would just pass it to sys.stdout. In
both cases, there wouldn't be a need to pass an event formatter like I
wanted to. Thanks!

> I'm honestly not sure why this exists at all.  It seems like a terrible mistake has happened here, since `_loggerFor` is actually exported in __all__, which should never ever happen.
> 
> From what I can tell, it should be removed, since rather than creating that fairly noisy attr.ib() definition, you could do this:
> 
>     _log = Logger()
> 
> which is a lot more succinct, and has exactly the same effect (do `self._log.info <http://log.info/>(...)`) and there you have it.
> 
> If you could explain why it's great, then maybe we could remove the underscore and add it to the docs.

It is indeed a lot more succinct! The reason I used _loggerFor is that
it creates a logger for any instance it receives. That way, it can
set the namespace automatically when instantiated inside any method of
a class - the constructor, for example. I just do not remember why
creating a separate logger for each instance instead of sharing the
class'. Would there be a reason for that?

But I do think that if you would like to log something but not keep
the instance around, _loggerFor may be useful, as Logger would only
set the namespace based on the module when called from a method.

> Absolutely!  Super glad you brought this up. This was a major part of the design of the new logging system, both to do this, and to also do as little work as possible with messages that were ultimately caught by such filters.
> 
> Here's a quick example program demonstrating the combination of https://twistedmatrix.com/documents/17.9.0/api/twisted.logger.LogLevelFilterPredicate.html <https://twistedmatrix.com/documents/17.9.0/api/twisted.logger.LogLevelFilterPredicate.html> and https://twistedmatrix.com/documents/17.9.0/api/twisted.logger.FilteringLogObserver.html <https://twistedmatrix.com/documents/17.9.0/api/twisted.logger.FilteringLogObserver.html>.

Thanks for the example! Unfortunately I think that is different from
what I tried to describe. Here is an example:

    class ThirdPartyClass:
        a_log = Logger()

        def method_a(self):
            self.a_log.info('Log I want to supress')

            self.a_log.warn('Log I do not want to supress')

    class MyClass(ThirdPartyClass):
        b_log = Logger()

        def method_b(self):
            self.method_a()

            self.b_log.info('Log I do not want to supress')


    MyClass().method_b()

Considering that the class definitions would be in separate files,
they would still have the same namespaces. This would be a case where
the libraries you are using are a bit noisy and you would just want to
display warnings+.

I believe that as there is a reference to a_log, it would be possible
to change the namespace, but if the third party class used
_loggerFor().info() instead, then that would not be possible, right?

This actually happens with Factory.doStart() [0] once that is
subclassed, you cannot differ its  namespace from your class'.

These would be situations where very few people would come across or
maybe I still have to learn more about the logging system, but I
thought it would be worth to be discussed.

Thanks,
-Felipe

[0]: https://github.com/twisted/twisted/blob/trunk/src/twisted/internet/protocol.py#L75