[systemd-devel] Failed to get journal fields: Bad message

Mon Feb 27 07:29:22 UTC 2017

On Sun, 2017-02-26 at 21:45 +0100, Lennart Poettering wrote:
> On Sat, 25.02.17 11:10, Krzysztof Błaszkowski (kb at sysmikro.com.pl)
> wrote:
> 
> > 
> > 
> > Any thoughts ? wise only ..
> > 
> > when there was /var/log/messages available there was no problem
> > with
> > accessing logs because the "database" was plain text but now.
> > 
> > corrupted less or more it did not matter. it is responsibility of
> > /var/log filesystem to perform right recovery ..
> > 
> > I want to see what could happen before I had to hard reboot and I
> > can't
> > access "messages" even before a month ago.
> > 
> > 
> > don't want to see reply like this:
> > http://forums.fedoraforum.org/showthread.php?t=311314
> > 
> > because I will express how stupid *-journal idea is.
> > and making double recovery scheme by the file system and poor one
> > by *-
> > journal is so brain fucked like I have never seen yet.
> 
> The journal file format is primarily an append-based format (though
> some fields at the front are updated, to link the new additions
> up). This makes it not too bad when it comes to disk corruptions, and
> data up to the point of corruption should be readable pretty nicely
> still.
> 
> 

well, the most interesting information is located beyond that point
very often. 

> Anyway, if you have a corrupted journal file and current journalctl
> can't read it, then please file a bug, attach the journal file, and
> we'll look into improving journalctl.
> 

journalctl --verify
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-
1105.journal                         
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/system at 0005495e
2bb26863-aa72c6a8a7437123.journal~
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/system at 0005455b
e5e6181f-8616123458bd2b50.journal~
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/system at 00054956
b0c61ef7-6f0ef8bfd59ad5e8.journal~
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-1000 at 00054
95e2c558675-4af46c2d79464765.journal~
549f50: Invalid entry item (7/9 offset:
000000                                                    
549f50: Invalid object contents: Bad
message                                                      
File corruption detected at /var/log/journal/52f04da61fa8108cd5f48bca58
6164a2/system at 0005495abfa1c9d8-cf2deeeef0a23044.journal~:549f50 (of
8388608 bytes, 66%).
FAIL: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/system at 0005495a
bfa1c9d8-cf2deeeef0a23044.journal~ (Bad message)
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-1000 at 00054
55bfdbeb23d-1ff3046498e945ad.journal~
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/system at 0005495e
3d56c587-44f1967167aac5a3.journal~
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/system at 65bee6e3
4f3c4b77b265431a1dd2a6df-0000000000000001-0005459b8fd2a11e.journal
c84f48: Invalid entry item (8/24 offset:
000000                                                   
c84f48: Invalid object contents: Bad
message                                                      
File corruption detected at /var/log/journal/52f04da61fa8108cd5f48bca58
6164a2/system at 0005459b8ff5e32b-620437abf7009d7d.journal~:c84f48 (of
16777216 bytes, 78%).
FAIL: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/system at 0005459b
8ff5e32b-620437abf7009d7d.journal~ (Bad message)
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-
1000.journal                         
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-1000 at 00054
95e3de63208-bbc6d86046b94014.journal~
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-1105 at 2a1f1
b3f5241431483971743eded852c-000000000000d6d6-000547f91700222b.journal
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-1000 at 00054
59b907b630d-a25c081908a032be.journal~
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/system at 0005495e
8db292fb-cb1d4cbe87b5093f.journal~
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-1001 at 1dd4c
9dcd66446b483e91ea564f6f1b6-00000000000043c6-0005478f1ea62cb4.journal
PASS:
/var/log/journal/52f04da61fa8108cd5f48bca586164a2/system.journal       

3a86e0: Invalid
object                                                                 

File corruption detected at /var/log/journal/52f04da61fa8108cd5f48bca58
6164a2/user-1000 at 0005495ac03d6f02-bc5bf9a6b1d16fec.journal~:3a86e0 (of
8388608 bytes, 45%).
FAIL: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-1000 at 00054
95ac03d6f02-bc5bf9a6b1d16fec.journal~ (Bad message)
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/system at 0005455b
eea9f506-e4b5738d99c3f3ab.journal~
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-
1020.journal                         
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-
1005.journal                         
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-1000 at 8d932
e8a67a74b8483761b6d509bd81f-00000000000005e0-0005459b907b791b.journal
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-1000 at 00054
956b1a5b541-cf982e5a4667655f.journal~
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/user-
1001.journal                         
4bf850: Invalid
object                                                                 

File corruption detected at /var/log/journal/52f04da61fa8108cd5f48bca58
6164a2/system at 0005495e4825d0e0-cb146f70781a7baa.journal~:4bf850 (of
8388608 bytes, 59%).
FAIL: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/system at 0005495e
4825d0e0-cb146f70781a7baa.journal~ (Bad message)
PASS: /var/log/journal/52f04da61fa8108cd5f48bca586164a2/system at 00054956
aac67a38-5b59fccdc0bcf4fe.journal~

journalctl --version
systemd 228
+PAM -AUDIT +SELINUX -IMA +APPARMOR -SMACK +SYSVINIT +UTMP
+LIBCRYPTSETUP +GCRYPT -GNUTLS +ACL +XZ -LZ4 +SECCOMP +BLKID -ELFUTILS
+KMOD -IDN

> If you think that our ideas, and in particular journal files are
> stupid, then please use something else, there are plenty syslog
> implementations around, and they still work on systemd.

No, you got me wrong. This is not about what I think or whatever. This
is logical conclusion and here is simple logical (mathematical) proof
for the thesis above:

- logs rely on underlying filesystem abilities to perform proper
journaling and recovery
- *-journal adds yet another layer of abstraction on top of the
filesystem.

- can *-journal do better recovery than bottom filesystem ? - no it
can't. it is not possible. 

so does it make any sense to design surplus journal log recovery
facilities ? no it does not because if filesytem fails then nothing
else will help.

Is *-journal recovery done right now ? of course it is not. if *-
journal is stopped abruptly then logs can be corrupted - that's my
case.

I would really like to have old syslogd + logrotate restored and
working however systemd is required by too many things thus I can not
get rid of whole systemd however I would like to listen to *-journal
developers on how to replace systemd-journal preserving other systemd
facilities.
Seems that I have to be an expert on *-journal while I don't want to be
because there are other topics I'm more interested in and I wouldn't
even find this if my Dell's M4800 battery approached end of its life
thus many weird things used to happen after un/re-plugging mains.

> 
> Lennart
> 
-- 
Krzysztof Blaszkowski