Bug 1018042 - All log entries have "journal" prepended
All log entries have "journal" prepended
Product: Fedora
Classification: Fedora
Component: openstack-swift (Show other bugs)
Unspecified Unspecified
unspecified Severity unspecified
: ---
: ---
Assigned To: Silas Sewell
Fedora Extras Quality Assurance
Depends On:
  Show dependency treegraph
Reported: 2013-10-11 00:31 EDT by Pete Zaitcev
Modified: 2013-11-05 09:51 EST (History)
11 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Last Closed: 2013-11-05 09:51:22 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---

Attachments (Terms of Use)

External Trackers
Tracker ID Priority Status Summary Last Updated
OpenStack gerrit 53252 None None None Never

  None (edit)
Description Pete Zaitcev 2013-10-11 00:31:54 EDT
Description of problem:

Log entries look like this:

Oct 10 23:57:49 kvm-rei journal: proxy-server 11/Oct/2013/03/57/49 GET /v1/AUTH_t1%3Fformat%3Djson HTTP/1.0 200 - - MIIF.........i8w%3D%3D - 786 - tx22d63c0146ca40c7bff2e-005257773d - 0.0455 - -

They used to be like this on RHEL 6:

Oct 10 23:54:20 rhev-a24c-01 proxy-server 11/Oct/2013/03/54/20 GET /v1/AUTH_test%3Fformat%3Djson HTTP/1.0 200 - - AUTH_tka.........6a7 - 907 - tx6018d95b1cec45c8aa5ed-005257766c - 0.0392 - -

Version-Release number of selected component (if applicable):


How reproducible:

Seems stable

Steps to Reproduce:
1. Install openstack-swift-proxy

Actual results:

Different log format

Expected results:

Traditional log format

Additional info:

We thought it was systemd journal thing, but then realized
that /var/log/messages still has normal looking entries
from every other service.

[zaitcev@kvm-rei ~]$ cat /etc/rsyslog.d/swift.conf 
local0.*	/var/log/swift/swift.log

But actually same thing happens if we let logs go into
/var/log/messages too.
Comment 1 Pete Zaitcev 2013-10-21 17:47:17 EDT
Oh, brother, it's just as I suspected.

The /dev/log is served by the systemd-journal, which parses the messages,
optionally stores them, then reassembles them back and forwards to rsyslog.
At the parsing time, something called "identifier" is searched by
looking for a word surrounded by whitespace and ending with a colon.
It's in src/journal/journal-syslog.c,
 server_process_syslog_message => syslog_parse_identifier
If the indentifier is not set, something in the depths of systemd adds it.

There's an option of forwarding to syslog raw, and in fact it is enabled
by default in systemd. Rsyslog is configured to listen on
/run/systemd/journal/syslog as well (with $SystemLogSocketName
in /etc/rsyslog.d/listen.conf), but it does not actually listen there.

The way journal forwards logging to rsyslogd is fairly strange
and difficult to pick up with strace - apparently it goes through
shared mmap-ed file, watched with inotify in
Comment 2 Pete Zaitcev 2013-11-05 09:51:22 EST
merged upstream (tentatively at least), will track in Icehouse

Note You need to log in before you can comment on or make changes to this bug.