[Twisted-Python] logging

[Christopher Armstrong]

On Fri, Jun 14, 2013 at 6:20 PM, Wilfredo Sánchez Vega
<wsanchez at wsanchez.net> wrote:
> Christopher Armstrong wrote:
>
> logger.msg("scheduled-compaction-failed")
>
>   I'm confused.  You don't want to use English, but… why not change your
> hyphens to spaces and call it a day?  Also, why did it fail?

Because as soon as you introduce spaces, you're probably going to
introduce capitalization and punctuation as well, and then all of a
sudden your log statements are a lot harder to filter.

>   Here's a fuller example, modified to fit the API I'm using:
>
> from twisted.python.log import Logger
>
> log = Logger()
>
> try:
>   scheduleCompaction(…)
> except Exception as e:
>   log.error("Scheduled compaction failed: {why}", why=e,
>             id=2C09A260-184C-44F9-B11F-E12B26B26C9C)
>
>
>   Some things to note about this:
>
>   - `log = Logger()` does some magic so that log.namespace is the name of
> your module "spacecombat.server.db".  So, your "system" identifier is
> perhaps covered by that, with no typing.

I like making it trivial to specify the system, but I don't think it's
a good idea to do it based on the module name. Code moves around a
lot, and you may have lots of implementation modules for one logical
system. I think it's fine to just have people say 'log =
Logger("spacecombat.server.db")' at the top of their file.

>   - I have a format string instead of a fixed string.  An observer emitting
> text can emit something informative.  I know you think that text logs aren't
> useful, but a lot of us do.  And you can use observers that ignore this
> format.  Maybe there's an argument for making the format optional...

I think the argument about English is separate from the argument about
whether we should require specifying the interpolation in the strings.

>   - Formatting isn't done here, so... cheap if you don't use it in any
> observers.

>   - I added a GUID id argument since you seem keen, I think on a unique key
> to identify the code point at which the message is logged.  It's not used in
> the format, but an observer storing things in a DB could use that to take
> you straight to the relevant code, or identify multiple instances of that
> message, etc. if the format string isn't how you want to do that.

I don't think it's worth coming up with some kind of GUID-based
system, because I don't think anyone's going to go to the trouble to
use it, and I think it basically offers no practical benefit over
simple event names.

So, again, I want to reiterate that I wasn't really proposing
mandating an event name and enforcing these rules on it.

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.

--
Christopher Armstrong
http://radix.twistedmatrix.com/
http://planet-if.com/