Mysterious 12 minute pause in boot

General support questions
ktrampe
Posts: 21
Joined: 2018/02/20 22:39:56

Re: Mysterious 12 minute pause in boot

Post by ktrampe » 2018/02/21 20:09:24

TrevorH wrote: Then you did it incorrectly as removing rhgb quiet from the kernel command line should disable that splash screen completely and just leave you looking at thousands of kernel messages as they scroll past.
Sorry, I was wrong about the "exact" part. It does change what it says right before the "Welcome to CentOS Linux 7 (Core)!" line, it does list many, many kernel messages, but those all fly by very fast. Here's what I'm doing:

1. Power on machine
2. At the grub screen I press the e key.
3. This loads the grub editor. I look for the line that says: linux16 /vmlinuz-3.10.0-229.11.1.el7.x86_64... etc
4. I remove rhgb quiet from that line, then press ctrl-x.
5. Many many lines fly by very quickly, then it stops at the "Welcome to CentOS Linux 7 (Core)!" message. There are a few empty lines below it and a flashing cursor, and there it sits for 12 minutes.

Code: Select all

[   OK   ] Mounted /sysroot.
[   OK   ] Reached target Initrd Root File System.
              Starting Reload Configuration from the Real Root...
[   OK   ] Started Reload Configuration from the Real Root.
[   OK   ] Reached target Initrd File Systems.
[   OK   ] Reached target Initrd Default Target.
[       7.798966] system-journald[188]: Received SIGTERM
[       8.852904] SELinux: Disabled at runtime.
[       8.876058] type=1404 audit(1519047576.325:2): selinux=0 auid=4294967295 ses=4294967295
[       8.999790] system[1]: RTC configured in local time, applying delta of -360 minutes to system time.

Welcome to CentOS Linux 7 (Core)!

_ <-- Flashing cursor here for 12 minutes...
6. Then, after 12 minutes it says:

Code: Select all

[   OK   ] Stopped Switch Root.
[   OK   ] Stopped target Switch Root.
[   OK   ] Stopped target Initrd File Systems.
7. ... and proceeds to boot in just a few seconds to the login.

Does it have something to do with the "Stopped Switch Root" line? That's the first thing it says right after the 12 minute hang.

Thanks again so much!

User avatar
TrevorH
Forum Moderator
Posts: 23458
Joined: 2009/09/24 10:40:56
Location: Brighton, UK

Re: Mysterious 12 minute pause in boot

Post by TrevorH » 2018/02/21 20:19:19

[ 8.999790] system[1]: RTC configured in local time, applying delta of -360 minutes to system time.
That's the only odd thing I see there.
CentOS 5 died in March 2017 - migrate NOW!
Full time Geek, part time moderator. Use the FAQ Luke

ktrampe
Posts: 21
Joined: 2018/02/20 22:39:56

Re: Mysterious 12 minute pause in boot

Post by ktrampe » 2018/02/21 20:56:10

TrevorH wrote:
That's the only odd thing I see there.
Hmm, do you think there could be a problem with time?

desertcat
Posts: 434
Joined: 2014/08/07 02:17:29
Location: Tucson, AZ

Re: Mysterious 12 minute pause in boot

Post by desertcat » 2018/02/22 08:11:31

ktrampe wrote:
TrevorH wrote:
That's the only odd thing I see there.
Hmm, do you think there could be a problem with time?
While I have yet to encounter that problem with CentOS 7.x, I have encountered it many times, though in my case as it was blazing through the
[OK]
[OK]
etc.
It would hang when it reached [starting ntpd] clearly searching for a ntp source and then it would hang there for 12-15 minutes before, as you said, it then proceeds on its merry way towards logging in. In short the service "timed out".

There *could* be two sources to check *IF* it *IS* a time problem: 1) The time as saved on system board. If you have not changed your battery now might be the time to do it. I "rescued" an OLD HP Workstation that some one was throwing out and set next to the dumpster, which when I took it in was DOA, the problem was the battery, once I inserted a NEW battery, reset the BIOS clock, calendar, etc., etc., etc.It started right up, and has been running ever since. In short you might have a time drift problem, one time as saved by your BIOS and your system board, 2) and an external time sources which is runs against the system clock. So it hangs as it tries to figure out the correct time, trying to bring the two time sources into alignment. If the problem is a weak battery it is easy enough to buy a new battery, change, then you then go into BIOS, set a new time, date, etc., then reboot.

The other possibility is the system clock (ie BIOS) and the time you have imputed on the panel are way out of whack. I've seen this problem too, the last time however was with an IBM PS/2 286 back in the Days of DOS. The computer time was set and shipped by IBM for their local, and we lived in a different time zone which my boss set during some installation of some program. He when tried o reboot the machine it was DEAD! He tried to boot the machine for some hour, before he gave up, and went into BIOS changing things back to factory reset, then set the Time, and Date, etc., then he rebooted the machine and up it came. So you could check to see if the on-board time and your OS time in CentOS match. My GUESS is that your battery is starting to fail, or that your on-board system (BIOS), and your installation (CentOS) times are out of sync.

Keep us posted.

User avatar
TrevorH
Forum Moderator
Posts: 23458
Joined: 2009/09/24 10:40:56
Location: Brighton, UK

Re: Mysterious 12 minute pause in boot

Post by TrevorH » 2018/02/22 10:07:37

Hmm, do you think there could be a problem with time?
No idea but having the hardware clock set 6 hours before the current time might cause "interesting" things to happen and it's dead easy to change and find out if it helps.
CentOS 5 died in March 2017 - migrate NOW!
Full time Geek, part time moderator. Use the FAQ Luke

ktrampe
Posts: 21
Joined: 2018/02/20 22:39:56

Re: Mysterious 12 minute pause in boot

Post by ktrampe » 2018/02/22 18:12:40

I have spent a fair amount of time looking into time issues (no pun intended). :) I'm just not having any success. This OS is a guest OS on XenServer, and it is living next to a few other guest VMs, which all seem to be having no trouble with time or slow reboots. Yes, the host's clock is off by a few minutes (not 12, more like 7), but the other VMs are rebooting happily. I am thinking that the -360 mins message is just because our local TZ is -6 UTC.

As for a failing battery, I don't think that would apply in this scenario, given that the XenServer Host is not rebooting, it is just the guest VM rebooting.

Is there any other, more granular way of seeing what, exactly is going on during this 12 minute pause?

Can I "step through" the boot process somehow? This feels so much like some sort device timeout, I just don't see any evidence of it anywhere in the logs.

Why is there such a discrepancy between:

Code: Select all

systemd-analyze
Startup finished in 2.426s (kernel) + 3.214s (initrd) + 12min 9.114s (userspace) = 12min 14.755s
and

Code: Select all

systemd-analyze blame
         34.196s network.service
          4.685s lvm2-monitor.service
          2.208s boot.mount
          1.383s lvm2-pvscan@202:2.service
           527ms systemd-cryptsetup@swap.service
           294ms sendmail.service
           291ms systemd-vconsole-setup.service
           185ms systemd-tmpfiles-setup-dev.service
           180ms rhel-readonly.service
           136ms kmod-static-nodes.service
           134ms systemd-udev-trigger.service
           123ms sys-kernel-debug.mount
           101ms dev-hugepages.mount
           101ms dev-mqueue.mount
            99ms systemd-remount-fs.service
            98ms plymouth-read-write.service
            93ms rhel-import-state.service
            80ms systemd-sysctl.service
            62ms rhel-dmesg.service
            62ms sm-client.service
            59ms systemd-logind.service
            49ms dev-mapper-swap.swap
            40ms systemd-tmpfiles-clean.service
            37ms systemd-tmpfiles-setup.service
            33ms systemd-update-utmp.service
            29ms plymouth-start.service
            25ms systemd-random-seed.service
            24ms systemd-udevd.service
            12ms systemd-update-utmp-runlevel.service
             3ms systemd-journal-flush.service
             2ms sys-kernel-config.mount
If you add up all the lines in the "blame", the don't come anywhere near the 12 min user space.

Again, I appreciate time and attention. Thank you so much.

hunter86_bg
Posts: 1317
Joined: 2015/02/17 15:14:33
Location: Bulgaria
Contact:

Re: Mysterious 12 minute pause in boot

Post by hunter86_bg » 2018/02/22 18:19:46

You can generate the following plot:

Code: Select all

systemd-analyze plot > somefile
Then open the plot in a browser.It will show which service is waiting so much.

ktrampe
Posts: 21
Joined: 2018/02/20 22:39:56

Re: Mysterious 12 minute pause in boot

Post by ktrampe » 2018/02/22 18:30:10

hunter86_bg wrote:You can generate the following plot:

Code: Select all

systemd-analyze plot > somefile
Then open the plot in a browser.It will show which service is waiting so much.
Thanks hunter86_bg, I have done this and all I see is a 12 minute long blue line. See attached .svg.
Attachments
1.png
1.png (109.98 KiB) Viewed 2847 times

ktrampe
Posts: 21
Joined: 2018/02/20 22:39:56

Re: Mysterious 12 minute pause in boot

Post by ktrampe » 2018/02/22 19:17:41

Here's a zoomed in image of the upper-left-hand corner of the .svg:
Attachments
2.png
2.png (20.46 KiB) Viewed 2839 times

ktrampe
Posts: 21
Joined: 2018/02/20 22:39:56

Re: Mysterious 12 minute pause in boot

Post by ktrampe » 2018/02/22 19:19:05

... and here's the other end of the 12 minute long blue line:
Attachments
3.png
3.png (219.5 KiB) Viewed 2839 times

Post Reply