[Twisted-Python] logging

Hynek Schlawack hs at ox.cx
Sat Jun 15 01:18:03 MDT 2013

Am 15.06.2013 um 08:18 schrieb Christopher Armstrong <radix at twistedmatrix.com>:

>> As far as actual *proposals* go, I have these ones, that are all independent:
>> 1. include all keyword arguments in log output without requiring
>> specifying the formatting in the string
>> 2. make it really easy to specify the "system"
>> 3. stop affecting the "system" of application code based on the
>> framework code that's running the application code (i.e., don't use
>> callWithContext to specify the system any more)
>> Of these, I think #2 and #3 have the most benefit; I can do #1 with my
>> own logging statements just fine, and while IMO it'd be nice if the
>> whole world adopted a nice identifier-based system, the lion's share
>> of the benefit comes from my use of it consistently in the
>> application's codebase.
> This conversation has gotten pretty sprawling; time to reel it in with
> some code.
> What do you think of this for an API that meets in the middle?
> https://gist.github.com/radeex/5787124
> This example implementation only concerns itself with the points under
> debate right now; obviously it's completely unusable in general. But
> anyway:
> 1. it supports English logs
> 2. it doesn't require you to specify a formatting if you want to just
> log a bunch of data
> 3. it makes it easy to specify a system (both manually and based on
> the module your code is in)

I’ve held back from this discussion so far because it seemed to me that I always missed some part of the discussion to fully understand what you’re all talking about. I would like to comment on this concrete proposal though before I hold my peace forever. (NB I’m not replying just to Christopher but try to address everything I saw on the thread so far – I like most of his proposal.)

I find that there’s some kind of false dichotomy brought up in this discussion and API and output are somewhat muddled together a bit (maybe I’m just misunderstanding though – that’s why I didn’t comment until now).

I personally like my logs 100% structured (except for Exceptions) and still be able to “comment” on events in plain English if I need to.

And I don’t see why comments/events should be special case on output (square brackets in this example). If you have an event called user_error, you can always add a key called error for another “symbol” or just an error_msg if you insist on English. When looking for a certain type of user_error, you simply write an AND clause in your logging software (Kibana or whatever). It’s pretty easy to keep *that* consistent across applications.

For example, *my* log would look like this:

event=user_error peer= error=pebkac

If the programmer in question hadn’t enough logging pain in their life to see that’s reasonable, they can always do:

event=user_error peer= error_msg='Problem exists between keyboard and chair.'

Still perfectly parseable, perfectly readable. And with {!r} easy to achieve. A nice API I would like to have be:

log('user_error', peer=self.transport.getPeer().host, error_msg='Problem exists between keyboard and chair.') – and log figures out itself if it needs to quote. I could also live with them all quoted, i.e.:

event='user_error' peer='' error='pebkac'

to have less special cases.

I hope that makes some sense, the point I’m trying to make that events don’t need to be distinct by themselves. If you enforce that, you’re forcing structure on them which you could spread over multiple fields that are *much* more pleasant to parse.


P.S. For convenience, I usually write a log method in Twisted protocols that prepends the messages with state data, peer IP etc, but that JFTR.

More information about the Twisted-Python mailing list