Logging multiple lines

[Nikolaus Rath]

Hi,

Are there any best practices for handling multi-line log messages?

For example, the program,

main = logging.getLogger()
handler = logging.StreamHandler()
handler.setFormatter(logging.Formatter('%(asctime)s %(levelname)s %(message)s'))
main.addHandler(handler)
main.setLevel(logging.DEBUG)
main.info("Starting")
try:
bla = 42/0
except:
main.exception("Oops...")

generates the log messages

2009-06-16 22:19:57,515 INFO Starting
2009-06-16 22:19:57,518 ERROR Oops...
Traceback (most recent call last):
File "/home/nikratio/lib/EclipseWorkspace/playground/src/mytests.py", line 27, in <module>
bla = 42/0
ZeroDivisionError: integer division or modulo by zero


which are a mess in any logfile because they make it really difficult to
parse.


How do you usually handle multi-line messages? Do you avoid them
completely (and therefore also the exception logging facilities provided
by logging)? Or is it possible to tweak the formatter so that it inserts
the prefix at the beginning of every line?


Best,


-Nikolaus

 

[Mike Kazantsev]

How do you usually handle multi-line messages? Do you avoid them
completely (and therefore also the exception logging facilities
provided by logging)? Or is it possible to tweak the formatter so
that it inserts the prefix at the beginning of every line?

I'd log exception name and timestamp (or id) only, pushing the full
message with the same id to another log or facility (like mail it to
some dedicated bug-report box).

--
Mike Kazantsev // fraggod.net

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.11 (GNU/Linux)

iEYEARECAAYFAko4YeEACgkQASbOZpzyXnFu5ACgzkD9O9eNjQFytPxTElMm525w
eGMAn2ch6kt5ydE2p+UqlqrPD/GhMAUE
=1Dhz
-----END PGP SIGNATURE-----

 

[Lie Ryan]

Hi,

Are there any best practices for handling multi-line log messages?

For example, the program,

main = logging.getLogger()
handler = logging.StreamHandler()
handler.setFormatter(logging.Formatter('%(asctime)s %(levelname)s %(message)s'))
main.addHandler(handler)
main.setLevel(logging.DEBUG)
main.info("Starting")
try:
bla = 42/0
except:
main.exception("Oops...")

generates the log messages

2009-06-16 22:19:57,515 INFO Starting
2009-06-16 22:19:57,518 ERROR Oops...
Traceback (most recent call last):
File "/home/nikratio/lib/EclipseWorkspace/playground/src/mytests.py", line 27, in <module>
bla = 42/0
ZeroDivisionError: integer division or modulo by zero


which are a mess in any logfile because they make it really difficult to
parse.


How do you usually handle multi-line messages? Do you avoid them
completely (and therefore also the exception logging facilities provided
by logging)? Or is it possible to tweak the formatter so that it inserts
the prefix at the beginning of every line?

The next line that starts with a timestamp is part of the next log.

If you added timestamp on every line, that would be much more difficult
to parse. You could do something like:

import re

timestamp_re = '...'
messages = []

for line in open('log.log'):
if timestamp_re.match(line):
messages.append([line])
else:
messages[-1].append(line)