Bug 779449

Summary: systemd-journalctl: Failed to iterate through journal: Bad message
Product: [openSUSE] openSUSE 12.2 Reporter: Erwin Lam <erwinl>
Component: BasesystemAssignee: Frederic Crozat <fcrozat>
Status: RESOLVED FIXED QA Contact: E-mail List <qa-bugs>
Severity: Major    
Priority: P5 - None CC: erwinl, meissner
Version: Final   
Target Milestone: ---   
Hardware: x86-64   
OS: openSUSE 12.2   
Whiteboard:
Found By: --- Services Priority:
Business Priority: Blocker: ---
Marketing QA Status: --- IT Deployment: ---

Description Erwin Lam 2012-09-09 19:20:52 UTC
User-Agent:       Mozilla/5.0 (X11; Linux x86_64; rv:15.0) Gecko/20100101 Firefox/15.0

When I try to print the systemd journal to stdout, systemd-journalctl stumbles over a bad message and refuses to display the rest of the journal file.

Reproducible: Always

Steps to Reproduce:
1. As root, I run "systemd-journalctl --no-pager"
Actual Results:  
The contents of the journal is displayed till timestamp "systemd-journalctl" and then an error message follows.

Sep 07 20:18:44 frodo SuSEfirewall2[2088]: /var/lock/SuSEfirewall2.booting exists which means system boot in progress, exit.
Sep 07 20:18:44 frodo dhcpcd[1611]: eth0: exiting
Sep 07 20:18:44 frodo dhclient[1629]: send_packet6: Cannot assign requested address
Sep 07 20:18:44 frodo dhclient[1629]: dhc6: send_packet6() sent -1 of 58 bytes
Sep 07 20:18:44 avahi-daemon[616]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::ca60:ff:fe13:9c82.
Failed to iterate through journal: Bad message

Expected Results:  
I expect the entire journal to be displayed including everything logged on Sept. 8th and 9th.

From the information above, one can see clearly that the message from the avahi-daemon is formatted differently. So this might be the cause of the journal corruption.

In my opinion, however, a more serious issue is the fact that systemd refuses to print the remainder of the journal file after it encounters a single bad message. This means that an important security mechanism of the system is now susccesfully sabotaged. Therefor, please, treat this as a security issue.

NB 1: I have to systemd journal files on my system (see below) and both show the same error message when I try to cat them through "systemd-journalctl --no-pager":

-rw-r-----  1 root root 10027008 Sep  9 21:04 system.journal
-rw-r-----  1 root root   884736 Sep  7 20:19 system@022cd6fc1eb34ca0aed2ae3176b8dff3-0000000000000423-0004c920a390aee0.journal

NB 2: For privacy reasons, the journal files have not be enclosed here. I can send them by private mail if they are required.
Comment 1 Erwin Lam 2012-09-09 19:25:26 UTC
Correction of a copy/paste error: Under "Steps to Reproduce", the timestamp mentioned should be "Sep 07 20:18:44".
Comment 2 Marcus Meissner 2012-09-10 06:28:56 UTC
it might also mean that your journal has been tampered with... ;)

But i suspect more of a bug. -> frederic
Comment 3 Frederic Crozat 2012-09-18 08:47:28 UTC
(In reply to comment #0)
> NB 2: For privacy reasons, the journal files have not be enclosed here. I can
> send them by private mail if they are required.

could you mail me the journal files ? There has been fixes for journal and one of them might fix your issues.
Comment 4 Erwin Lam 2012-09-18 15:49:02 UTC
Journal file have been send per private mail to Frederic Crozat.
Comment 5 Frederic Crozat 2012-10-10 12:18:26 UTC
Could you test systemd package from http://download.opensuse.org/repositories/home:/fcrozat:/branches:/openSUSE:/12.2:/Update/openSUSE_12.2_Update/ (x86-64 is available on mirror, i586 should be available in less than one hour).

I've backport many journal fixes and they seem to fix your issue (I've tested with your journal files)
Comment 6 Erwin Lam 2012-10-11 15:35:02 UTC
Ok, I have downloaded and installed the new systemd RPM from you site.

A test shows that systemd-journalctl no longer aborts at the bad message. Apparently, the issue has been fixed with the new package.
Comment 7 Frederic Crozat 2012-10-11 15:38:09 UTC
closing as fixed, the fix will be part of the next 12.2 maintenance update for systemd
Comment 8 Frederic Crozat 2012-11-20 12:42:20 UTC
reopening to request maintenance update
Comment 9 Frederic Crozat 2012-11-20 12:42:38 UTC
mr#142070
Comment 10 Benjamin Brunner 2012-11-20 20:29:32 UTC
Thanks for the submission. I started an update, see openSUSE:Maintenance:1109
Comment 11 Benjamin Brunner 2012-11-28 12:21:52 UTC
Update released for 12.2. Resolved fixed.
Comment 12 Swamp Workflow Management 2012-11-28 13:08:50 UTC
openSUSE-RU-2012:1582-1: An update that has 6 recommended fixes can now be installed.

Category: recommended (important)
Bug References: 777405,779449,780966,782271,783317,789151
CVE References: 
Sources used:
openSUSE 12.2 (src):    systemd-44-10.4.1, systemd-gtk-44-10.4.1