I have a 12.1/KDE4.80 system that today(1-30-12) got a kernel update via YAST, to 3.1.9-1.4-desktop.
There were also many “normal” updates downloaded at the same time (2 day’s worth)
The log in /var/log/zypp/history does no show anything unusual.
This system has an Nvidia card, I run NvidiaTHW using James’ lnvhw (ver 1.2.0) script.
After the downloads and install were complete, I rebooted to level 3 and ran (as root) the lnvhw script, which ran OK, after which I rebooted again.
I have been booting with systemd, which I believe is the default for new installs. No issues when system first installed.
After this update, I found that booting with systemd would hang, early in the boot process, after a few rows of systemd-fsck declaring the partitions “clean”. After waiting for over a minute, I rebooted, to Level 3.
The boot process paused again at the partition checks, then after 5 or so seconds gave me the level 3 login prompt.
I logged in as root, ran init 3, then init 5 and the “normal” kdm greeter was displayed.
I was able to login to KDE as my normal user and the system seemed OK.
Out of curiosity, I shutdown and rebooted, this time with system V, and the boot process proceeded to level 5 without a hitch.
I believe systemd is the direction of the future.
Any thoughts on why systemd is now misbehaving?
On 2012-01-31 00:16, cmcgrath5035 wrote:
>
> Any hints on how to capture early boot console output (for inclusion in
> bug report), for the case where it "freezes?
Hum! If it is not in /var/log/messages (systemd does not use boot.msg) then
the classical method is a real serial port. You add “console=tty9
console=ttyS0,38400” or equivalent to the kernel boot options, and connect
your serial port to another machine. Mind: the machine booting up needs a
real hardware serial port. The machine receiving the data can use a 232-usb
converter.
However… I tried this myself in 12.1 with systemd, and the log file was
way less verbose than it was previously on other versions.
–
Cheers / Saludos,
Carlos E. R.
(from 11.4 x86_64 “Celadon” at Telcontar)
On Mon, 30 Jan 2012 23:16:04 +0000, cmcgrath5035 wrote:
> Any hints on how to capture early boot console output (for inclusion in
> bug report), for the case where it "freezes?
>
> I don’t think boot.msg has anything useful and for some reason there is
> no boot.omsg.
Updated today on 32bit OS and re-installing nvidia graphics driver
Re-booting took a long time and PC was very slow. Culprit appeared to be
kactivitymanager consumming all residual cpu time, hence cpu useage stayed at 100%, > 10 minutes
After two reboots cpu useage dropped a little to about 90%
After de-activating Nepomuk all was back to normal
Thanks, Carlos for the Serial Port method, I actually think that mobo has one.
In this case, the camera would have been adequate as the stall was only about 20 lines in.
And yes, the reason no boot.omsg file was that the system had only booted once with System V (which uses boot.msg), there was no old file.
ANYWAY, as an experiment, I rebooted the machine(systemd), it stalled and I went off to dinner.
45 minutes or so I returned, and a greeter was waiting for me. So now I am off to see if I am experiencing was similar to that of keellambert.
Perhaps something will be visible in messages.
Nepomuk is already shut down on this machine, but I believe the “stall” is much earlier in the startup process.
> Thanks, Carlos for the Serial Port method, I actually think that mobo
> has one.
It is a good thing to have. Old hardware has it uses
> but I believe the “stall”
> is much earlier in the startup process.
There is a nice tool with systemd:
systemd-analyze plot > plot.svg
then you can visualize the plot file and find out where the boot process
gets stuck. Or, instead of plot you can get a time table; the other options
are “time” and “blame”.
–
Cheers / Saludos,
Carlos E. R.
(from 11.4 x86_64 “Celadon” at Telcontar)
Update:
I determined by experimentation that the boot process stalls for 5 minutes.
Here are some lines from /var/log/messages
Jan 30 21:14:05 PVE-Beast ifup: eth0 Startmode is 'off'
Jan 30 21:14:05 PVE-Beast network[904]: ..skipped eth1 device: nVidia Corporation MCP55 Ethernet
Jan 30 21:14:05 PVE-Beast ifup: eth1 device: nVidia Corporation MCP55 Ethernet
Jan 30 21:14:05 PVE-Beast kernel: 13.897558] forcedeth 0000:00:11.0: irq 42 for MSI/MSI-X
Jan 30 21:14:05 PVE-Beast kernel: 13.897746] forcedeth 0000:00:11.0: eth1: no link during initialization
Jan 30 21:14:05 PVE-Beast kernel: 13.898963] ADDRCONF(NETDEV_UP): eth1: link is not ready
Jan 30 21:14:05 PVE-Beast ifup: eth1
Jan 30 21:14:05 PVE-Beast ifup: IP address: 192.168.10.40/24
Jan 30 21:14:05 PVE-Beast network[904]: eth1 IP address: 192.168.10.40/24
Jan 30 21:14:05 PVE-Beast ifup:
Jan 30 21:14:05 PVE-Beast avahi-daemon[960]: Joining mDNS multicast group on interface eth1.IPv4 with address 192.168.10.40.
Jan 30 21:14:05 PVE-Beast avahi-daemon[960]: New relevant interface eth1.IPv4 for mDNS.
Jan 30 21:14:05 PVE-Beast avahi-daemon[960]: Registering new address record for 192.168.10.40 on eth1.IPv4.
Jan 30 21:14:06 PVE-Beast kernel: 14.776245] forcedeth 0000:00:11.0: eth1: link up
Jan 30 21:14:06 PVE-Beast kernel: 14.778909] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
Jan 30 21:19:04 PVE-Beast systemd[1]: network.service operation timed out. Terminating.
Jan 30 21:19:04 PVE-Beast systemd[1]: Unit network.service entered failed state.
At first I thought this was related to eth0.
The mobo here has 2 ethernet connections. I don’t use eth0, and eth1 is set to a static address
eth0 is set to start on cable connection (or never -makes no difference).
On closer look, eth0 appears to be properly recognized as not starting.
So I am still searching for what is causing the failure/timeout (highlighted)
On 2012-01-31 04:06, cmcgrath5035 wrote:
>
> Update:
> I determined by experimentation that the boot process stalls for 5
> minutes.
> Here are some lines from /var/log/messages
Smells of bug.
–
Cheers / Saludos,
Carlos E. R.
(from 11.4 x86_64 “Celadon” at Telcontar)
I tried out the systemd-analyze tool,
The **systemd-analyze plot **generated an output with “network.service” taking a long time.
For reason I don’t understand, the output of systemd-analyze blame which appears to be sorted list of execution times of the startup processes in descending order, the top 20 of which sum to <25000ms, does not have network.service on the list at all.
Following comment by virex, I changed the eth1 interface to IPV4-DHCP.
The booth process still stalls at the same point, but only for a few seconds, then proceeds.
I do note in /var/log/messages:
........
Jan 31 08:51:01 PVE-Beast network[909]: ..done eth0 device: nVidia Corporation MCP55 Ethernet
Jan 31 08:51:01 PVE-Beast ifup: eth0 device: nVidia Corporation MCP55 Ethernet
Jan 31 08:51:01 PVE-Beast network[909]: eth0 Startmode is 'off'
Jan 31 08:51:01 PVE-Beast ifup: eth0 Startmode is 'off'
Jan 31 08:51:01 PVE-Beast network[909]: ..skipped eth1 device: nVidia Corporation MCP55 Ethernet
Jan 31 08:51:01 PVE-Beast ifup: eth1 device: nVidia Corporation MCP55 Ethernet
Jan 31 08:51:01 PVE-Beast kernel: 14.213673] forcedeth 0000:00:11.0: irq 42 for MSI/MSI-X
Jan 31 08:51:01 PVE-Beast kernel: 14.213892] forcedeth 0000:00:11.0: eth1: no link during initialization
Jan 31 08:51:01 PVE-Beast kernel: 14.216780] ADDRCONF(NETDEV_UP): eth1: link is not ready
Jan 31 08:51:01 PVE-Beast ifup-dhcp: eth1 Starting DHCP4 client
Jan 31 08:51:01 PVE-Beast dhcpcd[1471]: eth1: dhcpcd 3.2.3 starting
Jan 31 08:51:01 PVE-Beast dhcpcd[1471]: eth1: hardware address = 00:1a:92:d3:f3:a7
Jan 31 08:51:01 PVE-Beast kernel: 14.280566] NET: Registered protocol family 17
Jan 31 08:51:01 PVE-Beast dhcpcd[1471]: eth1: broadcasting for a lease
Jan 31 08:51:01 PVE-Beast ifup-dhcp: .
Jan 31 08:51:02 PVE-Beast kernel: 15.467924] forcedeth 0000:00:11.0: eth1: link up
Jan 31 08:51:02 PVE-Beast kernel: 15.469049] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
Jan 31 08:51:04 PVE-Beast ifup-dhcp: .
Jan 31 08:51:04 PVE-Beast dhcpcd[1471]: eth1: offered 192.168.10.40 from 192.168.10.1
Jan 31 08:51:04 PVE-Beast dhcpcd[1471]: eth1: checking 192.168.10.40 is available on attached networks
Jan 31 08:51:05 PVE-Beast dhcpcd[1471]: eth1: leased 192.168.10.40 for infinity
Jan 31 08:51:05 PVE-Beast dhcpcd[1471]: eth1: adding IP address 192.168.10.40/24
Jan 31 08:51:05 PVE-Beast avahi-daemon[995]: Joining mDNS multicast group on interface eth1.IPv4 with address 192.168.10.40.
Jan 31 08:51:05 PVE-Beast avahi-daemon[995]: New relevant interface eth1.IPv4 for mDNS.
Jan 31 08:51:05 PVE-Beast avahi-daemon[995]: Registering new address record for 192.168.10.40 on eth1.IPv4.
Jan 31 08:51:06 PVE-Beast ifdown: eth1 device: nVidia Corporation MCP55 Ethernet (rev a2)
Jan 31 08:51:06 PVE-Beast ifup: eth1 device: nVidia Corporation MCP55 Ethernet (rev a2)
Jan 31 08:51:06 PVE-Beast ifup-dhcp: .
Jan 31 08:51:09 PVE-Beast ifup-dhcp: .
Jan 31 08:51:11 PVE-Beast ifup-dhcp: .
Jan 31 08:51:13 PVE-Beast ifup-dhcp: .
Jan 31 08:51:16 PVE-Beast ifup-dhcp: .
Jan 31 08:51:18 PVE-Beast ifup-dhcp: .
Jan 31 08:51:19 PVE-Beast network[909]: eth1 Starting DHCP4 client. . . . . . . .
Jan 31 08:51:19 PVE-Beast ifup-dhcp:
Jan 31 08:51:19 PVE-Beast network[909]: eth1 DHCP4 continues in background
Jan 31 08:51:19 PVE-Beast ifup-dhcp: eth1 DHCP4 continues in background
Jan 31 08:51:19 PVE-Beast network[909]: [1Awaiting
Jan 31 08:51:20 PVE-Beast network[909]: Waiting for mandatory devices: eth1
Jan 31 08:51:32 PVE-Beast network[909]: 11 10 8 7 6 5 4 2 1 0
Jan 31 08:51:32 PVE-Beast network[909]: eth1 device: nVidia Corporation MCP55 Ethernet
Jan 31 08:51:32 PVE-Beast network[909]: eth1 . . . is just beeing set up
Jan 31 08:51:32 PVE-Beast network[909]: eth1 IP address: 192.168.10.40/24
Jan 31 08:51:32 PVE-Beast network[909]: eth1 is up
Jan 31 08:51:32 PVE-Beast network[909]: [1Awaiting
Jan 31 08:51:32 PVE-Beast network[909]: eth1 interface could not be set up until now
Jan 31 08:51:32 PVE-Beast network[909]: ..failedSetting up service (localfs) network . . . . . . . . . ...failed
Jan 31 08:51:32 PVE-Beast systemd[1]: network.service: control process exited, code=exited status=7
Jan 31 08:51:32 PVE-Beast systemd[1]: Unit network.service entered failed state.
......
I assume the highlighted three rows in the log are telling me something, not sure what yet.
Bug?, perhaps, or maybe a hyper-sensitivity to a previously ignored or unimportant setting.
I’ll continue to dig a bit.
I’d comment that if my world was all DHCP, I probably would not have even noticed this, but peobably would have said that the system booted “a little slower” after the upgrade.
After search Bugzilla, this looks like Bug 725503 - multiminute hang/delay during systemd boot
which, if I read the thread correctly, is fixed as of 1/30/2012.
While it is not obvious that Samba is involved from the log files, the parallelism introduced by systemd ( a good thing, when it works) makes it a bit more difficult to track.
I did enable Samba after the initial install - but tend to sleep, not reboot my system.
It is quite possible that my problem appeared on the first reboot after enabling Samba, and is in fact not related to the updates I received (both to kernel and systemd).
I plan to wait a couple days for the fixes to propagate.
