Strange behavior with USB devices

tasty_minerals · 2011-12-05 07:22:52

I got arch installed at home and at work. Recently on both machines I got a black screen with dmesg output after connecting the usb device (android tablet and iriver player). I could get back my screen with CTRL+ALT+F7, but then my usb ports stopped working and dmesg shows nothing, after I connected the devices for the second time. I was able to get them running only after the reboot( It doesn't happen every time I connect a device, but it happened twice already, so I though I should write a feedback.

cat /var/log/kernel.log

Dec  5 10:02:01 pshkadko kernel: [585770.318168] usb 1-1: USB disconnect, device number 6
Dec  5 10:02:01 pshkadko kernel: [585770.319078] scsi: killing requests for dead queue
Dec  5 10:02:01 pshkadko kernel: [585770.319283] BUG: unable to handle kernel NULL pointer dereference at 00000004
Dec  5 10:02:01 pshkadko kernel: [585770.319445] IP: [<f8201f07>] sd_revalidate_disk+0x27/0x1cb0 [sd_mod]
Dec  5 10:02:01 pshkadko kernel: [585770.319594] *pde = 00000000 
Dec  5 10:02:01 pshkadko kernel: [585770.319730] Oops: 0000 [#1] PREEMPT SMP 
Dec  5 10:02:01 pshkadko kernel: [585770.319879] Modules linked in: nls_cp437 vfat fat uas usb_storage fuse ipv6 ext2 snd_intel8x0 snd_cs4236 snd_ac97_codec ac97_bus snd_wavefront snd_wss_lib snd_pcm snd_opl3_lib nouveau snd_timer snd_hwdep snd_mpu401 ttm snd_mpu401_uart snd_page_alloc drm_kms_helper snd_rawmidi ns558 3c59x drm snd_seq_device processor i2c_algo_bit snd mxm_wmi i2c_i801 wmi ppdev intel_agp intel_gtt parport_pc agpgart mii video usbhid hid button shpchp pci_hotplug parport iTCO_wdt i2c_core evdev gameport iTCO_vendor_support soundcore ext4 mbcache jbd2 crc16 sr_mod sd_mod cdrom pata_acpi ata_piix libata uhci_hcd usbcore scsi_mod
Dec  5 10:02:01 pshkadko kernel: [585770.321427] [drm] nouveau 0000:01:00.0: GPU lockup - switching to software fbcon
Dec  5 10:02:01 pshkadko kernel: [585770.321427] 
Dec  5 10:02:01 pshkadko kernel: [585770.321427] Pid: 16515, comm: hald-addon-stor Not tainted 3.1.1-1-ARCH #1    /8IR533  
Dec  5 10:02:01 pshkadko kernel: [585770.321427] EIP: 0060:[<f8201f07>] EFLAGS: 00010246 CPU: 0
Dec  5 10:02:01 pshkadko kernel: [585770.321427] EIP is at sd_revalidate_disk+0x27/0x1cb0 [sd_mod]
Dec  5 10:02:01 pshkadko kernel: [585770.321427] EAX: 00000000 EBX: f8204e60 ECX: 00000002 EDX: 00000000
Dec  5 10:02:01 pshkadko kernel: [585770.321427] ESI: c4e06c60 EDI: c4e06c00 EBP: f2ef3d34 ESP: f2ef3ca8
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Dec  5 10:02:01 pshkadko kernel: [585770.321427] Process hald-addon-stor (pid: 16515, ti=f2ef2000 task=ebc41aa0 task.ti=f2ef2000)
Dec  5 10:02:01 pshkadko kernel: [585770.321427] Stack:
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  c02c57fd 00000002 f2ef3cb8 f81050ad f2ef3cd8 c0232022 c357e090 c0249ed0
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  f6d34498 c4e06c3c f6d34498 f6406800 f2ef3cf8 c0232bc0 f2ef3d08 c4e06c3c
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  c4e06c00 f2ef3d0c c02c57fd c4e06c00 f2ef3d0c c357e090 00000000 f2ef3d1c
Dec  5 10:02:01 pshkadko kernel: [585770.321427] Call Trace:
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c02c57fd>] ? kobject_put+0x1d/0x50
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<f81050ad>] ? scsi_device_dev_release_usercontext+0x13d/0x160 [scsi_mod]
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c0232022>] ? find_inode+0x92/0xa0
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c0249ed0>] ? I_BDEV+0x10/0x10
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c0232bc0>] ? iget5_locked+0x70/0x190
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c02c57fd>] ? kobject_put+0x1d/0x50
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c0232d14>] ? iput+0x34/0x1c0
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c02b7297>] ? disk_part_iter_next+0x97/0xe0
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c0271052>] rescan_partitions+0x82/0x560
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c02c57fd>] ? kobject_put+0x1d/0x50
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<f80fa007>] ? scsi_device_put+0x47/0x50 [scsi_mod]
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c04609cd>] ? mutex_unlock+0xd/0x10
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<f81ff9d9>] ? scsi_disk_put+0x39/0x50 [sd_mod]
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c024b746>] __blkdev_get+0x266/0x3c0
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c024b8eb>] blkdev_get+0x4b/0x2b0
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c024bba0>] blkdev_open+0x50/0x70
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c0219e32>] __dentry_open+0x1d2/0x350
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c021b10e>] nameidata_to_filp+0x6e/0x80
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c024bb50>] ? blkdev_get+0x2b0/0x2b0
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c02291af>] do_last+0x2ef/0x8c0
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c0229864>] path_openat+0xa4/0x350
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<f80fa007>] ? scsi_device_put+0x47/0x50 [scsi_mod]
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c0229c21>] do_filp_open+0x31/0x80
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c0234873>] ? alloc_fd+0xa3/0xe0
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c021b206>] do_sys_open+0xe6/0x1b0
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c016f8e1>] ? ktime_get_ts+0xe1/0x110
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c021b2fe>] sys_open+0x2e/0x40
Dec  5 10:02:01 pshkadko kernel: [585770.321427]  [<c046291f>] sysenter_do_call+0x12/0x28
Dec  5 10:02:01 pshkadko kernel: [585770.321427] Code: 90 90 90 90 55 89 e5 57 56 53 83 c4 80 3e 8d 74 26 00 31 d2 89 45 b4 65 a1 14 00 00 00 89 45 f0 31 c0 8b 45 b4 8b 80 ec 01 00 00 <8b> 58 04 89 45 c0 8b 83 9c 03 00 00 89 5d b8 83 f8 04 0f 95 c2 
Dec  5 10:02:01 pshkadko kernel: [585770.321427] EIP: [<f8201f07>] sd_revalidate_disk+0x27/0x1cb0 [sd_mod] SS:ESP 0068:f2ef3ca8
Dec  5 10:02:01 pshkadko kernel: [585770.321427] CR2: 0000000000000004
Dec  5 10:02:01 pshkadko kernel: [585770.535181] ---[ end trace c949e922fd04c28a ]---
Dec  5 10:02:13 pshkadko kernel: [585782.948206] usb 1-1: new full speed USB device number 7 using uhci_hcd
Dec  5 10:02:13 pshkadko kernel: [585783.121881] scsi6 : usb-storage 1-1:1.0
Dec  5 10:02:14 pshkadko kernel: [585784.126473] scsi 6:0:0:0: Direct-Access     iriver   E30                   PQ: 0 ANSI: 4
Dec  5 10:02:14 pshkadko kernel: [585784.132555] scsi: killing requests for dead queue
Dec  5 10:02:14 pshkadko kernel: [585784.134556] scsi: killing requests for dead queue
Dec  5 10:02:14 pshkadko kernel: [585784.137512] sd 6:0:0:0: [sdb] 475264 4096-byte logical blocks: (1.94 GB/1.81 GiB)
Dec  5 10:02:14 pshkadko kernel: [585784.137573] scsi: killing requests for dead queue
Dec  5 10:02:14 pshkadko kernel: [585784.140473] sd 6:0:0:0: [sdb] Write Protect is off
Dec  5 10:02:14 pshkadko kernel: [585784.140481] sd 6:0:0:0: [sdb] Mode Sense: 3e 00 00 00
Dec  5 10:02:14 pshkadko kernel: [585784.140526] scsi: killing requests for dead queue
Dec  5 10:02:14 pshkadko kernel: [585784.143550] sd 6:0:0:0: [sdb] No Caching mode page present
Dec  5 10:02:14 pshkadko kernel: [585784.143561] sd 6:0:0:0: [sdb] Assuming drive cache: write through
Dec  5 10:02:14 pshkadko kernel: [585784.143751] scsi: killing requests for dead queue
Dec  5 10:02:14 pshkadko kernel: [585784.143927] scsi: killing requests for dead queue
Dec  5 10:02:14 pshkadko kernel: [585784.144079] scsi: killing requests for dead queue
Dec  5 10:02:14 pshkadko kernel: [585784.144178] scsi: killing requests for dead queue
Dec  5 10:02:24 pshkadko kernel: [585793.691493] usb 1-1: USB disconnect, device number 7

cat /var/log/errors.log

Dec  5 10:02:01 pshkadko kernel: [585770.321427] [drm] nouveau 0000:01:00.0: GPU lockup - switching to software fbcon
Dec  5 10:02:14 pshkadko kernel: [585784.143550] sd 6:0:0:0: [sdb] No Caching mode page present
Dec  5 10:02:14 pshkadko kernel: [585784.143561] sd 6:0:0:0: [sdb] Assuming drive cache: write through

Last edited by tasty_minerals (2011-12-05 07:23:42)

pigiron · 2011-12-06 03:29:25

If you look at this, then it appears that it may be a kernel problem:

http://www.spinics.net/lists/linux-scsi/msg55636.html

But if you drill down into that thread, a developer says the real problem is "The implication from the trace seems to be that something allowed blkid to open a non existent device."

Then when I look at your log, it shows that the failing job is:

Dec 5 10:02:01 pshkadko kernel: [585770.321427] Pid: 16515, comm: hald-addon-stor Not tainted 3.1.1-1-ARCH #1

I wonder if the problem is somehow tied to using the depreciated hal daemon... but this is a total guess.

tasty_minerals · 2011-12-08 05:59:52

No, I don't have hal running on the startup. But hmm, maybe it is somehow invoked since I use pcmanfm to quick-browse my devices. Thanks, I shall test it.

Last edited by tasty_minerals (2011-12-08 06:00:03)

the.ridikulus.rat · 2011-12-08 11:32:15

Is this same as https://bbs.archlinux.org/viewtopic.php?id=131124? I opened that topic, but still no answer.

Arch Linux

#1 2011-12-05 07:22:52

Strange behavior with USB devices

#2 2011-12-06 03:29:25

Re: Strange behavior with USB devices

#3 2011-12-08 05:59:52

Re: Strange behavior with USB devices

#4 2011-12-08 11:32:15

Re: Strange behavior with USB devices

Board footer