[systemd-devel] Multiline log mesages in journal

[Lennart Poettering]

On Wed, 07.03.12 13:09, Marti Raudsepp (marti at juffo.org) wrote:

> Hi list,
> 
> Some applications, such as PostgreSQL have log messages consisting of
> multiple lines. When reporting to syslog, these messages are
> artificially split into multiple log lines. But it would be nice to
> get rid of that legacy with journal -- to prevent lines from being
> interleaved with other unrelated log messages and to make the lives of
> log scrapers easier. Also, other fields don't need to be duplicated
> for each message line.
> 
> However, currently whenever applications send a message to the journal
> that includes newlines, it gets displayed as "[##B blob data]"
> 
> I hereby propose that the "short" output mode should first split the
> message into separate lines, and then simply repeat the timestamp/etc
> prefix for each line. Perhaps with a limit on the number of max lines
> per message. e.g:
> 
> Mar 07 12:23:57 host postgres[6326]: line1
> Mar 07 12:23:57 host postgres[6326]: line2
> 
> If this is considered a good idea, I can have a try at implementing
> it.

Hmm, so yes, I think we should support multi-line log messages like
this. There could be two other ways to display them however:

I think I would prefer if do not repeat the the meta data in the output,
and just output the actual message, line-by-line, prefixed with
whitespace. So that we'd get this:

Mar 07 12:23:57 host postgres[6326]: line1
                                     line2
                                     line3
Mar 07 12:23:58 host postgres[6326]: line1
                                     line2

That way we would clarify that this is a multi-line log messages,
and wouldn't show redundant information all the time.

Or, we could just ellipsize these messages at line breaks, indicating
that there's more in the message than what we are showing. But actually
I prefer the "whitespace" aligned output explained above much nicer.

Does PostgreSQL actually write those multi-line messages into syslog
datagrams? interesting i must say, I didn't expect that people do that
and I am a bit surprised that the journal actually handles that properly
and doesn't truncate things at the first newline. But I guess this is
good that way.

The display routines for those messages could use some love
probably. For example, I know a couple of services which log messages
with tabs in them. we probably should expand those before ellipsizing
the lines for column width. (currently we show these messages as "blob
data", too.

Also, we recently added functions to check utf8 validity of strings to
systemd. (in utf8.h) It probably would make sense to use this in the
display of journal data too, and show utf8 data if it is valid normally,
instead of "blob data".

All patches in this area happily accepted!

(And i added this to the todo list now, so that we don't forget)

Lennart

-- 
Lennart Poettering - Red Hat, Inc.