Bug 447142 - update-bootloader hangs kernel installation for >10 minutes
Summary: update-bootloader hangs kernel installation for >10 minutes
Status: RESOLVED FIXED
: 458284 (view as bug list)
Alias: None
Product: openSUSE 11.1
Classification: openSUSE
Component: Update Problems (show other bugs)
Version: Final
Hardware: x86 Other
: P2 - High : Critical (vote)
Target Milestone: ---
Assignee: E-mail List
QA Contact: Jiri Srain
URL:
Whiteboard: .
Keywords:
Depends on:
Blocks:
 
Reported: 2008-11-20 15:21 UTC by Jan Kupec
Modified: 2009-03-11 22:33 UTC (History)
4 users (show)

See Also:
Found By: ---
Services Priority:
Business Priority:
Blocker: ---
Marketing QA Status: ---
IT Deployment: ---


Attachments
tgz of /var/log/zypper & /var/log/zypper.solverTestCase (993.90 KB, application/x-gzip)
2008-11-20 20:17 UTC, Felix Miata
Details
menu.lst from most recent RC1 update-bootload run on host gx260 (4.36 KB, text/plain)
2008-11-30 06:57 UTC, Felix Miata
Details
menu.lst as I had left it prior to updating from 5.2 to RC1 with zypper (2.50 KB, text/plain)
2008-11-30 14:03 UTC, Felix Miata
Details
menu.lst.old (same timestamp as attachment 256784) (4.00 KB, text/plain)
2008-11-30 14:07 UTC, Felix Miata
Details
menu.lst prior to beginning comment 8 procedure (2.01 KB, text/plain)
2008-12-03 03:37 UTC, Felix Miata
Details
menu.lst.old resulting from comment 8 procedure (2.30 KB, text/plain)
2008-12-03 03:37 UTC, Felix Miata
Details
menu.lst resulting from comment 8 procedure (2.65 KB, text/plain)
2008-12-03 03:37 UTC, Felix Miata
Details
menu.lst as it is now that I cleaned it up again (1.81 KB, text/plain)
2008-12-03 03:37 UTC, Felix Miata
Details
patch for /usr/lib/perl5/vendor_perl/*/Bootloader/Tools.pm (630 bytes, patch)
2008-12-03 09:54 UTC, Josef Reidinger
Details | Diff
output of 'ps -A' & 'fuser -v -m /dev/hda22' while update-bootload running during kernel-default-base installation (3.19 KB, text/plain)
2008-12-03 16:07 UTC, Felix Miata
Details
tmon.out from host gx110 (296.08 KB, text/plain)
2008-12-08 15:38 UTC, Felix Miata
Details
tmon.out from comment 20 host (vizio) (77.01 KB, text/plain)
2008-12-09 18:42 UTC, Felix Miata
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Jan Kupec 2008-11-20 15:21:20 UTC
+++ This bug was initially created as a clone of Bug #446344 +++

to reproduce:
1-use system with many partitions (~15-40)
2-install new kernel via any standard method, e.g. rpm, smart or zypper

actual results:
1-installation of "kernel" takes long time (10 minutes or more), most of which top shows update-bootload, while ps -A shows many instances of hald-addon-stor

expect results:
1-installation of "kernel" takes only 3 minutes or less (on 2GHz P4)

comments:
1-the problem is compounded due to the split kernel packaging, which results in initrd being built at least once for each kernel subpackage
2-the problem is further compounded  by zypper installing multiple kernels (e.g. both default and pae) (I cooked, then ate, dinner, then filed this bug, all while zipper was installing the two latest default and pae kernels.)
3-mailing list thread containing extra details begins at: http://lists.opensuse.org/opensuse-factory/2008-11/msg00490.html
Comment 1 Felix Miata 2008-11-20 20:17:55 UTC
Created attachment 254083 [details]
tgz of /var/log/zypper & /var/log/zypper.solverTestCase

On a much slower Dell GX110 PIII 1000MHz I did essentially the same thing as comments 6 & 7 of bug 446344 but didn't first rpm -e any kernels and only created the solver at the end. Again, only the pae kernel was installed. The second dup run, which only reinstalled openSUSE-release and pae/pae-base kernel took about 25 minutes. Again, most of that 25 minutes according to top was spent on update-bootload, even though that run resulted in 0 changes to files in /boot/grub.
Comment 2 Felix Miata 2008-11-29 05:28:54 UTC
No improvement doing 2.6.27.7-3 kernels on 6 systems today. On one run I watched top while kernel-pae-extras was installed, and over 5 top cpu minutes were consumed by update-bootload on the gx110.
Comment 3 Felix Miata 2008-11-30 06:08:08 UTC
The same big delay happens with suspend updates, since suspend apparently also calls update-bootload. 
Comment 4 Felix Miata 2008-11-30 06:57:12 UTC
Created attachment 256771 [details]
menu.lst from most recent RC1 update-bootload run on host gx260

What a mess. :-(
Comment 5 Felix Miata 2008-11-30 14:03:15 UTC
Created attachment 256784 [details]
menu.lst as I had left it prior to updating from 5.2 to RC1 with zypper
Comment 6 Felix Miata 2008-11-30 14:07:56 UTC
Created attachment 256787 [details]
menu.lst.old (same timestamp as attachment 256784 [details])
Comment 7 Felix Miata 2008-11-30 14:10:12 UTC
Oops. s/attachment 256784 [details]/attachment 256771 [details]/.
Comment 8 Felix Miata 2008-12-03 03:33:17 UTC
Before starting on host gx150, I removed all prior kernels except 2.6.27.5-3 & 2.6.27.7-3 on PIII 1133MHz on i815 with 512M RAM. Using zypper, 
kernel-pae-base-2.6.27.7-4.1 took about 10 minutes to install
kernel-pae-2.6.27.7-4.1 took more than 12.5 minutes to install
suspend-0.80... took about 9 minutes to install
kernel-pae-extra- 2.6.27.7-4.1 took 16.5 minutes to install
Most of the time in each of the four was spent with update-bootload pegging CPU. The progress indicator for each spent more than 90% of the clock time showing ~94% completed. I doubt the other 1000+ packages upgrading from beta 5.2 to RC1  took collectively as long to install.
Comment 9 Felix Miata 2008-12-03 03:37:00 UTC
Created attachment 257551 [details]
menu.lst prior to beginning comment 8 procedure
Comment 10 Felix Miata 2008-12-03 03:37:06 UTC
Created attachment 257552 [details]
menu.lst.old resulting from comment 8 procedure
Comment 11 Felix Miata 2008-12-03 03:37:11 UTC
Created attachment 257553 [details]
menu.lst resulting from comment 8 procedure
Comment 12 Felix Miata 2008-12-03 03:37:17 UTC
Created attachment 257554 [details]
menu.lst as it is now that I cleaned it up again
Comment 13 Josef Reidinger 2008-12-03 09:54:55 UTC
Created attachment 257627 [details]
patch for /usr/lib/perl5/vendor_perl/*/Bootloader/Tools.pm

Please try this patch if this help. We have some problems (also performance) with parted and we find that it is not necessary (only some checks for enought size on partition), so this patch remove it.
Comment 14 Felix Miata 2008-12-03 16:07:54 UTC
Created attachment 257762 [details]
output of 'ps -A' & 'fuser -v -m /dev/hda22' while update-bootload running during kernel-default-base installation

After applying patch on host gx150, I did
'zypper in kernel-default kernel-default-base':
kernel-default-base-2.6.27.7-4.1 took about 7 minutes to install
kernel-default-2.6.27.7-4.1 took about 10.5 minutes to install
kernel-default-base-2.6.27.7-4.1 took about 10 minutes to install
Comment 15 Felix Miata 2008-12-05 22:32:19 UTC
'zypper rm kernel-default-base-2.6.27.7-4.1', which removed also kernel-default and kernel-default-extra, took more than 12 minutes to complete, with most time spent in update-bootload.
Comment 16 Felix Miata 2008-12-06 23:34:51 UTC
Big, but possibly misleading, improvement on my 2000MHz Sempron: zypper in kernel-pae installed kernel-pae-2.6.27.7-6.1 and kernel-pae-base-2.6.27.7-6.1 in about 8 minutes total including downloading. However, it left kernel-pae-extra-2.6.27.7-3.1 behind. Also, I had first removed with rpm -e --nodeps --noscripts all kernels except 2.6.27.5-3 & 2.6.27.7-3, and whittled menu.lst down to 1311 bytes (from the 2810 from the last perl-bootload run). zypper rm kernel-pae-extra took about 2 minutes.

Next up will be a 2.4GHz Celeron, on which I won't first remove any old kernels.
Comment 17 Felix Miata 2008-12-07 01:37:41 UTC
On the Celeron,  the installed pae kernels were 2.6.27-12.1, 2.6.27.1-2.1, 2.6.27.4-2.1, 2.6.27.5-3.2 & 2.6.27.7-3.1. zypper in kernel-pae installed kernel-pae-2.6.27.7-4.1 and kernel-pae-base-2.6.27.7-4.1 in about 11.5 minutes total including downloading. However, it left kernel-pae-extra-2.6.27.7-3.1 behind, which took zypper rm kernel-pae-extra about 2.5 minutes to complete. It took zypper rm 18.5 minutes to remove the 4 installed kernels older than 2.6.27.7-3.1.
Comment 18 Josef Reidinger 2008-12-08 10:58:53 UTC
OK. So I don't know what slow down update-Bootloader. Please try if also manual run of `update-Bootloader --refresh` take quite lot of time (it do same initialization, but only rewrite boot record which you already have).
if so then please run `perl -d:DProf /sbin/update-bootloader --refresh` and attach created tmon.out
thanks
Comment 19 Felix Miata 2008-12-08 15:38:08 UTC
Created attachment 258673 [details]
tmon.out from host gx110

On my fastest 11.1 system, m7ncd, running pae-2.6.27.7-4 on amd74xxx, with 9 stanzas in menu.lst and 3 installed kernels, update-bootloader --refresh took 0:1:17 to complete, and changed no files in /boot or /boot/grub.

On host gx260 running pae-2.6.27.7-4 on ata_piix with device mapper, with 13 stanzas in menu.lst and 6 installed kernels, update-bootloader --refresh took 0:1:50 to complete, and changed no files in /boot or /boot/grub.

On host t2240, running pae-2.6.27.7-4 on piix, with 5 stanzas in menu.lst and 2 installed kernels, update-bootloader --refresh took 0:00:34 to complete, and changed no files in /boot or /boot/grub.

On gx150, running pae-2.6.27.7-4 on piix (reporting beta 2 still), with 8 stanzas in menu.lst and 3 installed kernels, update-bootloader --refresh took 0:2:03 to complete, and changed no files in /boot or /boot/grub.

On gx110, running pae-2.6.27.7-3 on piix (reporting beta 2 still; last updated 28 Nov; my slowest Factory, PIII 1000MHz on i810), with 11 stanzas in menu.lst and 5 installed kernels, update-bootloader --refresh took 0:3:30 to complete, and changed no files in /boot or /boot/grub. perl -d:DProf /sbin/update-bootloader --refresh took 0:03:45 to complete.
Comment 20 Felix Miata 2008-12-09 06:02:42 UTC
I just did a 11.0 to 11.1-RC1 upgrade installation on a P4-2.53GHz machine with 1G RAM. It only had one kernel installed, 5 total stanzas in menu.lst (two of which are for starting installation), and only 9 partitions total. I forgot to time it until rather well after the process started, and yet it still showed 0:01:39 on the stopwatch until I saw the updating bootloader message disappear from the YaST installation screen.
Comment 21 Jeff Mahoney 2008-12-09 18:28:37 UTC
Can you try the suggestion in comment #18?
Comment 22 Felix Miata 2008-12-09 18:42:12 UTC
Created attachment 259008 [details]
tmon.out from comment 20 host (vizio)

update-bootloader --refresh & perl -d:DProf /sbin/update-bootloader --refresh each took less than 8 seconds. Only 1 kernel installed, and only 4 stanzas in menu.lst. Did you mean I should attach tmon.out for any or all other 11.1 hosts?
Comment 23 Josef Reidinger 2008-12-10 07:21:19 UTC
thanks, thats enought, I need analyze it.
Comment 24 Josef Reidinger 2008-12-10 08:14:44 UTC
(In reply to comment #19 from Felix Miata)
> Created an attachment (id=258673) [details]
> tmon.out from host gx110

I study that profile and find really huge amount of call l_debug...so do you have md RAID? if not, how many RAM does have that host?
Comment 25 Josef Reidinger 2008-12-10 09:43:03 UTC
I find two bottle neck and fix it in svn. Now kernel update should be faster. Also in future release (11.2) will be new logging system, which have also some significant speed improvement.
Comment 26 Felix Miata 2008-12-10 11:26:17 UTC
(In reply to comment #24 from Josef Reidinger)
> (In reply to comment #19 from Felix Miata)
> > host gx110
 
> I study that profile and find really huge amount of call l_debug...so do you
> have md RAID?

No.

> if not, how many RAM does have that host?
 
512M. That host is a poor performer. On memtest, speed results are a tiny fraction of current hardware, less than 10% even though CPU speed 1/3 or more. Chipset is i810 with PIII/133 @ 1000MHz.
Comment 27 Josef Reidinger 2008-12-11 15:01:47 UTC
*** Bug 458284 has been marked as a duplicate of this bug. ***
Comment 33 Josef Reidinger 2008-12-18 11:13:42 UTC
released for SLE11 code as perl-Bootloader 0.4.82
Please don't close bugs, as it still waits for update for opensuse 11.1
Comment 36 Josef Reidinger 2009-01-08 08:08:10 UTC
released as maintenance update for opensuse11.1 as perl-Bootloader-0.4.81.1. If problem still occur please reopen bug.
Comment 37 Swamp Workflow Management 2009-02-23 13:51:08 UTC
The SWAMPID for this issue is 22674.
Please submit the patch and patchinfo file using this ID.
(https://swamp.suse.de/webswamp/wf/22674)
Comment 38 Dirk Mueller 2009-03-09 12:51:57 UTC
reopen for maintenance tracking purposes.
Comment 41 Dirk Mueller 2009-03-11 22:33:11 UTC
closing as resolved/fixed again