GNU bug report logs - #55707
syslogd logging kernel messages slowly?

Previous Next

Full log

View this message in rfc822 format

From: help-debbugs <at> gnu.org (GNU bug Tracking System)
To: Ludovic Courtès <ludo <at> gnu.org>
Subject: bug#55707: closed (Re: bug#55707: syslogd logging kernel messages
 slowly?)
Date: Mon, 06 Jun 2022 20:47:03 +0000

[Message part 1 (text/plain, inline)]

Your bug report

#55707: syslogd logging kernel messages slowly?

which was filed against the guix package, has been closed.

The explanation is attached below, along with your original report.
If you require more details, please reply to 55707 <at> debbugs.gnu.org.

-- 
55707: https://debbugs.gnu.org/cgi/bugreport.cgi?bug=55707
GNU Bug Tracking System
Contact help-debbugs <at> gnu.org with problems

[Message part 2 (message/rfc822, inline)]

From: Ludovic Courtès <ludo <at> gnu.org>
To: Luis Felipe <luis.felipe.la <at> protonmail.com>
Cc: 55707-done <at> debbugs.gnu.org, 55488 <at> debbugs.gnu.org
Subject: Re: bug#55707: syslogd logging kernel messages slowly?
Date: Mon, 06 Jun 2022 22:46:47 +0200

Hi,

Luis Felipe <luis.felipe.la <at> protonmail.com> skribis:

> This does reduce the time it takes to get to GDM log in screen from GRUB. It used to be around 2:35 minutes, but now it takes around 1:25 minutes, which is nice.

Alright, so commit 264ca9452fae827d6621b28b8972f4b1d68401a1 closes this
particular issue (#55707).

Thanks,
Ludo’.

[Message part 3 (message/rfc822, inline)]

From: Ludovic Courtès <ludo <at> gnu.org>
To: bug-guix <at> gnu.org
Subject: syslogd logging kernel messages slowly?
Date: Sun, 29 May 2022 16:59:05 +0200

Hello,

I noticed this weird phenomenon on an x86_64 machine (a 2GHz Celeron),
seen in an excerpt of /var/log/messages:

--8<---------------cut here---------------start------------->8---
May 29 12:34:49 localhost avahi-daemon[349]: avahi-daemon 0.8 starting up.
May 29 12:35:10 localhost vmunix: [    1.391673] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 1
May 29 12:35:10 localhost vmunix: [    1.392751] xhci_hcd 0000:00:14.0: hcc params 0x200077c1 hci version 0x100 quirks 0x0000000000009810
May 29 12:35:10 localhost vmunix: [    1.393050] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.17
May 29 12:35:10 localhost vmunix: [    1.393057] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
May 29 12:35:10 localhost vmunix: [    1.393062] usb usb1: Product: xHCI Host Controller
May 29 12:35:10 localhost vmunix: [    1.393065] usb usb1: Manufacturer: Linux 5.17.11-gnu xhci-hcd
May 29 12:35:10 localhost vmunix: [    1.393069] usb usb1: SerialNumber: 0000:00:14.0
May 29 12:35:11 localhost vmunix: [    1.393645] hub 1-0:1.0: USB hub found
May 29 12:35:11 localhost vmunix: [    1.393669] hub 1-0:1.0: 6 ports detected
May 29 12:35:11 localhost vmunix: [    1.394524] xhci_hcd 0000:00:14.0: xHCI Host Controller
May 29 12:35:11 localhost vmunix: [    1.394534] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 2
May 29 12:35:11 localhost vmunix: [    1.394543] xhci_hcd 0000:00:14.0: Host supports USB 3.0 SuperSpeed
May 29 12:35:11 localhost vmunix: [    1.394652] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.17
May 29 12:34:50 localhost elogind[341]: Watching system buttons on /dev/input/event4 (Darfon HP USB Keyboard)
May 29 12:35:11 localhost vmunix: [    1.394659] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
May 29 12:35:11 localhost vmunix: [    1.394664] usb usb2: Product: xHCI Host Controller
May 29 12:35:11 localhost vmunix: [    1.394667] usb usb2: Manufacturer: Linux 5.17.11-gnu xhci-hcd
May 29 12:35:11 localhost vmunix: [    1.394670] usb usb2: SerialNumber: 0000:00:14.0
May 29 12:35:11 localhost vmunix: [    1.395217] hub 2-0:1.0: USB hub found
May 29 12:35:12 localhost vmunix: [    1.395243] hub 2-0:1.0: 1 port detected
May 29 12:35:12 localhost vmunix: [    1.395581] i8042: PNP: No PS/2 controller found.
May 29 12:35:12 localhost vmunix: [    1.395584] i8042: Probing ports directly.
May 29 12:35:12 localhost vmunix: [    1.396141] serio: i8042 KBD port at 0x60,0x64 irq 1
May 29 12:35:12 localhost vmunix: [    1.396153] serio: i8042 AUX port at 0x60,0x64 irq 12
May 29 12:35:12 localhost vmunix: [    1.396481] mousedev: PS/2 mouse device common for all mice
May 29 12:35:12 localhost vmunix: [    1.396980] rtc_cmos 00:00: RTC can wake from S4
May 29 12:35:12 localhost vmunix: [    1.397736] rtc_cmos 00:00: registered as rtc0
May 29 12:35:12 localhost vmunix: [    1.397770] rtc_cmos 00:00: setting system clock to 2022-05-29T10:33:31 UTC (1653820411)
May 29 12:35:13 localhost vmunix: [    1.397817] rtc_cmos 00:00: alarms up to one month, y3k, 242 bytes nvram
May 29 12:35:13 localhost vmunix: [    1.397843] i2c_dev: i2c /dev entries driver
May 29 12:34:52 localhost NetworkManager[339]: <info>  [1653820492.6955] manager[0xfdb000]: monitoring kernel firmware directory '/lib/firmware'.
--8<---------------cut here---------------end--------------->8---

The “vmunix” messages take 3 seconds to get logged, although they
correspond to events that occurred in ~0.5 second before syslogd was
started.

During boot up on that machine, if you go to tty12, where syslogd relays
messages, you can indeed see those lines getting displayed pretty slowly.

Has anyone experienced that?

Thanks,
Ludo’.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.