Re: [regression] Re: 2.6.26-rc6: pcmcia stopped working

From: Pavel Machek
Date: Wed Jun 25 2008 - 18:16:44 EST


Hi!

> > > Thinkpad X60.
> >
> > Hmm, but with -rc8, I actually got some useful info:
> >
> > kjournald starting. Commit interval 5 seconds
> > EXT3-fs: mounted filesystem with ordered data mode.
> > VFS: Mounted root (ext3 filesystem) readonly.
> > debug: unmapping init memory c099f000..c09ef000
> > Write protecting the kernel text: 5320k
> > Write protecting the kernel read-only data: 1916k
> > Failed to execute /tmp/swsusp-init. Attempting defaults...
> > EXT3 FS on sda4, internal journal
> > Adding 987988k swap on /dev/sda1. Priority:-1 extents:1 across:987988k
> > kjournald starting. Commit interval 5 seconds
> > EXT3 FS on sda2, internal journal
> > EXT3-fs: mounted filesystem with ordered data mode.
> > pcmcia: Detected deprecated PCMCIA ioctl usage from process: hwclock.
> > pcmcia: This interface will soon be removed from the kernel; please expect breakage unless you upgrade to new tools.
> > pcmcia: see http://www.kernel.org/pub/linux/utils/kernel/pcmcia/pcmcia.html for details.
> > eth0: Link is Up 1000 Mbps Full Duplex, Flow Control: RX/TX
> > coda_read_super: Bad mount data
> > coda_read_super: device index: 0
> > coda_read_super: rootfid is (01234567.ffffffff.08051a38.00000000)
> > coda: Unexpected interruption.
> > Failure of coda_cnode_make for root: error -4
> > pccard: PCMCIA card inserted into slot 0
> > cs: memory probe 0x0c0000-0x0fffff: excluding 0xc0000-0xd3fff 0xdc000-0xfffff
> > cs: memory probe 0x60000000-0x60ffffff: excluding 0x60000000-0x60ffffff
> > cs: memory probe 0xe0000000-0xe3ffffff: excluding 0xe0000000-0xe3ffffff
> > cs: memory probe 0xe4300000-0xe7ffffff: excluding 0xe4300000-0xe46cffff 0xe4e70000-0xe523ffff 0xe5db0000-0xe617ffff 0xe6cf0000-0xe70bffff
> > pcmcia: registering new device pcmcia0.0
> > Probing IDE interface ide1...
> > hdc: SunDisk SDP3B-20, CFA DISK drive
> > hdd: SunDisk SDP3B-20, CFA DISK drive
> > ide-probe: ignoring undecoded slave
> > ide1 at 0x9100-0x9107,0x910e on irq 16
> > hdc: max request size: 128KiB
> > hdc: 40960 sectors (20 MB) w/1KiB Cache, CHS=640/2/32
> > hdc:hdc: set_geometry_intr: status=0x51 { DriveReady SeekComplete Error }
> > hdc: set_geometry_intr: error=0x04 { DriveStatusError }
> > ide: failed opcode was: unknown
> > hdc1 hdc3
> > ide-cs: hdc: Vpp = 0.0
> > Clocksource tsc unstable (delta = -68835537 ns)
> > pccard: card ejected from slot 0
> > INFO: task pccardd:1121 blocked for more than 120 seconds.
> > "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > pccardd D f6dd1e1c 0 1121 2
> > f6dd1e30 00000086 00000002 f6dd1e1c f6dd1e10 00000000 c2015e80 c2015e80
> > c09113e0 00000286 00000286 f72d13b8 f72d1618 c2015e80 f6dd0000 f6afedc0
> > ffff03a9 f6bcb458 00000000 c02bd187 00000000 f6dd1e4c 00000003 00000000
> > Call Trace:
> > [<c02bd187>] sysfs_addrm_finish+0x1a7/0x1e0
> > [<c072edec>] schedule_timeout+0x7c/0xd0
> > [<c02bd1e7>] remove_dir+0x27/0x40
> > [<c0730b9a>] _spin_lock_irq+0x2a/0x40
> > [<c072e240>] wait_for_common+0xc0/0x130
> > [<c021f5c0>] default_wake_function+0x0/0x10
> > [<c04d489f>] ide_unregister+0xcf/0x150
> > [<c04e5671>] ide_release+0x21/0x40
> > [<c04e56b9>] ide_detach+0x29/0x80
> > [<c0520146>] pcmcia_device_remove+0x36/0xe0
> > [<c0423116>] __device_release_driver+0x56/0x90
> > [<c0423210>] device_release_driver+0x20/0x40
> > [<c04225bb>] bus_remove_device+0x6b/0x90
> > [<c04210cf>] device_del+0xcf/0x140
> > [<c0421148>] device_unregister+0x8/0x10
> > [<c051fb7c>] pcmcia_card_remove+0x6c/0x80
> > [<c0520a34>] ds_event+0x64/0xb0
> > [<c051c12f>] pccardd+0x16f/0x2a0
> > [<c051b7fb>] send_event+0x4b/0x80
> > [<c051ba6b>] socket_shutdown+0xb/0xd0
> > [<c051bb4c>] socket_remove+0x1c/0x30
> > [<c051c1fe>] pccardd+0x23e/0x2a0
> > [<c021f5c0>] default_wake_function+0x0/0x10
> > [<c051bfc0>] pccardd+0x0/0x2a0
> > [<c023c3f2>] kthread+0x42/0x70
> > [<c023c3b0>] kthread+0x0/0x70
> > [<c02047ab>] kernel_thread_helper+0x7/0x1c
> > [<c04216f2>] device_create_vargs+0x42/0xd0
> > =======================
> > no locks held by pccardd/1121.
> > INFO: task pccardd:1121 blocked for more than 120 seconds.
> > "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > pccardd D f6dd1e1c 0 1121 2
> > f6dd1e30 00000086 00000002 f6dd1e1c f6dd1e10 00000000 c2015e80 c2015e80
> > c09113e0 00000286 00000286 f72d13b8 f72d1618 c2015e80 f6dd0000 f6afedc0
> > ffff03a9 f6bcb458 00000000 c02bd187 00000000 f6dd1e4c 00000003 00000000
> > Call Trace:
> > [<c02bd187>] sysfs_addrm_finish+0x1a7/0x1e0
> > [<c072edec>] schedule_timeout+0x7c/0xd0
> > [<c02bd1e7>] remove_dir+0x27/0x40
> > [<c0730b9a>] _spin_lock_irq+0x2a/0x40
> > [<c072e240>] wait_for_common+0xc0/0x130
> > [<c021f5c0>] default_wake_function+0x0/0x10
> > [<c04d489f>] ide_unregister+0xcf/0x150
> > [<c04e5671>] ide_release+0x21/0x40
> > [<c04e56b9>] ide_detach+0x29/0x80
> > [<c0520146>] pcmcia_device_remove+0x36/0xe0
> > [<c0423116>] __device_release_driver+0x56/0x90
> > [<c0423210>] device_release_driver+0x20/0x40
> > [<c04225bb>] bus_remove_device+0x6b/0x90
> > [<c04210cf>] device_del+0xcf/0x140
> > [<c0421148>] device_unregister+0x8/0x10
> > [<c051fb7c>] pcmcia_card_remove+0x6c/0x80
> > [<c0520a34>] ds_event+0x64/0xb0
> > [<c051c12f>] pccardd+0x16f/0x2a0
> > [<c051b7fb>] send_event+0x4b/0x80
> > [<c051ba6b>] socket_shutdown+0xb/0xd0
> > [<c051bb4c>] socket_remove+0x1c/0x30
> > [<c051c1fe>] pccardd+0x23e/0x2a0
> > [<c021f5c0>] default_wake_function+0x0/0x10
> > [<c051bfc0>] pccardd+0x0/0x2a0
> > [<c023c3f2>] kthread+0x42/0x70
> > [<c023c3b0>] kthread+0x0/0x70
> > [<c02047ab>] kernel_thread_helper+0x7/0x1c
> > [<c04216f2>] device_create_vargs+0x42/0xd0
> > =======================
> > no locks held by pccardd/1121.
> >
>
> Hmm, hitting sysrq-w produces no blocked task until I eject pcmcia
> card. Backtrace there is:
>
> Greg, I believe some traces lead to sysfs, can you help here?

ide_unregister() does not complete :-(.

device_unregister(&hwif->gendev);
+ printk("ide_unregister: waiting for rel_comp\n");
wait_for_completion(&hwif->gendev_rel_comp);

...that wait_for_completion never returns.


I added some debug prints:

Jun 25 23:59:21 amd cardmgr[1389]: start cmd exited with status 1
Jun 25 23:59:25 amd kernel: pccard: card ejected from slot 0
Jun 25 23:59:25 amd kernel: ide_unregister
Jun 25 23:59:25 amd kernel: ide_unregister: have lock
Jun 25 23:59:25 amd kernel: ide_unregister: have spinlock
Jun 25 23:59:25 amd kernel: ide_unregister: port_unregister
Jun 25 23:59:25 amd kernel: ide_unregister: proc_unregister
Jun 25 23:59:25 amd kernel: ide_unregister: free_irq
Jun 25 23:59:25 amd kernel: ide_unregister: remove from hwgroup
Jun 25 23:59:25 amd kernel: ide_unregister: waiting for rel_comp
Jun 25 23:59:26 amd kernel: Clocksource tsc unstable (delta = -63083806 ns)

diff --git a/drivers/ide/ide.c b/drivers/ide/ide.c
index c758dcb..2c4dc7e 100644
--- a/drivers/ide/ide.c
+++ b/drivers/ide/ide.c
@@ -313,17 +313,22 @@ void ide_unregister(ide_hwif_t *hwif)
ide_hwgroup_t *hwgroup;
int irq_count = 0;

+ printk("ide_unregister\n");
BUG_ON(in_interrupt());
BUG_ON(irqs_disabled());
mutex_lock(&ide_cfg_mtx);
+ printk("ide_unregister: have lock\n");
spin_lock_irq(&ide_lock);
+ printk("ide_unregister: have spinlock\n");
if (!hwif->present)
goto abort;
+ printk("ide_unregister: port_unregister\n");
__ide_port_unregister_devices(hwif);
hwif->present = 0;

spin_unlock_irq(&ide_lock);

+ printk("ide_unregister: proc_unregister\n");
ide_proc_unregister_port(hwif);

hwgroup = hwif->hwgroup;
@@ -336,29 +341,37 @@ void ide_unregister(ide_hwif_t *hwif)
++irq_count;
g = g->next;
} while (g != hwgroup->hwif);
+ printk("ide_unregister: free_irq\n");
if (irq_count == 1)
free_irq(hwif->irq, hwgroup);

+ printk("ide_unregister: remove from hwgroup\n");
ide_remove_port_from_hwgroup(hwif);

device_unregister(hwif->portdev);
device_unregister(&hwif->gendev);
+ printk("ide_unregister: waiting for rel_comp\n");
wait_for_completion(&hwif->gendev_rel_comp);

/*
* Remove us from the kernel's knowledge
*/
+ printk("ide_unregister: blk unregister\n");
blk_unregister_region(MKDEV(hwif->major, 0), MAX_DRIVES<<PARTN_BITS);
kfree(hwif->sg_table);
unregister_blkdev(hwif->major, hwif->name);
spin_lock_irq(&ide_lock);

+ printk("ide_unregister: dma engine\n");
if (hwif->dma_base)
ide_release_dma_engine(hwif);

+ printk("ide_unregister: reset port_data\n");
/* restore hwif data to pristine status */
ide_init_port_data(hwif, hwif->index);

+ printk("ide_unregister: done\n");
+
abort:
spin_unlock_irq(&ide_lock);
mutex_unlock(&ide_cfg_mtx);



--
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/