Kernel messages not logged to /var/log/kern.log

Bug #255635 reported by Matt Zimmerman
8
Affects Status Importance Assigned to Milestone
sysklogd (Debian)
Invalid
Undecided
Unassigned
sysklogd (Ubuntu)
High
Unassigned
Intrepid
High
Unassigned

Bug Description

Binary package hint: sysklogd

On two independent systems, after upgrading from Hardy to intrepid, nothing has since been logged to /var/log/kern.log (zero bytes). This is despite several reboots and a variety of other content which is visible in dmesg. Not even the initial messages from klogd itself are logged (Inspecting /boot/System.map etc.)

Further inspection reveals that they are being logged to /var/log/syslog

Revision history for this message
Matt Zimmerman (mdz) wrote :

Confirmed by Martin Pitt as well.

Changed in sysklogd:
importance: Undecided → High
status: New → Confirmed
Revision history for this message
Matt Zimmerman (mdz) wrote :

<pitti> mdz: hm, "sudo tail -f /proc/kmsg" doesn't report anything either (tried with some modprobe)
<pitti> itz kernel bug?

description: updated
Revision history for this message
Martin Pitt (pitti) wrote : Re: No messages in /proc/kmsg

I used this to reliably and conveniently produce kernel messages and verify that dmesg has new stuff:

$ sudo dmesg -c
$ sudo /etc/init.d/apparmor restart
Reloading AppArmor profiles : done.
$ sudo dmesg -c
[68804.887693] type=1505 audit(1218098412.816:494): operation="profile_replace" name="/usr/share/gdm/guest-session/Xsession" name2="default" pid=27662
[68805.155782] type=1505 audit(1218098413.084:495): operation="profile_replace" name="/usr/lib/cups/backend/cups-pdf" name2="default" pid=27667
[68805.156318] type=1505 audit(1218098413.084:496): operation="profile_replace" name="/usr/sbin/cupsd" name2="default" pid=27667

I started this in the background before:

sudo /etc/init.d/klogd stop
sudo tail -f /proc/kmsg

no output from the latter

printk looks correct to me:

$ cat /proc/sys/kernel/printk
4 4 1 7

Changed in linux:
assignee: nobody → ubuntu-kernel-team
status: Confirmed → Triaged
Revision history for this message
Ben Collins (ben-collins) wrote :

I've reproduced this. Working through the motions...

Changed in linux:
assignee: ubuntu-kernel-team → ben-collins
milestone: none → intrepid-alpha-5
status: Triaged → In Progress
Revision history for this message
Matt Zimmerman (mdz) wrote :

The most recent message (in /var/log/kern.log.0) on my system is:

Jul 11 09:16:49 mizar kernel: Kernel log daemon terminating.

and I was running 2.6.26-2.6 at that time, so this has been broken for quite a while.

Revision history for this message
Ben Collins (ben-collins) wrote :

After more investigation, it seems that tail -f is not the right way to reproduce this. Using cat or dd shows that messages are actually getting out of /proc/kmsg. Strace shows that klogd is actually reading them, and is doing a sendto() to send them to syslog.

However, the problem is that they are not being sent to /var/log/kern.log, presumably because they are being sent as klogd.* and syslog is looking for kern.*. You can see the messages in /var/log/syslog, so it's definite that they are getting there.

Reverting back to klogd.

Changed in linux:
assignee: ben-collins → nobody
status: In Progress → Triaged
Matt Zimmerman (mdz)
description: updated
Revision history for this message
Matt Zimmerman (mdz) wrote :

klogd.c is still using "kernel":
                openlog("kernel", 0, LOG_KERN);

but the messages are ending up with "klogd":

mizar:[/tmp/sysklogd-1.5] grep kernel: /var/log/syslog
zsh: exit 1 grep kernel: /var/log/syslog
mizar:[/tmp/sysklogd-1.5] grep klogd: /var/log/syslog
Aug 15 09:54:55 mizar klogd: [253172.357916] usb 2-1.3: USB disconnect, address 4
Aug 15 09:54:55 mizar klogd: [253172.364002] cannot submit datapipe for urb 0, error -19: no device
Aug 15 09:55:43 mizar klogd: [253220.720528] Marking TSC unstable due to: cpufreq changes.
Aug 15 09:55:44 mizar klogd: [253221.032029] Clocksource tsc unstable (delta = -202362927 ns)
mizar:[/tmp/sysklogd-1.5]

Changed in sysklogd:
status: Unknown → New
Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package sysklogd - 1.5-2ubuntu6

---------------
sysklogd (1.5-2ubuntu6) intrepid; urgency=low

  * Makefile: disable FORTIFY_SOURCE for klogd, otherwise the protection
    macros redirect the calls improperly (LP: #255635).

 -- Kees Cook <email address hidden> Fri, 29 Aug 2008 16:50:29 -0700

Changed in sysklogd:
status: Triaged → Fix Released
Revision history for this message
nullack (nullack) wrote :

confirming the success of the fix in Intrepid, thank you :)

Revision history for this message
Matt Zimmerman (mdz) wrote :

Removing the Debian bug watch; this was actually a different (Ubuntu-specific) bug

Changed in sysklogd:
importance: Unknown → Undecided
status: New → Invalid
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.