From 56d8b2b04adf9d44989c2671cf71697d225b9d65 Mon Sep 17 00:00:00 2001 From: Michael Still Date: Tue, 27 Mar 2012 07:14:12 +1100 Subject: [PATCH] Support timestamps as prefixes for traceback log lines. Traceback lines in the log are now formatted to match other log lines. So, instead of getting something like: 2012-03-26 14:53:26 ERROR nova.rpc.common [-] AMQP server on 10.55.58.1:5672 is unreachable: Socket closed. Trying again in 1 secon ds. (nova.rpc.common): TRACE: Traceback (most recent call last): (nova.rpc.common): TRACE: File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 446, in reconnect (nova.rpc.common): TRACE: self._connect() (nova.rpc.common): TRACE: File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 423, in _connect (nova.rpc.common): TRACE: self.connection.connect() [snip] You would get something like: 2012-03-26 14:53:26 ERROR nova.rpc.common [-] AMQP server on 10.55.58.1:5672 is unreachable: Socket closed. Trying again in 1 secon ds. 2012-03-26 14:53:26 TRACE nova.rpc.common Traceback (most recent call last): 2012-03-26 14:53:26 TRACE nova.rpc.common File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 446, in reconnect 2012-03-26 14:53:26 TRACE nova.rpc.common self._connect() 2012-03-26 14:53:26 TRACE nova.rpc.common File "/usr/lib/python2.7/dist-packages/nova/rpc/impl_kombu.py", line 423, in _connect 2012-03-26 14:53:26 TRACE nova.rpc.common self.connection.connect() [snip] This is tracked by bug 967842. Change-Id: Ie017317f7e0b636016a220cb21a3543ab569dea5 --- nova/log.py | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/nova/log.py b/nova/log.py index 60028a68..cbc757f2 100644 --- a/nova/log.py +++ b/nova/log.py @@ -63,7 +63,7 @@ log_opts = [ '%(pathname)s:%(lineno)d', help='data to append to log format when level is DEBUG'), cfg.StrOpt('logging_exception_prefix', - default='(%(name)s): TRACE: ', + default='%(asctime)s TRACE %(name)s %(instance)s', help='prefix each line of exception output with this format'), cfg.StrOpt('instance_format', default='[instance: %(uuid)s] ', @@ -247,11 +247,16 @@ class LegacyNovaFormatter(logging.Formatter): """Format exception output with FLAGS.logging_exception_prefix.""" if not record: return logging.Formatter.formatException(self, exc_info) + stringbuffer = cStringIO.StringIO() traceback.print_exception(exc_info[0], exc_info[1], exc_info[2], None, stringbuffer) lines = stringbuffer.getvalue().split('\n') stringbuffer.close() + + if FLAGS.logging_exception_prefix.find('%(asctime)') != -1: + record.asctime = self.formatTime(record, self.datefmt) + formatted_lines = [] for line in lines: pl = FLAGS.logging_exception_prefix % record.__dict__