Sample Header Ad - 728x90

rsyslogd sometimes doesn't write the initial bits of dmesg to /var/log/syslog

2 votes
1 answer
177 views
I have a Linux machine running Ubuntu 16.04.7 LTS that uses rsyslogd. My understanding of rsyslogd is that it rotates the content from the kernel ring buffer (ie, dmesg) to an on-disk file (ie, /var/log/syslog). So nominally in /var/log/syslog, I expect see a "start" message from rsyslogd followed by kernel messages that I can later retrieve in dmesg. Notice how the first kernel message starts at a relative 0.0000s time.
$ cat /var/log/syslog
... 
rsyslogd: [origin software="rsyslogd" swVersion="8.16.0" x-pid="4970" x-info="http://www.rsyslog.com "] start
...
kernel: [    0.000000] Booting Linux on physical CPU 0x0
Sometimes, when I look at /var/log/syslog, I'd notice that the first kernel message starts as late as 40+ seconds:
$ cat /var/log/syslog
... 
rsyslogd: [origin software="rsyslogd" swVersion="8.16.0" x-pid="4970" x-info="http://www.rsyslog.com "] start
...
kernel: [   45.829155] IRQ6 no longer affine to CPU4
If I then immediately look at dmesg, I'd find the missing "Booting Linux on physical CPU 0x0" message.
$ dmesg | head -n1
kernel: [    0.000000] Booting Linux on physical CPU 0x0
All this makes me think that for _some_ reason, rsyslogd occasionally encounters a race condition in which it doesn't log the first bits of kernel messages. But I have no idea how to go about troubleshooting this. I would love to get some pointers on how to get to the bottom of this problem.
Asked by Ken Lin (153 rep)
May 13, 2023, 02:35 AM
Last activity: May 30, 2023, 11:37 PM