Bug 1227396

Summary: journald strips away white space prefixes of messages
Product: Red Hat Enterprise Linux 7 Reporter: Tomas Heinrich <theinric>
Component: systemdAssignee: systemd-maint
Status: CLOSED ERRATA QA Contact: Robin Hack <rhack>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 7.1CC: ffotorel, filbranden, jscotka, lnykryn, lpoetter, msekleta, pvrabec, rhack, systemd-maint-list, systemd-maint, yoguma
Target Milestone: rcKeywords: Reopened
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: systemd-219-4.el7 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-11-19 15:07:05 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 743890    

Description Tomas Heinrich 2015-06-02 14:56:19 UTC
Description of problem:
journald strips away white space prefixes and suffixes of messages written (via logger or otherwise) to /dev/log.

Version-Release number of selected component (if applicable):
systemd-208-20.el7.x86_64

Steps to Reproduce:
$ echo '   a   b   ' | logger
$ journalctl -n 1

Actual results:
"Jun 02 16:17:28 localhost.localdomain root[11160]: a   b"

Expected results:
"Jun 02 16:17:28 localhost.localdomain root[11160]:    a   b   "

Comment 2 Michal Sekletar 2015-06-02 18:15:44 UTC
Can you give an example where this could cause troubles? I mean you rarely grep for whitespace patterns :)

Comment 3 Tomas Heinrich 2015-06-03 11:18:52 UTC
(In reply to Michal Sekletar from comment #2)
> Can you give an example where this could cause troubles? I mean you rarely
> grep for whitespace patterns :)

Well, if you log something, whitespace or not, you expect the message to be stored as you've logged it.
Second guessing what the message "should" look like by removing whitespace seems a little arbitrary. Is this the only change done to the messages? Is this documented anywhere?

An example of a serious issue this policy caused is given in rhbz#743890 which this bug blocks.

Comment 4 Michal Sekletar 2015-06-09 10:29:29 UTC
TL;DR if you want your /var/log/messages on RHEL7 look the same as it did on RHEL5/6 setup syslog forwarding and don't look at data stored by journal at all.

https://github.com/systemd/systemd/issues/98

Sorry.

Comment 5 Filipe Brandenburger 2015-06-11 15:51:47 UTC
Fixed upstream for leading whitespaces:
https://github.com/systemd/systemd/pull/156

This is the commit that went in:
https://github.com/systemd/systemd/commit/6f6fdcb5906ff9259443b97daca429ed1de2559c

Tested with `pstree | logger` and confirmed that the journalctl output showed the output as originally formatted by pstree.

Trailing whitespace will still be stripped (but hopefully nobody was actually relying on those being present.)

Cheers,
Filipe

Comment 6 Tomas Heinrich 2015-06-12 09:17:55 UTC
(In reply to Filipe Brandenburger from comment #5)
> Fixed upstream for leading whitespaces:
> https://github.com/systemd/systemd/pull/156

Thanks, this is an improvement.

> Trailing whitespace will still be stripped (but hopefully nobody was
> actually relying on those being present.)

This is still a problem. I don't think hope is a good backwards-compatibility policy.

Comment 9 Lukáš Nykrýn 2015-06-16 12:12:15 UTC
Devel-ack for backporting https://github.com/systemd/systemd/commit/6f6fdcb5906ff9259443b97daca429ed1de2559c 

I don't think that the other part will be ever acccepted in upstream and we are not going to patch it downstream.

Comment 11 Filipe Brandenburger 2015-06-18 16:50:00 UTC
Hi Tomas,

(In reply to Tomas Heinrich from comment #6)
> (In reply to Filipe Brandenburger from comment #5)
> > Trailing whitespace will still be stripped (but hopefully nobody was
> > actually relying on those being present.)
> 
> This is still a problem. I don't think hope is a good
> backwards-compatibility policy.

I guess it really depends on what bug 743890 is requesting (that bug is private, so I can not really check that myself.)

I can see how stripping leading whitespace might be a problem if you're expecting to dump formatted output of commands into logs and stripping whitespace may indeed make it less readable, that's why I fixed the leading whitespace case and tested it using `pstree` which is not too realistic but is something that produces such a formatted output.

I really don't see how removing trailing whitespace will break a *sane* log parser (though I wouldn't be surprised to see it.)

In any case, as pointed out by Lennart in https://github.com/systemd/systemd/issues/98, for such use cases it's always possible to run a regular syslog daemon such as rsyslog and just use ForwardSyslog=yes, in which case the regular syslog should get the original messages verbatim including all the whitespace (I haven't really checked that's the case myself.) So users that have legacy scripts that rely on trailing whitespace should be able to use that workaround, which is likely to always keep working.

Do you think that's acceptable?

Comment 14 Tomas Heinrich 2015-06-19 13:48:36 UTC
(In reply to Filipe Brandenburger from comment #11)
> I can see how stripping leading whitespace might be a problem if you're
> expecting to dump formatted output of commands into logs and stripping
> whitespace may indeed make it less readable,

The core of the issue is not as much a misaligned output as that the message is modified at all.

> that's why I fixed the leading
> whitespace case and tested it using `pstree` which is not too realistic but
> is something that produces such a formatted output.

Yeah, thanks for the patch.
I can't see why retaining leading whitespace is acceptable but trailing whitespace is not, though. (Not that it was your call.)

> I really don't see how removing trailing whitespace will break a *sane* log
> parser (though I wouldn't be surprised to see it.)

I don't think we can afford to assume "sane".
You can have a stupid piece of hw that can't be updated or an ancient piece of closed sw that can't be replaced or a large deployment that would be too costly to fix.
I don't think we should break all these use cases because whitespace "is a menace".

> In any case, as pointed out by Lennart in
> https://github.com/systemd/systemd/issues/98, for such use cases it's always
> possible to run a regular syslog daemon such as rsyslog and just use
> ForwardSyslog=yes, 

That proposal is bogus. With this workaround you loose the benefits of using journald and you get some additional drawbacks.
A unix socket is not a good storage medium. You can resume reading messages from journald after a week - you can't do that with ForwardSyslog. If the messages are coming in too fast, you loose some of them.
Ideally, all consumers would be migrated to one (journald) API. Saying "we don't provide this functionality, use the old interface" seems silly.

> in which case the regular syslog should get the original
> messages verbatim including all the whitespace (I haven't really checked
> that's the case myself.)

I've checked, the messages are not modified.

> So users that have legacy scripts that rely on
> trailing whitespace should be able to use that workaround, which is likely
> to always keep working.
> 
> Do you think that's acceptable?

There don't seem to be any other options right now.

Comment 16 errata-xmlrpc 2015-11-19 15:07:05 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2015-2092.html