Bug 1018042 - All log entries have "journal" prepended
All log entries have "journal" prepended
Status: CLOSED UPSTREAM
Product: Fedora
Classification: Fedora
Component: openstack-swift (Show other bugs)
rawhide
Unspecified Unspecified
unspecified Severity unspecified
: ---
: ---
Assigned To: Silas Sewell
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  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:
Environment:
Last Closed: 2013-11-05 09:51:22 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
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 192.168.128.11 192.168.128.11 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 10.10.55.128 127.0.0.1 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):

openstack-swift-1.9.1-2.fc21.noarch
rsyslog-7.4.2-2.fc20.x86_64

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
/var/log/journal/xxxxxxxxx/user-531.journal
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.