[Twisted-Python] logging question
I'm using twisted.python.log to do some logging in an application. It's formatting the output like "<date> [-] <mymessage>". I've seen in some of my other applications that the contents of "[-]" can change depending on how the code is reached. Is there a way that I can customize this in my application? I'd like to change the contents to reflect the particular object that is generating the log message. -- Jeff Ollie
On Tue, Nov 15, 2011 at 11:36 AM, Jeffrey Ollie <jeff@ocjtech.us> wrote:
I'm using twisted.python.log to do some logging in an application. It's formatting the output like "<date> [-] <mymessage>". I've seen in some of my other applications that the contents of "[-]" can change depending on how the code is reached. Is there a way that I can customize this in my application? I'd like to change the contents to reflect the particular object that is generating the log message.
If you pass a 'system' kwarg to log.msg then it will go in that field. log.msg("hi", system="stuff") results in <date> [stuff] hi In my applications I usually hack the default log context stuff to disable the inferred systems because they end up just being misleading and inconsistent anyway. -- Christopher Armstrong http://radix.twistedmatrix.com/ http://planet-if.com/
On 11/15/2011 8:57 AM, Christopher Armstrong wrote:
If you pass a 'system' kwarg to log.msg then it will go in that field.
log.msg("hi", system="stuff") results in <date> [stuff] hi
This triggered me to look further into what LogPublisher.msg does, since I've long wanted to customize the format of the output. I found what I wanted in http://twistedmatrix.com/documents/current/api/twisted.python.log.ILogObserv... : In msg(), the message gets added to the kwargs dictionary (along with a timestamp called 'time'), and that dict is passed to LogObserver.emit, which uses textFromEventDict() to create what's actually output. This dictionary has the following keys recognized by textFromEventDict: * |message|: A |tuple| of |str| containing messages to be logged. * |system|: A |str| which indicates the "system" which is generating this event. * |isError|: A |bool| indicating whether this event represents an error. * |failure|: A |failure.Failure| <http://twistedmatrix.com/documents/current/api/twisted.python.failure.Failure.html> instance, required if the event is an error. * |why|: Used as header of the traceback in case of errors. * |format|: A string format used in place of |message| to customize the event. The intent is for the observer to format a message by doing something like |format % eventDict|. So, for example, you could do log.msg(format='....', foo='stuff', bar='things') I suggest that this be added to the documentation string of the msg() method and http://twistedmatrix.com/documents/current/core/howto/logging.html. -- Don Dwiggins Advanced Publishing Technology
On Wed, Nov 16, 2011 at 2:27 PM, Don Dwiggins <ddwiggins@advpubtech.com>wrote:
** On 11/15/2011 8:57 AM, Christopher Armstrong wrote:
If you pass a 'system' kwarg to log.msg then it will go in that field.
log.msg("hi", system="stuff") results in <date> [stuff] hi
This triggered me to look further into what LogPublisher.msg does, since I've long wanted to customize the format of the output. I found what I wanted in http://twistedmatrix.com/documents/current/api/twisted.python.log.ILogObserv...:
In msg(), the message gets added to the kwargs dictionary (along with a timestamp called 'time'), and that dict is passed to LogObserver.emit, which uses textFromEventDict() to create what's actually output. This dictionary has the following keys recognized by textFromEventDict:
- message: A tuple of str containing messages to be logged. - system: A str which indicates the "system" which is generating this event. - isError: A bool indicating whether this event represents an error. - failure: A failure.Failure<http://twistedmatrix.com/documents/current/api/twisted.python.failure.Failure.html>instance, required if the event is an error. - why: Used as header of the traceback in case of errors. - format: A string format used in place of message to customize the event. The intent is for the observer to format a message by doing something like format % eventDict.
So, for example, you could do log.msg(format='....', foo='stuff', bar='things')
I suggest that this be added to the documentation string of the msg() method and http://twistedmatrix.com/documents/current/core/howto/logging.html.
--
Don Dwiggins Advanced Publishing Technology
Please open a ticket for this, so it doesn't get lost. Thx. Kevin Horn
On 09:10 pm, kevin.horn@gmail.com wrote:
On Wed, Nov 16, 2011 at 2:27 PM, Don Dwiggins <ddwiggins@advpubtech.com>wrote:
** On 11/15/2011 8:57 AM, Christopher Armstrong wrote:
If you pass a 'system' kwarg to log.msg then it will go in that field.
log.msg("hi", system="stuff") results in <date> [stuff] hi
This triggered me to look further into what LogPublisher.msg does, since I've long wanted to customize the format of the output. I found what I wanted in http://twistedmatrix.com/documents/current/api/twisted.python.log.ILogObserv...:
In msg(), the message gets added to the kwargs dictionary (along with a timestamp called 'time'), and that dict is passed to LogObserver.emit, which uses textFromEventDict() to create what's actually output. This dictionary has the following keys recognized by textFromEventDict:
- message: A tuple of str containing messages to be logged. - system: A str which indicates the "system" which is generating this event. - isError: A bool indicating whether this event represents an error. - failure: A failure.Failure<http://twistedmatrix.com/documents/current/api/twisted.python.failure.Failure.html>instance, required if the event is an error. - why: Used as header of the traceback in case of errors. - format: A string format used in place of message to customize the event. The intent is for the observer to format a message by doing something like format % eventDict.
So, for example, you could do log.msg(format='....', foo='stuff', bar='things')
I suggest that this be added to the documentation string of the msg() method and http://twistedmatrix.com/documents/current/core/howto/logging.html.
`msg` doesn't really care about what you give it. It doesn't support the `format` keyword in any particular way. It's the job of a log observer to handle that sort of thing. So it could certainly be documented, but don't mix things together that are unrelated. Jean-Paul
On 11/17/2011 3:26 PM, exarkun@twistedmatrix.com wrote:
`msg` doesn't really care about what you give it. It doesn't support the `format` keyword in any particular way. It's the job of a log observer to handle that sort of thing. So it could certainly be documented, but don't mix things together that are unrelated.
Jean-Paul
True, but I was motivated by a different concern: when I first started using msg, I was unable to trace through the API docs to the place where I could find what I've quoted; Chris' message gave me the hint I needed to complete my detective work. I'd like to spare future users of the method the trouble I had. Looking at the source of log.py, I'm at a bit of a loss to reconcile these two forces. Certainly, the two log observers implemented there use textFromEventDict, but one could create a different observer that does things entirely differently. The best idea I can come up with is, in the documentation for msg, refer to the documentation for the chosen log observer; then, in each log observer's documentation, describe how the formatting is done, either explicitly, or by reference to textFromEventDict. (And maybe in the documentation for ILogObserver, recommend strongly that each implementation be explicit about message formatting.) There should probably also be something in the logging howto. Any better suggestions? -- Don Dwiggins Advanced Publishing Technology
On Tue, Nov 29, 2011 at 10:44:21AM -0800, Don Dwiggins wrote:
Looking at the source of log.py, I'm at a bit of a loss to reconcile these two forces. Certainly, the two log observers implemented there use textFromEventDict, but one could create a different observer that does things entirely differently.
The best idea I can come up with is, in the documentation for msg, refer to the documentation for the chosen log observer; then, in each log observer's documentation, describe how the formatting is done, either explicitly, or by reference to textFromEventDict. (And maybe in the documentation for ILogObserver, recommend strongly that each implementation be explicit about message formatting.) There should probably also be something in the logging howto.
Any better suggestions?
While not every log observer needs to flatten a log event dict into a string, that particular approach is probably common enough that it deserves a simple solution. I think, in my ideal world, there would be a LogMessage class that inherits from dict, with a __str__ method that looks something like: def __str__(self): if "msg" in self: return self["msg"] elif "format" in self: return self["format"] % self else return dict.__str__(self) If the standard Twisted logging functions automatically constructed LogMessage instances from dict instances, it should be easy enough for future ILogObserver implementations to do the right thing (by just calling str(msg)). Of course, they could also do more sophisticated things like pulling particular keys out of the message to set observer-specific message properties (like syslog channel and severity, etc.) The documentation for the standard Twisted logging functions could then just point to the LogMessage documentation to describe what goes into a log event and how it gets interpreted, with a footnote to the effect that different log observers can handle the same message in different ways.
On 04:07 am, screwtape@froup.com wrote:
On Tue, Nov 29, 2011 at 10:44:21AM -0800, Don Dwiggins wrote:
Looking at the source of log.py, I'm at a bit of a loss to reconcile these two forces. Certainly, the two log observers implemented there use textFromEventDict, but one could create a different observer that does things entirely differently.
The best idea I can come up with is, in the documentation for msg, refer to the documentation for the chosen log observer; then, in each log observer's documentation, describe how the formatting is done, either explicitly, or by reference to textFromEventDict. (And maybe in the documentation for ILogObserver, recommend strongly that each implementation be explicit about message formatting.) There should probably also be something in the logging howto.
Any better suggestions?
While not every log observer needs to flatten a log event dict into a string, that particular approach is probably common enough that it deserves a simple solution. I think, in my ideal world, there would be a LogMessage class that inherits from dict, with a __str__ method that looks something like:
def __str__(self): if "msg" in self: return self["msg"] elif "format" in self: return self["format"] % self else return dict.__str__(self)
If the standard Twisted logging functions automatically constructed LogMessage instances from dict instances, it should be easy enough for future ILogObserver implementations to do the right thing (by just calling str(msg)). Of course, they could also do more sophisticated things like pulling particular keys out of the message to set observer-specific message properties (like syslog channel and severity, etc.)
Oooorrrr there could be a function that takes a dict intended to represent a text message and returns that message as a string. Jean-Paul
The documentation for the standard Twisted logging functions could then just point to the LogMessage documentation to describe what goes into a log event and how it gets interpreted, with a footnote to the effect that different log observers can handle the same message in different ways.
_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com http://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python
On 29 Nov, 06:44 pm, ddwiggins@advpubtech.com wrote:
On 11/17/2011 3:26 PM, exarkun@twistedmatrix.com wrote:
`msg` doesn't really care about what you give it. It doesn't support the `format` keyword in any particular way. It's the job of a log observer to handle that sort of thing. So it could certainly be documented, but don't mix things together that are unrelated.
Jean-Paul
True, but I was motivated by a different concern: when I first started using msg, I was unable to trace through the API docs to the place where I could find what I've quoted; Chris' message gave me the hint I needed to complete my detective work. I'd like to spare future users of the method the trouble I had.
Looking at the source of log.py, I'm at a bit of a loss to reconcile these two forces. Certainly, the two log observers implemented there use textFromEventDict, but one could create a different observer that does things entirely differently.
The best idea I can come up with is, in the documentation for msg, refer to the documentation for the chosen log observer; then, in each log observer's documentation, describe how the formatting is done, either explicitly, or by reference to textFromEventDict. (And maybe in the documentation for ILogObserver, recommend strongly that each implementation be explicit about message formatting.) There should probably also be something in the logging howto.
Any better suggestions?
I'm not sure what you mean by "refer to the documentation for the chosen log observer". The only interpretation I can think of involves changing the documentation dynamically at runtime, which doesn't make any sense, so I don't think it's what you meant. :) Adding something about observers to the twisted.python.log.msg documentation does seem like it makes sense. Maybe that could be a link to most-used observers that Twisted comes with, or maybe to a document about observers in general. The second part of your suggestion, having each observer document what kind of events it expects to consume, sounds great. Extending the logging howto also sounds great. And a long-standing related issue, twisted.python.log.msg not appearing in the API documentation, would also be nice to resolve. Jean-Paul
On Wed, Nov 30, 2011 at 01:04:27PM -0000, exarkun@twistedmatrix.com wrote:
On 04:07 am, screwtape@froup.com wrote:
If the standard Twisted logging functions automatically constructed LogMessage instances from dict instances, it should be easy enough for future ILogObserver implementations to do the right thing (by just calling str(msg)). Of course, they could also do more sophisticated things like pulling particular keys out of the message to set observer-specific message properties (like syslog channel and severity, etc.)
Oooorrrr there could be a function that takes a dict intended to represent a text message and returns that message as a string.
As mentioned, we already have one of those in the form of textFromEventDict(). The trouble is that everybody who writes a LogObserver needs to know that it exists, and remember to call it. If it were the __str__() method of a LogMessage object, they'd have to go out of their way to *not* do the right thing.
On Nov 30, 2011, at 9:57 PM, Tim Allen wrote:
On Wed, Nov 30, 2011 at 01:04:27PM -0000, exarkun@twistedmatrix.com wrote:
On 04:07 am, screwtape@froup.com wrote:
If the standard Twisted logging functions automatically constructed LogMessage instances from dict instances, it should be easy enough for future ILogObserver implementations to do the right thing (by just calling str(msg)). Of course, they could also do more sophisticated things like pulling particular keys out of the message to set observer-specific message properties (like syslog channel and severity, etc.)
Oooorrrr there could be a function that takes a dict intended to represent a text message and returns that message as a string.
As mentioned, we already have one of those in the form of textFromEventDict().
Right, I think that's the tone all those extra letters are meant to suggest :).
The trouble is that everybody who writes a LogObserver needs to know that it exists, and remember to call it. If it were the __str__() method of a LogMessage object, they'd have to go out of their way to *not* do the right thing.
I really don't like using __str__ for structured conversions. For example, textFromEventDict has very strict error-handling behavior: it will try as hard as it can to give you something so that you don't need to do extra error handling in your log observer. But if you can get instances of LogMessage or some derived message type or possibly application-derived message types, the behavior might change and the error-handling would be less strict and now the default log observers need to be double-careful; once in LogMessage.__str__, once in the thing that calls it because you can never really know what str(x) is going to do. For another there's a whole nasty battery of unicode-or-bytes issues that crop up when you start using __str__. Finally, and I'm leaving it for last because this concern is rather silly, right now log events are constructed and propagated with extremely little copying, and the copying that does happen (ahem, log contexts) needs to be reduced. Adding a LogMessage object into the mix, even if it is a subclass of dict, means we have to, at the very least, copy all the values from msg()'s keyword arguments into a new object, rather than just propagating them to log observers. -glyph
On 11/30/2011 5:20 AM, exarkun@twistedmatrix.com wrote:
Looking at the source of log.py, I'm at a bit of a loss to reconcile these two forces. Certainly, the two log observers implemented there use textFromEventDict, but one could create a different observer that does things entirely differently. The best idea I can come up with is, in the documentation for msg, refer to the documentation for the chosen log observer; then, in each log observer's documentation, describe how the formatting is done, either explicitly, or by reference to textFromEventDict. (And maybe in the documentation for ILogObserver, recommend strongly that each implementation be explicit about message formatting.) There should probably also be something in the logging howto.
Any better suggestions? I'm not sure what you mean by "refer to the documentation for the chosen log observer". The only interpretation I can think of involves changing
On 29 Nov, 06:44 pm, ddwiggins@advpubtech.com wrote: the documentation dynamically at runtime, which doesn't make any sense, so I don't think it's what you meant. :)
Sorry, I was being a bit too concise. What I had in mind was that, when you're about to write a call to msg(), you know which log observer you're using, so you know which observer's documentation to refer to. Actually, that might not be quite true; if you use one of the LogFile classes, for example, you'd have to infer that it's using FileLogObserver, or dig into the source to find out -- again, the kind of thing I'd like to avoid. I'm beginning to think that howto/logging.html is the right place to explain things, and needs more work than I originally thought. I'm willing to submit something, but unfortunately not in the very near future. -- Don Dwiggins Advanced Publishing Technology
participants (7)
-
Christopher Armstrong -
Don Dwiggins -
exarkun＠twistedmatrix.com -
Glyph -
Jeffrey Ollie -
Kevin Horn -
Tim Allen