[Twisted-Python] logging

[Glyph]

On Jun 17, 2013, at 5:48 PM, James Y Knight <foom at fuhm.net> wrote:

> I'm surprised that a thread with 32 messages about logging doesn't seem to have once mentioned windows events, osx structured syslog, or systemd journal as important design points. 

As it happens I was discussing exactly that!  In a sense, they're just observers, and it's just a matter of persisting whatever fields are present to the various backend systems.

> Maybe people are thinking about such things in the background but it looks a lot like this is being designed in a vacuum when there's plenty of air around.

So yes, I, at least, have been thinking about them, abstractly.  But you raise a good point: we should be talking about them concretely and making sure that we could at least take advantage of the facilities they offer before we finalize anything.

However, then you fail to discuss them concretely :).  Do you have any practical experiences with these systems that would indicate what features would be useful to abstract over or how they should be exposed?

> And, no sane sysadmin should ever want a twisted-specific log file format or to write custom python log filters. That's crazy. Gimme a verbosity knob and the ability to emit structured log events to existing systems, with a fallback plain text file format. Great.

There is a reason why we should support such a thing, by which I mean a "Twisted specific" format in the sense of something like line-delimited JSON (or whatever).  We have an API for emitting log messages, and an API for observing log messages as they occur.  If someone were to use the latter API to produce some software that does a useful thing, it would be very good to have a built-in, platform-independent format for logs that could easily be reconstituted into something that is a reasonable enough facsimile of the information available at runtime.  That way log analysis using our log-analysis API would be possible offline without rewriting your online analysis tool to consume input from systemd, ASL, and windows event log instead of a Twisted observer.

I agree that our existing text format is basically pointless, but there are two reasons to keep it around.

First, it seem to be something that some sysadmins expect; there's definitely an archetype of sysadmin who prefers everything to be in "plain text" so they can run their perl scripts over it; someone more comfortable with regexes than structured data.  Maybe you wouldn't characterize these people as sane, but they're definitely extant, and some of them, at least, run Twisted services.

The second reason to keep the text format around is that even sysadmins who would _prefer_ structured data in an existing log facility have probably written some gross hacks to deal with twistd.log by now because we haven't previously exposed it in any meaningful way, so we need to preserve the existing format for some amount of compatibility.

My hope is that we can convince them to upgrade to some sort of structured system on its own merits, at the very least a log file that can be parsed reliably.

> The prime goal, it seems to me, should be exposing features useful for facilities present in existing log systems.

That's certainly a goal, but it's a little longer term than the prime goal, which is to present a logging API that encourages any structure (and filtering based on that structure) to be expressed at all.  It would of course be much better if that structure were aligned with existing logging systems.  If we had logging with structured messages already, there'd at least be a hope of writing a somewhat useful translator to these back-end systems.  As it is, sadly, we're going to have to touch almost every log.msg() call within Twisted to get any useful information out.

> And having a logging system which doesn't even support a basic log level is just silly. Hopefully the new system can at least have that.

The new system being proposed does have log levels.  (And, for that matter, so does Twisted currently; we've had log levels for compatibility with stlib Python logging forever.)

I still don't think that log levels are a particularly useful bit of structured information, and this is one reason I want to have our own structured format, to make sure that the other bits of more useful information hang around for longer in a useful form.  

I've been convinced that it's unhelpful to be contrarian and omit information which can be useful to a whole bunch of other systems and existing practices.  (Also, the effort described therein is way too ambitious to do in any reasonable time frame unless someone wanted to make logging in Twisted their full-time job for at least a year.)  Plus, I've seen some utility in Calendar Server from the use of the intersection of "level" and "namespace", although blanket application of log levels is still a crapshoot.

(So, other than those caveats, everything I said about identifying the audience and intent of messages in <http://glyph.twistedmatrix.com/2009/06/who-wants-to-know.html> still applies.)

Do all the systems you mentioned have the same set of log levels, or will there be some need to harmonize them?

-glyph
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://twistedmatrix.com/pipermail/twisted-python/attachments/20130617/380aaed4/attachment-0001.html>