[Twisted-Python] logging

[Glyph]

On Jun 14, 2013, at 10:48 PM, Christopher Armstrong <radix at twistedmatrix.com> wrote:

> There's... a lot here. I'm overwhelmed by how complex this system
> would be, and I think that end users would be as well. I don't really
> want to put UUIDs into my source code, whether I type them or paste
> them, and I don't want to have to invoke command line tools to figure
> out what those UUIDs in order to be a good developer.

The system isn't really that complex at all.  It's calling uuid.uuid5 once, and it's even doing that internally in a utility function, so you don't need to understand what it's doing.

> I think there's basically no practical benefit over the hierarchical
> "system" + event-identifier system, where:

I tried to lay out the benefits in my other recent reply.

> 1. it's trivial to specify a hierarchical, easy-to-read "system" key that has a small-ish scope

The fact that you have to say "trivial" here suggests it's not actually trivial :).  I think that the amount of energy people initially put into logging is so low that they will often forget to do something like this.  But, even if they remember in the future, we have to deal with the plethora of messages already within Twisted, and every Twisted library, that *don't* do this.

> 2. you think of a unique event name in that small-ish scope and type it out.

How do you know that your event name is unique though, other than running 'grep'?

> I'm beginning to think #1 is the most important of all, but I think
> I'll continue to use event-names to describe all my log statements.

This might be a good practice anyway.

> As I said in my response to Wilfredo, I think it's really important to
> stop specifying the "system" for application code in Twisted. The
> application's code should not be considered a part of the HTTP
> protocol's system. There are also other problems with the way we use
> system, like putting extra random data like request ID in there.


The "system" that Twisted currently specifies is supposed to be the reactor event which caused a particular chunk of code to run.  This is not related to the subsystem within your application where the functionality that is logging is implemented (which, really, still sounds to me like "module name").  I think this could be quite useful, especially in systems where the same functionality is exposed over multiple protocols and disparate events could cause the same subsystem to eventually get called.

However, there are a ton of problems with the way that's implemented; I can't really argue with you here about the current implementation, because it's so poorly done that I think it's next to useless.  With Failure's extended "exception caught here" stacks, it doesn't provide any information other than the traceback.

However, I'd like to bring it back at some point, especially if we can figure out how to have the causality of an event.  Wouldn't it be fantastic to see a trace like this when something went wrong?

<SomeProtocol at 0xFFFF>.dataReceived
  called callLater(x)
  called callInThread(y)
  which called callFromThread(z)
  and that's why your code is running now


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://twistedmatrix.com/pipermail/twisted-python/attachments/20130615/6e0f604b/attachment-0001.html>