Long boot times (~ 4min)

Help with booting MiniMyth

Moderator: Pablo

Post Reply
ph0t0nix
Member
Posts: 34
Joined: Sat Apr 07, 2007 5:36 pm
Location: Europe

Long boot times (~ 4min)

Post by ph0t0nix » Mon Jun 23, 2008 8:19 pm

I recently upgraded to ram-minimyth-0.21.0-52 from 0.20-25 an ever since I've had extremely long boot times. From the first DHCP request in my server's log till the moment the theme cache files are requested over tftp about 4 minutes have past. Booting used to be much quicker.
Most time is spent with the following messages on screen: "Loading kernel modules (automatic)" and "Checking for obsolete variables". Both take about one minute each.

I just upgraded to ram-minimyth-0.21.0-55 but that didn't resolve this problem.

My frontend is an ASUS Pundit P1-AH2, described here.

Pablo
Site Admin
Posts: 4182
Joined: Tue Dec 14, 2004 2:13 am
Location: La Jolla
Contact:

Post by Pablo » Mon Jun 23, 2008 8:58 pm

Based on what you describe, I would suspect that there is some kernel module that is failing. I believe that 25 uses Linux 2.6.17 and 55 uses Linux 2.6.23. Is their anything in /var/log/messages that looks strange; that looks like it takes a long time?
MiniMyth running on an Acer ApireRevo 3610 and a Zotac ZBOX-ID80-U. Find out more at my MythTV page.

ph0t0nix
Member
Posts: 34
Joined: Sat Apr 07, 2007 5:36 pm
Location: Europe

Post by ph0t0nix » Mon Jun 23, 2008 9:15 pm

Nothing stands out in particular. Apparently loading the kernel modules takes 1 minute and so does the obsolete variable check:

Code: Select all

Jun 23 19:08:33 (none) local0.info udhcpc[1102]: Lease of 192.168.10.59 obtained, lease time 3600
Jun 23 19:08:33 (none) local0.info minimyth: loading kernel modules (automatic) ...
Jun 23 19:09:35 (none) local0.info minimyth: downloading configuration ...
Jun 23 19:09:35 (none) local0.info minimyth: 'tftp://192.168.10.10/PXEClient/conf/lambik.karssen.org/minimyth.conf' downloaded.
Jun 23 19:09:35 (none) local0.info minimyth: processing configuration ...
Jun 23 19:09:35 (none) local0.info minimyth: checking for obsolete variables ...
Jun 23 19:10:37 (none) local0.info minimyth: stopping DHCP client ...
Jun 23 19:10:37 (none) local0.info udhcpc[1201]: Received SIGTERM
Jun 23 19:10:37 (none) local0.info minimyth: starting DHCP client ...
The processing of the MM_ variables takes about 3 seconds.

By the way, is syslogd supposed to exit (the jump to 21:10 most likely has to do with the time zone change or NTP sync)?

Code: Select all

Jun 23 21:10:42 (none) local0.info minimyth: processing configuration: fetching additional files 'MM_WIIMOTE'
Jun 23 21:10:42 (none) local0.info minimyth: processing configuration: fetching additional files 'MM_X'
Jun 23 21:10:42 (none) local0.info minimyth: 'tftp://192.168.10.10/PXEClient/conf/lambik.karssen.org/xorg.conf' downloaded.
Jun 23 21:10:42 (none) local0.info minimyth: loading kernel modules (manual) ...
Jun 23 21:10:42 (none) local0.info minimyth: starting system logging ...
Jun 23 21:10:43 (none) syslog.info syslogd exiting

Pablo
Site Admin
Posts: 4182
Joined: Tue Dec 14, 2004 2:13 am
Location: La Jolla
Contact:

Post by Pablo » Mon Jun 23, 2008 9:48 pm

In both cases, udev is triggered/retriggered. While there is not message, between "checking for obsolete variables ..." and "stopping DHCP client ...", MiniMyth retriggers udev.

If you run

Code: Select all

/sbin/udevadm trigger
/sbin/udevadm settle --timeout=60
how long does it take?
MiniMyth running on an Acer ApireRevo 3610 and a Zotac ZBOX-ID80-U. Find out more at my MythTV page.

ph0t0nix
Member
Posts: 34
Joined: Sat Apr 07, 2007 5:36 pm
Location: Europe

Post by ph0t0nix » Mon Jun 23, 2008 10:02 pm

Code: Select all

# date && /sbin/udevadm trigger && date &&  /sbin/udevadm settle  -timeout=60 && date
Mon Jun 23 22:58:08 CEST 2008
Mon Jun 23 22:58:08 CEST 2008
That's one date too few. So I guess the udevadm settle command finishes with an error.

Code: Select all

# date && /sbin/udevadm trigger && date &&  /sbin/udevadm settle --timeout=60 ; date
Mon Jun 23 23:00:36 CEST 2008
Mon Jun 23 23:00:36 CEST 2008
Mon Jun 23 23:01:37 CEST 2008
So it's the udevadm settle that takes a minute, as to be expected.

Running udevadm monitor at another terminal and running udevadm trigger and udevadm settle shows that it halts after

Code: Select all

UEVENT[1214255122.067607] add      /devices/virtual/tty/tty8 (tty)
UEVENT[1214255122.067683] add      /devices/virtual/tty/tty9 (tty)
UEVENT[1214255122.067768] add      /devices/virtual/vc/vcs (vc)
UEVENT[1214255122.067862] add      /devices/virtual/vc/vcs1 (vc)
UEVENT[1214255122.067939] add      /devices/virtual/vc/vcs2 (vc)
UEVENT[1214255122.068029] add      /devices/virtual/vc/vcsa (vc)
UEVENT[1214255122.068120] add      /devices/virtual/vc/vcsa1 (vc)
UEVENT[1214255122.068201] add      /devices/virtual/vc/vcsa2 (vc)
UEVENT[1214255122.068279] add      /devices/virtual/vtconsole/vtcon0 (vtconsole)
UEVENT[1214255122.068368] add      /devices/virtual/vtconsole/vtcon1 (vtconsole)
Maybe that helps?!

Post Reply