Am Tue, 24 Feb 2015 21:15:45 +0100 schrieb Marc Joliet <mar...@gmx.de>:
> However, I did find something unexpected. I haven't looked deeply yet, but I
> noticed some dmesg entries not ending up in the journal (i.e., a bunch of "-"
> lines in-between the "+" lines in the diff output). Did I do something wrong,
> or
> is this known behaviour when running the journal and syslog-ng simultaneously?
> I'll look more closely tomorrow, but wondered if anybody here noticed anything
> similar.
OK, I looked at the logs. It turns out that it was simply that various log
entries (mostly dmesg logs) were positioned differently or given different time
stamps. For example, this pinentry segfault:
Feb 15 01:11:03 arthur lightdm[1445]: ** (lightdm:1445): WARNING **: Could
not create user data directory /var/lib/lightdm-data/marcec: Error creating
directory: No such file or directory
-Feb 15 01:12:13 arthur kernel: [ 159.526696] pinentry[2323]: segfault at
18 ip 00007fe8e025965c sp 00007fffa2ba4678 error 4 in
libncursesw.so.5.9[7fe8e023e000+5d000]
+Feb 15 01:11:03 arthur lightdm[1891]: pam_unix(lightdm:session): session
opened for user marcec by (uid=0)
[...]
+Feb 15 01:12:13 arthur kernel: pinentry[2323]: segfault at 18 ip
00007fe8e025965c sp 00007fffa2ba4678 error 4 in
libncursesw.so.5.9[7fe8e023e000+5d000]
Notice that the journal entry is missing the dmesg time stamp. The reason for
that (whatever it is) is probably also the reason why some entries have slightly
different time stamps (e.g., 01:09:54 vs. 01:09:40).
I didn't look at every single difference, but it looks like no messages was
missed.
Ah, no, there is one class of messages that only went to syslog-ng:
-Feb 18 19:48:27 arthur kernel: 6.803784] systemd-journald[132]:
Received request to flush runtime journal from PID 1
-Feb 18 19:52:14 arthur kernel: 245.293713] systemd-journald[132]: Failed
to read ACL on
/var/log/journal/b3a495d35e890b80816684a4521fc1cc/user-1000.journal, ignoring:
Operation not supported
(Note that the ACL thing is fixed, I simply did't have btrfs POSIX ACL support
activated before the migration.)
That's... interesting. Why does the journal not contain these entries
relating to itself? All I can find in the journal related to flushing are lots
of "Time spent on flushing" entries:
% journalctl|grep flush
Feb 15 00:19:45 arthur systemd-journal[131]: Time spent on flushing to /var
is 20.220ms for 798 entries.
Feb 15 00:25:20 arthur kernel: nr_pdflush_threads exported in /proc is
scheduled for removal
Feb 15 00:32:36 arthur systemd-journal[131]: Time spent on flushing to /var
is 570.566ms for 775 entries.
[...]
Grepping for ACL also turns up empty. What gives?
--
Marc Joliet
--
"People who think they know everything really annoy those of us who know we
don't" - Bjarne Stroustrup
pgpkrkyAzp3B5.pgp
Description: Digitale Signatur von OpenPGP
