Bug#594472: grub-pc: scary messages and very long boot time after upgrade
Toni Mueller
support at oeko.net
Sun Aug 29 01:01:04 UTC 2010
Hi,
On Sun, 29.08.2010 at 02:35:09 +0200, Agustin Martin <agmartin at debian.org> wrote:
> May this be related to #583917, mdadm: long delay (6-200 minutes)
> during boot (root device detection) after upgrade on RAID/LVM/LUKS
> setup?
after reading this bug report, I'm not convinced. Contrary to my last
statement, my computer came up after a long time, but I wasn't present
then. In /var/log/dmesg, I find this, also scaring:
[ 2.210480] raid1: raid set md0 active with 2 out of 2 mirrors
[ 2.210526] md0: detected capacity change from 0 to 197263360
[ 2.211066] md0: unknown partition table
[ 2.231075] md: md1 stopped.
[ 2.245155] md: bind<sdb2>
[ 2.249267] md: bind<sda2>
[ 2.250166] raid1: raid set md1 active with 2 out of 2 mirrors
[ 2.250210] md1: detected capacity change from 0 to 1000004780032
[ 2.250777] md1: unknown partition table
[ 2.256108] device-mapper: uevent: version 1.0.3
[ 2.256206] device-mapper: ioctl: 4.15.0-ioctl (2009-04-01) initialised: dm-devel at redhat.com
[ 7972.303339] udevd invoked oom-killer: gfp_mask=0x84d0, order=0, oom_adj=-17
[ 7972.303349] udevd cpuset=/ mems_allowed=0
[ 7972.303355] Pid: 81, comm: udevd Not tainted 2.6.32-5-686-bigmem #1
[ 7972.303361] Call Trace:
[ 7972.303370] [<c108f0b4>] ? oom_kill_process+0x60/0x201
[ 7972.303377] [<c108f631>] ? __out_of_memory+0xf4/0x107
[ 7972.303383] [<c108f69e>] ? out_of_memory+0x5a/0x7c
[ 7972.303389] [<c1091f15>] ? __alloc_pages_nodemask+0x3e1/0x4e0
[ 7972.303396] [<c1092020>] ? __get_free_pages+0xc/0x17
[ 7972.303403] [<c1023bcc>] ? pgd_alloc+0x6c/0x21a
[ 7972.303409] [<c1033f60>] ? mm_init+0xa8/0xd4
[ 7972.303414] [<c1034429>] ? dup_mm+0x6a/0x363
[ 7972.303906] [<c10d3700>] ? copy_fs_struct+0x14/0x70
[ 7972.303911] [<c1034cf1>] ? copy_process+0x57a/0xf62
[ 7972.303917] [<c103507e>] ? copy_process+0x907/0xf62
[ 7972.303923] [<c1035813>] ? do_fork+0x13a/0x2bc
[ 7972.303929] [<c10b8479>] ? fd_install+0x1e/0x3c
[ 7972.303935] [<c10bf954>] ? do_pipe_flags+0x8a/0xc8
[ 7972.303941] [<c11426c3>] ? copy_to_user+0x29/0xf8
[ 7972.303947] [<c1006c2e>] ? sys_clone+0x21/0x27
[ 7972.303953] [<c100805c>] ? syscall_call+0x7/0xb
[ 7972.303958] Mem-Info:
[ 7972.303962] DMA per-cpu:
[ 7972.303966] CPU 0: hi: 0, btch: 1 usd: 0
[ 7972.303971] CPU 1: hi: 0, btch: 1 usd: 0
[ 7972.303976] CPU 2: hi: 0, btch: 1 usd: 0
[ 7972.303981] CPU 3: hi: 0, btch: 1 usd: 0
[ 7972.303986] Normal per-cpu:
[ 7972.303990] CPU 0: hi: 186, btch: 31 usd: 185
[ 7972.303995] CPU 1: hi: 186, btch: 31 usd: 180
[ 7972.304020] CPU 2: hi: 186, btch: 31 usd: 185
[ 7972.304025] CPU 3: hi: 186, btch: 31 usd: 90
[ 7972.304030] HighMem per-cpu:
[ 7972.304034] CPU 0: hi: 186, btch: 31 usd: 84
[ 7972.304039] CPU 1: hi: 186, btch: 31 usd: 167
[ 7972.304044] CPU 2: hi: 186, btch: 31 usd: 162
[ 7972.304049] CPU 3: hi: 186, btch: 31 usd: 21
[ 7972.304055] active_anon:8840 inactive_anon:7482 isolated_anon:0
[ 7972.304056] active_file:859 inactive_file:4801 isolated_file:0
[ 7972.304057] unevictable:3490 dirty:0 writeback:0 unstable:0
[ 7972.304058] free:1779496 slab_reclaimable:384 slab_unreclaimable:204066
[ 7972.304058] mapped:732 shmem:8190 pagetables:394 bounce:0
[ 7972.304083] DMA free:3504kB min:64kB low:80kB high:96kB active_anon:0kB inactive_anon:0kB active_file:16kB inactive_file:40kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15800kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:12276kB kernel_stack:24kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[ 7972.304110] lowmem_reserve[]: 0 865 7851 7851
[ 7972.304121] Normal free:3700kB min:3728kB low:4660kB high:5592kB active_anon:0kB inactive_anon:0kB active_file:24kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:885944kB mlocked:0kB dirty:0kB writeback:0kB mapped:4kB shmem:0kB slab_reclaimable:1536kB slab_unreclaimable:803988kB kernel_stack:1264kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[ 7972.304148] lowmem_reserve[]: 0 0 55892 55892
[ 7972.304159] HighMem free:7110780kB min:512kB low:8040kB high:15568kB active_anon:35360kB inactive_anon:29928kB active_file:3396kB inactive_file:19164kB unevictable:13960kB isolated(anon):0kB isolated(file):0kB present:7154180kB mlocked:13388kB dirty:0kB writeback:0kB mapped:2924kB shmem:32760kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:1576kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[ 7972.304187] lowmem_reserve[]: 0 0 0 0
[ 7972.304196] DMA: 3*4kB 8*8kB 5*16kB 10*32kB 12*64kB 2*128kB 0*256kB 0*512kB 0*1024kB 1*2048kB 0*4096kB = 3548kB
[ 7972.304214] Normal: 67*4kB 0*8kB 1*16kB 1*32kB 1*64kB 0*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 0*4096kB = 3708kB
[ 7972.304233] HighMem: 22*4kB 14*8kB 7*16kB 2*32kB 2*64kB 2*128kB 0*256kB 1*512kB 1*1024kB 1*2048kB 1735*4096kB = 7110904kB
[ 7972.304251] 14610 total pagecache pages
[ 7972.304256] 0 pages in swap cache
[ 7972.304260] Swap cache stats: add 0, delete 0, find 0/0
[ 7972.304265] Free swap = 0kB
[ 7972.304269] Total swap = 0kB
[ 7972.322916] 2228208 pages RAM
[ 7972.322922] 2000898 pages HighMem
[ 7972.322926] 215734 pages reserved
[ 7972.322930] 11140 pages shared
[ 7972.322934] 230695 pages non-shared
[ 7972.322939] Out of memory: kill process 1062 (lvm) score 216 or a child
[ 7972.322945] Killed process 1062 (lvm)
[ 7974.500006] udevd invoked oom-killer: gfp_mask=0x84d0, order=0, oom_adj=-17
[ 7974.500016] udevd cpuset=/ mems_allowed=0
[ 7974.500022] Pid: 19424, comm: udevd Not tainted 2.6.32-5-686-bigmem #1
[ 7974.500028] Call Trace:
[ 7974.500037] [<c108f0b4>] ? oom_kill_process+0x60/0x201
[ 7974.500044] [<c108f631>] ? __out_of_memory+0xf4/0x107
[ 7974.500050] [<c108f69e>] ? out_of_memory+0x5a/0x7c
[ 7974.500056] [<c1091f15>] ? __alloc_pages_nodemask+0x3e1/0x4e0
[ 7974.500063] [<c1092020>] ? __get_free_pages+0xc/0x17
[ 7974.500070] [<c1023bcc>] ? pgd_alloc+0x6c/0x21a
[ 7974.500077] [<c127c4cc>] ? _cond_resched+0x25/0x3c
[ 7974.500082] [<c127c503>] ? wait_for_common+0x20/0x100
[ 7974.500089] [<c1033f9d>] ? mm_alloc+0x11/0x37
[ 7974.500094] [<c1033f60>] ? mm_init+0xa8/0xd4
[ 7974.500101] [<c10becd2>] ? bprm_mm_init+0x14/0x144
[ 7974.500107] [<c10beee5>] ? do_execve+0xe3/0x25b
[ 7974.500113] [<c1006be9>] ? sys_execve+0x23/0x47
[ 7974.500119] [<c100805c>] ? syscall_call+0x7/0xb
[ 7974.500124] Mem-Info:
[ 7974.500128] DMA per-cpu:
[ 7974.500132] CPU 0: hi: 0, btch: 1 usd: 0
[ 7974.500137] CPU 1: hi: 0, btch: 1 usd: 0
[ 7974.500143] CPU 2: hi: 0, btch: 1 usd: 0
[ 7974.500148] CPU 3: hi: 0, btch: 1 usd: 0
[ 7974.500152] Normal per-cpu:
[ 7974.500157] CPU 0: hi: 186, btch: 31 usd: 157
[ 7974.500162] CPU 1: hi: 186, btch: 31 usd: 168
[ 7974.500167] CPU 2: hi: 186, btch: 31 usd: 184
[ 7974.500172] CPU 3: hi: 186, btch: 31 usd: 90
[ 7974.500176] HighMem per-cpu:
[ 7974.500181] CPU 0: hi: 186, btch: 31 usd: 95
[ 7974.500186] CPU 1: hi: 186, btch: 31 usd: 127
[ 7974.500191] CPU 2: hi: 186, btch: 31 usd: 125
[ 7974.500196] CPU 3: hi: 186, btch: 31 usd: 19
[ 7974.500202] active_anon:14224 inactive_anon:2047 isolated_anon:0
[ 7974.500203] active_file:825 inactive_file:4793 isolated_file:0
[ 7974.500204] unevictable:760 dirty:0 writeback:0 unstable:0
[ 7974.500205] free:1782386 slab_reclaimable:382 slab_unreclaimable:204109
[ 7974.500205] mapped:284 shmem:8191 pagetables:318 bounce:0
[ 7974.500230] DMA free:3504kB min:64kB low:80kB high:96kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15800kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:12312kB kernel_stack:16kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[ 7974.500255] lowmem_reserve[]: 0 865 7851 7851
[ 7974.500266] Normal free:3728kB min:3728kB low:4660kB high:5592kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:8kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:885944kB mlocked:0kB dirty:0kB writeback:0kB mapped:4kB shmem:0kB slab_reclaimable:1528kB slab_unreclaimable:804124kB kernel_stack:1264kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[ 7974.500293] lowmem_reserve[]: 0 0 55892 55892
[ 7974.500304] HighMem free:7122312kB min:512kB low:8040kB high:15568kB active_anon:56896kB inactive_anon:8188kB active_file:3396kB inactive_file:19164kB unevictable:3040kB isolated(anon):0kB isolated(file):0kB present:7154180kB mlocked:0kB dirty:0kB writeback:0kB mapped:1132kB shmem:32764kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:1272kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[ 7974.500331] lowmem_reserve[]: 0 0 0 0
[ 7974.500340] DMA: 5*4kB 8*8kB 4*16kB 10*32kB 12*64kB 2*128kB 0*256kB 0*512kB 0*1024kB 1*2048kB 0*4096kB = 3540kB
[ 7974.500358] Normal: 92*4kB 4*8kB 1*16kB 0*32kB 0*64kB 0*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 0*4096kB = 3744kB
[ 7974.500377] HighMem: 444*4kB 152*8kB 48*16kB 19*32kB 10*64kB 8*128kB 7*256kB 7*512kB 2*1024kB 1*2048kB 1735*4096kB = 7122064kB
[ 7974.500396] 14601 total pagecache pages
[ 7974.500400] 0 pages in swap cache
[ 7974.500404] Swap cache stats: add 0, delete 0, find 0/0
[ 7974.500409] Free swap = 0kB
[ 7974.500413] Total swap = 0kB
[ 7974.519396] 2228208 pages RAM
[ 7974.519401] 2000898 pages HighMem
[ 7974.519405] 215734 pages reserved
[ 7974.519409] 10694 pages shared
[ 7974.519413] 228450 pages non-shared
[ 7974.519418] Out of memory: kill process 19115 (udevadm) score 29 or a child
[ 7974.519425] Killed process 19115 (udevadm)
[ 7974.527534] PM: Starting manual resume from disk
[ 7974.527543] PM: Resume from partition 253:2
[ 7974.527544] PM: Checking hibernation image.
[ 7974.543155] PM: Error -22 checking image file
[ 7974.543157] PM: Resume from disk failed.
[ 7974.571999] kjournald starting. Commit interval 5 seconds
[ 7974.572012] EXT3-fs: mounted filesystem with ordered data mode.
[ 7976.746289] udev: starting version 160
[ 7976.825441] udev: renamed network interface eth0 to eth1
[ 7976.875482] udev: renamed network interface eth1_rename to eth0
[ 7976.923009] input: Power Button as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0C:00/input/input2
[ 7976.923022] ACPI: Power Button [PWRB]
[ 7976.923066] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
[ 7976.923075] ACPI: Power Button [PWRF]
[ 7976.926556] processor LNXCPU:00: registered as cooling_device0
[ 7976.926962] processor LNXCPU:01: registered as cooling_device1
[ 7976.927306] processor LNXCPU:02: registered as cooling_device2
[ 7976.927655] processor LNXCPU:03: registered as cooling_device3
[ 7976.974505] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[ 7976.991243] parport_pc 00:06: reported by Plug and Play ACPI
[ 7976.991814] parport0: PC-style at 0x378 (0x778), irq 7 [PCSPP,TRISTATE]
[ 7977.008370] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
[ 7977.043616] input: PC Speaker as /devices/platform/pcspkr/input/input4
[ 7977.049384] ACPI: I/O resource piix4_smbus [0xb00-0xb07] conflicts with ACPI region SOR1 [0xb00-0xb0f]
[ 7977.049394] ACPI: If an ACPI driver is available for this device, you should use it instead of the native driver
[ 7977.086514] [drm] Initialized drm 1.1.0 20060810
[ 7977.151930] HDA Intel 0000:00:14.2: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[ 7977.311248] [drm] radeon kernel modesetting enabled.
At this point, booting appears to be normal.
> Does downgrading to mdadm 3.1.1 help?
I currently don't find the archive where all .debs ever released are
stored, and don't have this version on my local disk, for some
obscure reason. So I can't make a statement about this right now.
--
Kind regards,
--Toni++
More information about the Pkg-grub-devel
mailing list