TW mystery console boot message: [ 5.299369]
I'm seeing a sole console message during splash=silent boots. The message is a number in square brackets, for example [ 5.299369]. The value is always padded with leading spaces and is roughly in the range 5.* to 6.*. It appears some time between the boot splash and X11/sddm startup. This makes me suspect it could be something like the seconds from boot to login prompt. If I switch from sddm to a console, I can see the same message just above the "Welcome to OpenSUSE Tumbleweed..." Is everyone seeing such a message? On a related issue, I also see "eth0: <ipv4-address> <mac-address>" just below the "Welcome to OpenSUSE Tumbleweed...". Is that new, I can't say I'd noticed that before. No big deal, just a bit curious. BTW - I'm using the proprietary Nvidia driver, which might make my bootup messages a bit different than the norm. Michael
* Michael Hamilton <michael@actrix.gen.nz> [03-04-21 15:47]:
I'm seeing a sole console message during splash=silent boots. The message is a number in square brackets, for example [ 5.299369]. The value is always padded with leading spaces and is roughly in the range 5.* to 6.*. It appears some time between the boot splash and X11/sddm startup. This makes me suspect it could be something like the seconds from boot to login prompt.
If I switch from sddm to a console, I can see the same message just above the "Welcome to OpenSUSE Tumbleweed..."
Is everyone seeing such a message?
On a related issue, I also see "eth0: <ipv4-address> <mac-address>" just below the "Welcome to OpenSUSE Tumbleweed...". Is that new, I can't say I'd noticed that before.
No big deal, just a bit curious.
BTW - I'm using the proprietary Nvidia driver, which might make my bootup messages a bit different than the norm.
such as: ----- enp0s25: 192.168.1.10 2600:1700:6010:1ab0:76ca:5ed:3b11:b98c enp7s0: enp9s2: ----- fwiw, I have seen this for several years now and am also using nvidia drivers. -- (paka)Patrick Shanahan Plainfield, Indiana, USA @ptilopteri http://en.opensuse.org openSUSE Community Member facebook/ptilopteri Photos: http://wahoo.no-ip.org/piwigo paka @ IRCnet freenode
On 04/03/2021 21.43, Michael Hamilton wrote:
I'm seeing a sole console message during splash=silent boots. The
message is a number in square brackets, for example [ 5.299369].
Run the command "dmesg" in a terminal and you will see that type of message: [ 5.299860] xhci_hcd 0000:03:00.0: xHCI Host Controller Yes, it is seconds since boot, but the text is missing in your case. No idea way. -- Cheers / Saludos, Carlos E. R. (from 15.2 x86_64 at Telcontar)
On Friday 05 March 2021, Carlos E. R. wrote:
On 04/03/2021 21.43, Michael Hamilton wrote:
I'm seeing a sole console message during splash=silent boots. The
message is a number in square brackets, for example [ 5.299369].
Run the command "dmesg" in a terminal and you will see that type of message:
[ 5.299860] xhci_hcd 0000:03:00.0: xHCI Host Controller
Yes, it is seconds since boot, but the text is missing in your case. No idea way.
Thanks for the help. The format did look familiar - the penny drops. So I tried to find a matching message in the output from dmesg. There is a completely blank line with no time info just afer 5.299361: [ 5.292426] asus_wmi: ASUS WMI generic driver loaded [ 5.299361] nvidia-nvlink: Nvlink Core is being initialized, major device number 239 [ 5.317772] nvidia 0000:01:00.0: vgaarb: changed VGA decodes: olddecodes=io+mem,decodes=none:owns=io+mem [ 5.360488] NVRM: loading NVIDIA UNIX x86_64 Kernel Module 460.56 Tue Feb 23 23:31:36 UTC 2021 [ 5.375472] asus_wmi: Initialization: 0x0 The blank appears in output from journalctrl --boot as well: Mar 05 07:21:16 kosmos1 kernel: nvidia-nvlink: Nvlink Core is being initialized, major device number 239 Mar 05 07:21:16 kosmos1 systemd[1]: Condition check resulted in Lock Directory being skipped. <..omitted other systemd messages..> Mar 05 07:21:16 kosmos1 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Mar 05 07:21:16 kosmos1 kernel: Mar 05 07:21:16 kosmos1 kernel: nvidia 0000:01:00.0: vgaarb: changed VGA decodes: olddecodes=io+mem,decodes=none:owns=io+mem Mar 05 07:21:16 kosmos1 systemd[1]: Starting Create Volatile Files and Directories... It looks most likely that the Nvidia driver is responsible for the blank. Looking at the entire dmesg, this appears to be the only time a blank appears in the dmesg output. It may be that kernel logging or the capture of kernel logging has problems with empty lines or lines containing linefeeds, carriage-returns, or possibly other weird characters. Or perhaps the initialisation of the graphics drive causes a hiphup in output redirected. Anyway, I think my curiosity is satisfied. Michael
On 05/03/2021 01.42, Michael Hamilton wrote:
On Friday 05 March 2021, Carlos E. R. wrote:
On 04/03/2021 21.43, Michael Hamilton wrote:
I'm seeing a sole console message during splash=silent boots. The
message is a number in square brackets, for example [ 5.299369].
Run the command "dmesg" in a terminal and you will see that type of message:
[ 5.299860] xhci_hcd 0000:03:00.0: xHCI Host Controller
Yes, it is seconds since boot, but the text is missing in your case. No idea way.
Thanks for the help. The format did look familiar - the penny drops.
So I tried to find a matching message in the output from dmesg. There is a completely blank line with no time info just afer 5.299361:
[ 5.292426] asus_wmi: ASUS WMI generic driver loaded [ 5.299361] nvidia-nvlink: Nvlink Core is being initialized, major device number 239
[ 5.317772] nvidia 0000:01:00.0: vgaarb: changed VGA decodes: olddecodes=io+mem,decodes=none:owns=io+mem [ 5.360488] NVRM: loading NVIDIA UNIX x86_64 Kernel Module 460.56 Tue Feb 23 23:31:36 UTC 2021 [ 5.375472] asus_wmi: Initialization: 0x0
Could be an extra line feed in the text of the previous message. If you are that curious, you could look in the nvidia kernel module sources and try to find that text ;-)
The blank appears in output from journalctrl --boot as well:
Mar 05 07:21:16 kosmos1 kernel: nvidia-nvlink: Nvlink Core is being initialized, major device number 239 Mar 05 07:21:16 kosmos1 systemd[1]: Condition check resulted in Lock Directory being skipped. <..omitted other systemd messages..> Mar 05 07:21:16 kosmos1 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Mar 05 07:21:16 kosmos1 kernel: Mar 05 07:21:16 kosmos1 kernel: nvidia 0000:01:00.0: vgaarb: changed VGA decodes: olddecodes=io+mem,decodes=none:owns=io+mem Mar 05 07:21:16 kosmos1 systemd[1]: Starting Create Volatile Files and Directories...
It looks most likely that the Nvidia driver is responsible for the blank.
Looking at the entire dmesg, this appears to be the only time a blank appears in the dmesg output. It may be that kernel logging or the capture of kernel logging has problems with empty lines or lines containing linefeeds, carriage-returns, or possibly other weird characters. Or perhaps the initialisation of the graphics drive causes a hiphup in output redirected.
Anyway, I think my curiosity is satisfied.
The strange thing to me is that only that line is printed, not that the line is empty :-) -- Cheers / Saludos, Carlos E. R. (from 15.2 x86_64 at Telcontar)
On 3/4/21 9:44 PM, Carlos E. R. wrote:
[ 5.292426] asus_wmi: ASUS WMI generic driver loaded [ 5.299361] nvidia-nvlink: Nvlink Core is being initialized, major device number 239
[ 5.317772] nvidia 0000:01:00.0: vgaarb: changed VGA decodes: olddecodes=io+mem,decodes=none:owns=io+mem <snip>
Could be an extra line feed in the text of the previous message. If you are that curious, you could look in the nvidia kernel module sources and try to find that text ;-)
Concur, looks like an additional line-feed after 239. No rhyme or reason why other than Nvidia. There may be some (whatever openSUSE uses for boot spash now) logic that suppresses normal messages, but displays any lines that are malformed or empty using the last valid timestamp. That is a guess! (I haven't and have no plans to explore that source :) -- David C. Rankin, J.D.,P.E.
On Friday 05 March 2021, David C. Rankin wrote:
On 3/4/21 9:44 PM, Carlos E. R. wrote:
[ 5.292426] asus_wmi: ASUS WMI generic driver loaded [ 5.299361] nvidia-nvlink: Nvlink Core is being initialized, major device number 239
[ 5.317772] nvidia 0000:01:00.0: vgaarb: changed VGA decodes: olddecodes=io+mem,decodes=none:owns=io+mem <snip>
Could be an extra line feed in the text of the previous message. If you are that curious, you could look in the nvidia kernel module sources and try to find that text ;-)
Concur, looks like an additional line-feed after 239. No rhyme or reason why other than Nvidia. There may be some (whatever openSUSE uses for boot spash now) logic that suppresses normal messages, but displays any lines that are malformed or empty using the last valid timestamp.
That is a guess! (I haven't and have no plans to explore that source :)
OK - perhaps I'm still a bit curious... I put on my dusty old C programming hat and took a guess. I found I can log a empty line lacking a timestamp to /dev/kmsg by doing the following: echo -e "x" > /dev/kmsg; echo -e "\0" > /dev/kmsg; echo -e "\0" > /dev/kmsg; This doesn't come up on the console, but perhaps that because I'm not in some special stage of booting, but it does create a totally timestamp-less blank line in the dmesg output and this does also get logged to the journal. So maybe something (the nvidia driver) is logging one or more null strings. Invoking such bad behaviour from user space is a little worrying, but at least it can only be done from root. I wonder what else is possible? Michael
On 05/03/2021 07.47, Michael Hamilton wrote:
On Friday 05 March 2021, David C. Rankin wrote:
On 3/4/21 9:44 PM, Carlos E. R. wrote:
...
OK - perhaps I'm still a bit curious... I put on my dusty old C programming hat and took a guess. I found I can log a empty line lacking a timestamp to /dev/kmsg by doing the following:
echo -e "x" > /dev/kmsg; echo -e "\0" > /dev/kmsg; echo -e "\0" > /dev/kmsg;
This doesn't come up on the console, but perhaps that because I'm not in some special stage of booting, but it does create a totally timestamp-less blank line in the dmesg output and this does also get logged to the journal. So maybe something (the nvidia driver) is logging one or more null strings.
Invoking such bad behaviour from user space is a little worrying, but at least it can only be done from root. I wonder what else is possible?
Maybe bad behaviour, but not dangerous and allows you to log things there if there is a need. I don't see now why there would be a need, though. -- Cheers / Saludos, Carlos E. R. (from 15.2 x86_64 at Telcontar)
participants (4)
-
Carlos E. R. -
David C. Rankin -
Michael Hamilton -
Patrick Shanahan