2.5.68 IDE Oops at boot
Hi Eric,
the oops occurs in __elv_add_request, because the elevator structure is not initialized:
Quoted 6 lines · Eric
EIP: 0060:[<00000000>] Not tainted
[ snip ]Call Trace: [<c02839e3>] __elv_add_request+0x33/0x50
A jump to an uninitialized function pointer within __elv_add_request.
Quoted 8 lines · Eric
SiI3112 Serial ATA: IDE controller at PCI slot 01:0b.0
SiI3112 Serial ATA: chipset revision 1
SiI3112 Serial ATA: not 100% native mode: will probe irqs later
ide0: MMIO-DMA at 0xf8808000-0xf8808007, BIOS settings: hda:pio, hdb:pio
ide1: MMIO-DMA at 0xf8808008-0xf880800f, BIOS settings: hdc:pio, hdd:pio
hda: MAXTOR 6L080L4, ATA DISK drive
hdc: MAXTOR 6L080L4, ATA DISK drive
NFORCE2: IDE controller at PCI slot 00:09.0
Quoted 9 lines
NFORCE2: chipset revision 162
NFORCE2: not 100% native mode: will probe irqs later
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xxAMD_IDE: PCI device 10de:0065 (nVidia Corporation) (rev a2) UDMA100 controller on pci00:09.0
ide2: BM-DMA at 0xf000-0xf007, BIOS settings: hde:DMA, hdf:DMA
ide3: BM-DMA at 0xf008-0xf00f, BIOS settings: hdg:DMA, hdh:DMA
hde: MAXTOR 6L040L2, ATA DISK drive
ide2 at 0x1f0-0x1f7,0x3f6 on irq 14
That line is from init_irq(), called within hwif_init(): hwif and drives fully initialized.
Quoted 5 lines
hdg: PLEXTOR CD-R PX-W4012A, ATAPI CD/DVD-ROM drive
hdh: Pioneer DVD-ROM ATAPIModel DVD-104S 020, ATAPI CD/DVD-ROM drive ide3 at 0x170-0x177,0x376 on irq 15
Dito.
Hmm. But where is "ide0 at ... on irq ..."?
It seems the drives attached to the sata controller were not initialized properly. No idea why. Could you apply the attached patch? I assume that the hwif_init fails somewhere before calling init_irq(), the printks would show me where.
--
Manfred
drivers/block/elevator.c +1 -0
@@ -290,6 +290,7 @@if (plug)blk_plug_device (q); +if (!q->elevator.elevator_add_req_fn)printk (KERN_INFO "Duh. Elevator %p not initialized.\n" , q); q->elevator.elevator_add_req_fn (q, rq, insert); }
drivers/block/ll_rw_blk.c +2 -0
@@ -1156,6 +1156,7 @@ {int count = (queue_nr_requests*2 ); +printk (KERN_INFO "blk_cleanup_queue: destroying %p.\n" , q);elevator_exit (q); count -=__blk_cleanup_queue (&q->rq[READ ]);
@@ -1273,6 +1274,7 @@blk_queue_max_phys_segments (q,MAX_PHYS_SEGMENTS );INIT_LIST_HEAD (&q->plug_list); +printk (KERN_INFO "blk_init_queue: %p initialized.\n" , q);return 0 ; }
drivers/ide/ide.c +2 -0
@@ -599,6 +599,7 @@ hwif = &ide_hwifs[index];if (!hwif->present) goto abort; +printk (KERN_INFO "ide_unregister called for %s.\n" , hwif->name);for (unit =0 ; unit <MAX_DRIVES ; ++unit) { drive = &hwif->drives[unit];if (!drive->present)
@@ -1428,6 +1429,7 @@if (!try_module_get (driver->owner))continue ;spin_unlock (&drivers_lock); +printk (KERN_INFO "ata_attach: trying driver %p for drive %s(%p).\n" , driver, drive->name, &drive->queue);if (driver->attach (drive) ==0 ) {module_put (driver->owner); drive->gendev.driver = &driver->gen_driver;
drivers/ide/ide-probe.c +11 -1
@@ -1007,8 +1007,8 @@* limits and LBA48 we could raise it but as yet * do not. */ -blk_init_queue (q, do_ide_request, &ide_lock); +printk (KERN_INFO "ide_init_queue: drive %s has queue %p.\n" , drive->name, q); q->queuedata =HWGROUP (drive); drive->queue_setup =1 ;blk_queue_segment_boundary (q,0xffff );
@@ -1060,6 +1060,8 @@BUG_ON (irqs_disabled ());down (&ide_cfg_sem); hwif->hwgroup =NULL ; + +printk (KERN_INFO "init_irq called for hwif %s.\n" , hwif->name);#if MAX_HWIFS >1 /* * Group up with any other hwifs that share our irq(s).
@@ -1315,8 +1317,10 @@ {int old_irq, unit; +printk (KERN_INFO "hwif_init: hwif %s, stage 1.\n" , hwif->name);if (!hwif->present)return 0 ; +printk (KERN_INFO "hwif_init: hwif %s, stage 2.\n" , hwif->name);if (!hwif->irq) {if (!(hwif->irq =ide_default_irq (hwif->io_ports[IDE_DATA_OFFSET ])))
@@ -1325,6 +1329,7 @@return (hwif->present =0 ); } } +printk (KERN_INFO "hwif_init: hwif %s, stage 3.\n" , hwif->name);#ifdef CONFIG_BLK_DEV_HD if (hwif->irq ==HD_IRQ && hwif->io_ports[IDE_DATA_OFFSET ] !=HD_DATA ) { printk("%s: CANNOT SHARE IRQ WITH OLD "
@@ -1335,15 +1340,19 @@/* we set it back to 1 if all is ok below */ hwif->present =0 ; +printk (KERN_INFO "hwif_init: hwif %s, stage 4.\n" , hwif->name);if (register_blkdev (hwif->major, hwif->name))return 0 ; +printk (KERN_INFO "hwif_init: hwif %s, stage 5.\n" , hwif->name);if (alloc_disks (hwif) <0 ) goto out; +printk (KERN_INFO "hwif_init: hwif %s, stage 6.\n" , hwif->name);if (init_irq (hwif) ==0 ) goto done; +printk (KERN_INFO "hwif_init: hwif %s, stage 7.\n" , hwif->name); old_irq = hwif->irq;/*
@@ -1355,6 +1364,7 @@ hwif->name, old_irq); goto out_disks; } +printk (KERN_INFO "hwif_init: hwif %s, stage 8.\n" , hwif->name);if (init_irq (hwif)) {printk ("%s: probed IRQ %d and default IRQ %d failed.\n" , hwif->name, old_irq, hwif->irq);
drivers/ide/setup-pci.c +1 -0
@@ -751,6 +751,7 @@ {ata_index_t index_list =do_ide_setup_pci_device (dev, d,1 ); +printk (KERN_INFO "ide_setup_pci_device for %s called.\n" , dev->dev.name);if ((index_list.b.low &0xf0 ) !=0xf0 )probe_hwif_init (&ide_hwifs[index_list.b.low]);if ((index_list.b.high &0xf0 ) !=0xf0 )
Quoted 39 lines · Manfred Spraul
Hi Eric,
the oops occurs in
__elv_add_request, because the elevator structure is not initialized:Quoted 4 lines · Eric
EIP: 0060:[<00000000>] Not tainted
[ snip ]Call Trace: [<c02839e3>] __elv_add_request+0x33/0x50A jump to an uninitialized function pointer within
__elv_add_request.Quoted 9 lines · Eric
SiI3112 Serial ATA: IDE controller at PCI slot 01:0b.0 SiI3112 Serial ATA: chipset revision 1
SiI3112 Serial ATA: not 100% native mode: will probe irqs later
ide0: MMIO-DMA at 0xf8808000-0xf8808007, BIOS settings: hda:pio,
hdb:pio ide1: MMIO-DMA at 0xf8808008-0xf880800f, BIOS settings: hdc:pio, hdd:pio hda: MAXTOR 6L080L4, ATA DISK drive
hdc: MAXTOR 6L080L4, ATA DISK drive
NFORCE2: IDE controller at PCI slot 00:09.0
NFORCE2: chipset revision 162Quoted 8 lines
NFORCE2: not 100% native mode: will probe irqs later
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xxAMD_IDE: PCI device 10de:0065 (nVidia Corporation) (rev a2) UDMA100 controller on pci00:09.0
ide2: BM-DMA at 0xf000-0xf007, BIOS settings: hde:DMA, hdf:DMA
ide3: BM-DMA at 0xf008-0xf00f, BIOS settings: hdg:DMA, hdh:DMA
hde: MAXTOR 6L040L2, ATA DISK drive
ide2 at 0x1f0-0x1f7,0x3f6 on irq 14That line is from
init_irq(), called withinhwif_init(): hwif and drives fully initialized.Quoted 3 lines
hdg: PLEXTOR CD-R PX-W4012A, ATAPI CD/DVD-ROM drive
hdh: Pioneer DVD-ROM ATAPIModel DVD-104S 020, ATAPI CD/DVD-ROM drive ide3 at 0x170-0x177,0x376 on irq 15
Quoted 8 lines
Dito.
Hmm. But where is "ide0 at ... on irq ..."?
It seems the drives attached to the sata controller were not initialized properly. No idea why. Could you apply the attached patch? I assume that the
hwif_initfails somewhere before callinginit_irq(), the printks would show me where.
Here is the resulting boot log:
Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx SiI3112 Serial ATA: IDE controller at PCI slot 01:0b.0
SiI3112 Serial ATA: chipset revision 1
SiI3112 Serial ATA: not 100% native mode: will probe irqs later
ide0: MMIO-DMA at 0xf8808000-0xf8808007, BIOS settings: hda:pio, hdb:pio
ide1: MMIO-DMA at 0xf8808008-0xf880800f, BIOS settings: hdc:pio, hdd:pioide_setup_pci_device for PCI device 1095:3112 (CMD Technology Inc) called.
hda: MAXTOR 6L080L4, ATA DISK drivehwif_init: hwif ide0, stage 1.hwif_init: hwif ide0, stage 3.hwif_init: hwif ide0, stage 4.hwif_init: hwif ide0, stage 5.hwif_init: hwif ide0, stage 6.init_irq called for hwif ide0.
hdc: MAXTOR 6L080L4, ATA DISK drivehwif_init: hwif ide1, stage 1.hwif_init: hwif ide1, stage 3.hwif_init: hwif ide1, stage 4.hwif_init: hwif ide1, stage 5.hwif_init: hwif ide1, stage 6.init_irq called for hwif ide1.
NFORCE2: IDE controller at PCI slot 00:09.0
NFORCE2: chipset revision 162
NFORCE2: not 100% native mode: will probe irqs later
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xxAMD_IDE: PCI device 10de:0065 (nVidia Corporation) (rev a2) UDMA100 controller on pci00:09.0
ide2: BM-DMA at 0xf000-0xf007, BIOS settings: hde:DMA, hdf:DMA
ide3: BM-DMA at 0xf008-0xf00f, BIOS settings: hdg:DMA, hdh:DMAide_setup_pci_device for PCI device 10de:0065 (nVidia Corporation) called.
hde: MAXTOR 6L040L2, ATA DISK drivehwif_init: hwif ide2, stage 1.hwif_init: hwif ide2, stage 3.hwif_init: hwif ide2, stage 4.hwif_init: hwif ide2, stage 5.hwif_init: hwif ide2, stage 6.init_irq called for hwif ide2.blk_init_queue: c04c99d4 initialized.ide_init_queue: drive hde has queue c04c99d4.
ide2 at 0x1f0-0x1f7,0x3f6 on irq 14
hdg: PLEXTOR CD-R PX-W4012A, ATAPI CD/DVD-ROM drive
hdh: Pioneer DVD-ROM ATAPIModel DVD-104S 020, ATAPI CD/DVD-ROM drivehwif_init: hwif ide3, stage 1.hwif_init: hwif ide3, stage 3.hwif_init: hwif ide3, stage 4.hwif_init: hwif ide3, stage 5.hwif_init: hwif ide3, stage 6.init_irq called for hwif ide3.blk_init_queue: c04ca2c0 initialized.ide_init_queue: drive hdg has queue c04ca2c0.blk_init_queue: c04ca5d8 initialized.ide_init_queue: drive hdh has queue c04ca5d8.
ide3 at 0x170-0x177,0x376 on irq 15hwif_init: hwif ide4, stage 1.hwif_init: hwif ide5, stage 1.hwif_init: hwif ide6, stage 1.hwif_init: hwif ide7, stage 1.hwif_init: hwif ide8, stage 1.hwif_init: hwif ide9, stage 1.ata_attach: trying driver c043a3e0 for drive hda(c04c87fc). Duh. Elevator c04c87fc not initialized.
Unable to handle kernel NULL pointer dereference at virtual address 00000000 printing eip: 00000000 *pde = 00000000 Oops: 0000 [#1] CPU: 0 EIP: 0060:[<00000000>] Not tainted EFLAGS: 00010082
EIP is at 0x0
eax: f7f9fdcc ebx: c04c87fc ecx: 00000002 edx: 00000000
esi: 00000000 edi: 00000202 ebp: f7f9fd80 esp: f7f9fd68
ds: 007b es: 007b ss: 0068
Process swapper (pid: 1, threadinfo=f7f9e000 task=f7f9c040)
Stack: c0288829 c04c87fc f7f9fdcc 00000000 f7f9e000 f7f9fdcc f7f9fdb8 c02a2e05
c04c87fc f7f9fdcc 00000001 00000000 c1b29534 00000000 f7f9fda0 f7f9fda0
f7f9fdd4 f7f9fe94 00000000 f7f9fdcc f7f9fe68 c02a89cb c04c87ec f7f9fdcc
Call Trace:
[<c0288829>] __elv_add_request+0x39/0x60
[<c02a2e05>] ide_do_drive_cmd+0x85/0x100
[<c02a89cb>] ide_diag_taskfile+0x7b/0xb0
[<c02a8a27>] ide_raw_taskfile+0x27/0x30
[<c02af069>] idedisk_read_native_max_address+0x49/0x90
[<c02a7cc0>] task_no_data_intr+0x0/0xa0
[<c02af1a4>] init_idedisk_capacity+0x34/0x240
[<c02b02a8>] idedisk_setup+0x118/0x2f0
[<c02acead>] ide_register_subdriver+0x16d/0x1a0
[<c02b07d4>] idedisk_attach+0xa4/0x1c0
[<c02ac150>] ata_attach+0x70/0x130
[<c02ad116>] ide_register_driver+0xf6/0x110
[<c02b0902>] idedisk_init+0x12/0x50
[<c048078c>] do_initcalls+0x2c/0xa0
[<c0130e92>] init_workqueues+0x12/0x40
[<c01050a6>] init+0x36/0x190
[<c0105070>] init+0x0/0x190
[<c010924d>] kernel_thread_helper+0x5/0x18
Code: Bad EIP value.
<0>Kernel panic: Attempted to kill init!Quoted 3 lines · Eric Northup
init_irqcalled for hwif ide0.
hdc: MAXTOR 6L080L4, ATA DISK drive
init_irq called, but does nothing.
Quoted 3 lines
init_irqcalled for hwif ide2.blk_init_queue:c04c99d4initialized.
This is what's supposed to happen: init_irq initialized the queues.
Two bugs:
- why doesn't init_irq initialize the queues for the siimage controller? I found a difference between 2.5.67 and 68: init_irq always returns 0, even on error. It should return 1 on error. (It wasn't difficult to find, I introduced it :-(
- The error handling is bad. Probably drive->present should be forced to 0, if the queues could not be initialized.
Could you try the attached patch? It fixes the return code and adds some additional printks.
--
Manfred
// $Header$
// Kernel Version:
// VERSION = 2 // PATCHLEVEL = 5 // SUBLEVEL = 68 // EXTRAVERSION =
drivers/block/elevator.c +1 -0
@@ -290,6 +290,7 @@if (plug)blk_plug_device (q); +if (!q->elevator.elevator_add_req_fn)printk (KERN_INFO "Duh. Elevator %p not initialized.\n" , q); q->elevator.elevator_add_req_fn (q, rq, insert); }
drivers/block/ll_rw_blk.c +2 -0
@@ -1156,6 +1156,7 @@ {int count = (queue_nr_requests*2 ); +printk (KERN_INFO "blk_cleanup_queue: destroying %p.\n" , q);elevator_exit (q); count -=__blk_cleanup_queue (&q->rq[READ ]);
@@ -1273,6 +1274,7 @@blk_queue_max_phys_segments (q,MAX_PHYS_SEGMENTS );INIT_LIST_HEAD (&q->plug_list); +printk (KERN_INFO "blk_init_queue: %p initialized.\n" , q);return 0 ; }
drivers/ide/ide.c +2 -0
@@ -599,6 +599,7 @@ hwif = &ide_hwifs[index];if (!hwif->present) goto abort; +printk (KERN_INFO "ide_unregister called for %s.\n" , hwif->name);for (unit =0 ; unit <MAX_DRIVES ; ++unit) { drive = &hwif->drives[unit];if (!drive->present)
@@ -1428,6 +1429,7 @@if (!try_module_get (driver->owner))continue ;spin_unlock (&drivers_lock); +printk (KERN_INFO "ata_attach: trying driver %p for drive %s(%p).\n" , driver, drive->name, &drive->queue);if (driver->attach (drive) ==0 ) {module_put (driver->owner); drive->gendev.driver = &driver->gen_driver;
drivers/ide/ide-probe.c +19 -4
@@ -1007,8 +1007,8 @@* limits and LBA48 we could raise it but as yet * do not. */ -blk_init_queue (q, do_ide_request, &ide_lock); +printk (KERN_INFO "ide_init_queue: drive %s has queue %p.\n" , drive->name, q); q->queuedata =HWGROUP (drive); drive->queue_setup =1 ;blk_queue_segment_boundary (q,0xffff );
@@ -1060,6 +1060,8 @@BUG_ON (irqs_disabled ());down (&ide_cfg_sem); hwif->hwgroup =NULL ; + +printk (KERN_INFO "init_irq called for hwif %s.\n" , hwif->name);#if MAX_HWIFS >1 /* * Group up with any other hwifs that share our irq(s).
@@ -1107,8 +1109,10 @@spin_unlock_irq (&ide_lock); }else { hwgroup =kmalloc (sizeof (ide_hwgroup_t),GFP_KERNEL ); -if (!hwgroup) +if (!hwgroup) { +printk (KERN_INFO "init_irq: kmalloc failed.\n" ); goto out_up; + } hwif->hwgroup = hwgroup;
@@ -1143,8 +1147,10 @@/* clear nIEN */ hwif->OUTB (0x08 , hwif->io_ports[IDE_CONTROL_OFFSET ]); -if (request_irq (hwif->irq,&ide_intr,sa,hwif->name,hwgroup)) +if (request_irq (hwif->irq,&ide_intr,sa,hwif->name,hwgroup)) { +printk (KERN_INFO "init_irq: request_irq failed for irq %d.\n" , hwif->irq); goto out_unlink; + } }/*
@@ -1155,6 +1161,7 @@*/ for (index =0 ; index <MAX_DRIVES ; ++index) {ide_drive_t *drive = &hwif->drives[index]; +printk (KERN_INFO "init_irq: processing drive %s(%p), present %d.\n" , drive->name, &drive->queue, drive->present);if (!drive->present)continue ;ide_init_queue (drive);
@@ -1214,7 +1221,7 @@spin_unlock_irq (&ide_lock); out_up:up (&ide_cfg_sem); -return 0 ; +return 1 ; }static int ata_lock (dev_t dev,void *data)
@@ -1315,8 +1322,10 @@ {int old_irq, unit; +printk (KERN_INFO "hwif_init: hwif %s, stage 1.\n" , hwif->name);if (!hwif->present)return 0 ; +printk (KERN_INFO "hwif_init: hwif %s, stage 2.\n" , hwif->name);if (!hwif->irq) {if (!(hwif->irq =ide_default_irq (hwif->io_ports[IDE_DATA_OFFSET ])))
@@ -1325,6 +1334,7 @@return (hwif->present =0 ); } } +printk (KERN_INFO "hwif_init: hwif %s, stage 3.\n" , hwif->name);#ifdef CONFIG_BLK_DEV_HD if (hwif->irq ==HD_IRQ && hwif->io_ports[IDE_DATA_OFFSET ] !=HD_DATA ) { printk("%s: CANNOT SHARE IRQ WITH OLD "
@@ -1335,15 +1345,19 @@/* we set it back to 1 if all is ok below */ hwif->present =0 ; +printk (KERN_INFO "hwif_init: hwif %s, stage 4.\n" , hwif->name);if (register_blkdev (hwif->major, hwif->name))return 0 ; +printk (KERN_INFO "hwif_init: hwif %s, stage 5.\n" , hwif->name);if (alloc_disks (hwif) <0 ) goto out; +printk (KERN_INFO "hwif_init: hwif %s, stage 6.\n" , hwif->name);if (init_irq (hwif) ==0 ) goto done; +printk (KERN_INFO "hwif_init: hwif %s, stage 7.\n" , hwif->name); old_irq = hwif->irq;/*
@@ -1355,6 +1369,7 @@ hwif->name, old_irq); goto out_disks; } +printk (KERN_INFO "hwif_init: hwif %s, stage 8.\n" , hwif->name);if (init_irq (hwif)) {printk ("%s: probed IRQ %d and default IRQ %d failed.\n" , hwif->name, old_irq, hwif->irq);
drivers/ide/setup-pci.c +1 -0
@@ -751,6 +751,7 @@ {ata_index_t index_list =do_ide_setup_pci_device (dev, d,1 ); +printk (KERN_INFO "ide_setup_pci_device for %s called.\n" , dev->dev.name);if ((index_list.b.low &0xf0 ) !=0xf0 )probe_hwif_init (&ide_hwifs[index_list.b.low]);if ((index_list.b.high &0xf0 ) !=0xf0 )
Re: 2.5.68 IDE Oops at boot [working now]
Quoted 19 lines · Manfred Spraul
Quoted 2 lines · Eric Northup
init_irqcalled for hwif ide0.
hdc: MAXTOR 6L080L4, ATA DISK drive
init_irqcalled, but does nothing.Quoted 2 lines
init_irqcalled for hwif ide2.blk_init_queue:c04c99d4initialized.This is what's supposed to happen:
init_irqinitialized the queues.Two bugs:
- why doesn'tinit_irqinitialize the queues for the siimage controller? I found a difference between 2.5.67 and 68:init_irqalways returns 0, even on error. It should return 1 on error. (It wasn't difficult to find, I introduced it :-(
- The error handling is bad. Probablydrive->presentshould be forced to 0, if the queues could not be initialized.
Quoted 5 lines
Could you try the attached patch? It fixes the return code and adds some additional printks.
--
Manfred
This fixes it, thank you very much! I am currently running 2.5.68 with your IDE patch. One annoyance is that the order of IDE channels is different between 2.4.20 and 2.5.68 - the Silicon Image SATA controller is detected first on 2.5 but not on 2.4. I've just put a simple script to swap /etc/fstab at boot based on the running kernel, but the device swap is not very user-friendly. Other than that, I've got no complaints - the system is running quite well!
--Eric Northup