Bug 234009 - Insertion of USB flash drive causes soft lockups (still)
Insertion of USB flash drive causes soft lockups (still)
Status: CLOSED ERRATA
Product: Fedora
Classification: Fedora
Component: kernel (Show other bugs)
6
All Linux
medium Severity medium
: ---
: ---
Assigned To: Kernel Maintainer List
Brian Brock
:
Depends On:
Blocks: 427887
  Show dependency treegraph
 
Reported: 2007-03-26 12:41 EDT by Jonathan Underwood
Modified: 2010-07-25 07:17 EDT (History)
2 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2008-01-08 05:55:55 EST
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
Output of dmesg (36.88 KB, text/plain)
2007-04-02 10:21 EDT, Jonathan Underwood
no flags Details
dmesg output showing messages from boot until lockup on insertion of usb key (61.09 KB, text/plain)
2007-05-10 17:10 EDT, Jonathan Underwood
no flags Details
Output of lspci -vvv (17.63 KB, text/plain)
2007-05-10 17:12 EDT, Jonathan Underwood
no flags Details

  None (edit)
Description Jonathan Underwood 2007-03-26 12:41:11 EDT
Description of problem:
Insertion of a USB drive causes a softlockup on smp machines and the system
hangs for a number of seconds. Observed on x86_64 SMP, but not i386 UP. (This
does go away if I use ub, as previously discussed in BZ 230322).

Version-Release number of selected component (if applicable):
kernel-2.6.20-1.2933.fc6


How reproducible:
Everytime

Steps to Reproduce:
1.Insert USB key
2.bang.
3.
  
Actual results:
Soft lockup

Expected results:
No soft lockup

Additional info:

usb-storage: device found at 5
usb-storage: waiting for device to settle before scanning
usbcore: registered new interface driver usb-storage
USB Mass Storage support registered.
BUG: soft lockup detected on CPU#1!

Call Trace:
 <IRQ>  [<ffffffff802b1004>] softlockup_tick+0xdb/0xf6
 [<ffffffff80417ad2>] neigh_timer_handler+0x0/0x31a
 [<ffffffff8028f925>] update_process_times+0x42/0x68
 [<ffffffff80272084>] smp_local_timer_interrupt+0x34/0x55
 [<ffffffff80284d92>] enqueue_task+0x41/0x56
 [<ffffffff80272760>] smp_apic_timer_interrupt+0x51/0x69
 [<ffffffff8025ace6>] apic_timer_interrupt+0x66/0x70
 [<ffffffff80260aab>] _spin_unlock_irq+0xb/0xc
 [<ffffffff8028f33e>] run_timer_softirq+0x122/0x1ac
 [<ffffffff80211fa5>] __do_softirq+0x55/0xc3
 [<ffffffff8025b23c>] call_softirq+0x1c/0x28
 [<ffffffff8026858d>] do_softirq+0x2c/0x85
 [<ffffffff80272765>] smp_apic_timer_interrupt+0x56/0x69
 [<ffffffff8025ace6>] apic_timer_interrupt+0x66/0x70
 <EOI>  [<ffffffff803a9be8>] __driver_attach+0x0/0xcd
 [<ffffffff80289f9d>] vprintk+0x2af/0x2ef
 [<ffffffff8028a02f>] printk+0x52/0xbd
 [<ffffffff802fc1cb>] sysfs_make_dirent+0x1b/0x8e
 [<ffffffff802fbb4b>] sysfs_add_file+0x76/0x85
 [<ffffffff803db0db>] usb_register_driver+0xc4/0xe0
 [<ffffffff881a7036>] :usb_storage:usb_stor_init+0x36/0x44
 [<ffffffff8029fcdf>] sys_init_module+0x1797/0x1904
 [<ffffffff8025a11e>] system_call+0x7e/0x83

BUG: soft lockup detected on CPU#0!

Call Trace:
 <IRQ>  [<ffffffff802b1004>] softlockup_tick+0xdb/0xf6
 [<ffffffff8028f53b>] process_timeout+0x0/0x5
 [<ffffffff8028f925>] update_process_times+0x42/0x68
 [<ffffffff80272084>] smp_local_timer_interrupt+0x34/0x55
 [<ffffffff80284d92>] enqueue_task+0x41/0x56
 [<ffffffff80272760>] smp_apic_timer_interrupt+0x51/0x69
 [<ffffffff8025ace6>] apic_timer_interrupt+0x66/0x70
 [<ffffffff80260aab>] _spin_unlock_irq+0xb/0xc
 [<ffffffff8028f33e>] run_timer_softirq+0x122/0x1ac
 [<ffffffff80211fa5>] __do_softirq+0x55/0xc3
 [<ffffffff8025b23c>] call_softirq+0x1c/0x28
 [<ffffffff8026858d>] do_softirq+0x2c/0x85
 [<ffffffff80272765>] smp_apic_timer_interrupt+0x56/0x69
 [<ffffffff8025ace6>] apic_timer_interrupt+0x66/0x70
 <EOI>  [<ffffffff80260aab>] _spin_unlock_irq+0xb/0xc
 [<ffffffff8028a2fe>] do_syslog+0x16c/0x3b2
 [<ffffffff80297f09>] autoremove_wake_function+0x0/0x2e
 [<ffffffff8025ef92>] thread_return+0xa6/0xf9
 [<ffffffff802f8ac5>] kmsg_read+0x3a/0x44
 [<ffffffff8020b14e>] vfs_read+0xcb/0x173
 [<ffffffff802117f1>] sys_read+0x45/0x6e
 [<ffffffff8025a11e>] system_call+0x7e/0x83

scsi 4:0:0:0: Direct-Access     SanDisk  U3 Titanium      3.21 PQ: 0 ANSI: 2
SCSI device sdb: 4001425 512-byte hdwr sectors (2049 MB)
sdb: Write Protect is off
sdb: Mode Sense: 03 00 00 00
sdb: assuming drive cache: write through
SCSI device sdb: 4001425 512-byte hdwr sectors (2049 MB)
sdb: Write Protect is off
sdb: Mode Sense: 03 00 00 00
sdb: assuming drive cache: write through
 sdb: sdb1 sdb2
sd 4:0:0:0: Attached scsi removable disk sdb
sd 4:0:0:0: Attached scsi generic sg2 type 0
scsi 4:0:0:1: CD-ROM            SanDisk  U3 Titanium      3.21 PQ: 0 ANSI: 2
sr1: scsi3-mmc drive: 8x/40x writer xa/form2 cdda tray
sr 4:0:0:1: Attached scsi CD-ROM sr1
sr 4:0:0:1: Attached scsi generic sg3 type 5
usb-storage: device scan complete
cdrom: This disc doesn't have any tracks I recognize!
SELinux: initialized (dev sdb2, type vfat), uses genfs_contexts
kjournald starting.  Commit interval 5 seconds
EXT3 FS on sdb1, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
SELinux: initialized (dev sdb1, type ext3), uses xattr
Comment 1 Chuck Ebbert 2007-03-28 11:46:50 EDT
This is one of those horrid SanDisk pieces of junk with the virtual
CD drive.  Removing that may help; the only way is to use the
Windows-based uninstaller.
Comment 2 Jonathan Underwood 2007-03-28 12:29:57 EDT
Hi Chuck,

Indeed, that backltrace was from a SanCrap, but it happens generally with USB
keys. Inserting a different (non-SanCrap) key:

usb 7-5.4: new high speed USB device using ehci_hcd and address 5
usb 7-5.4: configuration #1 chosen from 1 choice
Initializing USB Mass Storage driver...
scsi4 : SCSI emulation for USB Mass Storage devices
usb-storage: device found at 5
usb-storage: waiting for device to settle before scanning
usbcore: registered new interface driver usb-storage
USB Mass Storage support registered.
scsi 4:0:0:0: Direct-Access              USB DRIVE        2.00 PQ: 0 ANSI: 2
SCSI device sdb: 2023424 512-byte hdwr sectors (1036 MB)
sdb: Write Protect is off
sdb: Mode Sense: 03 00 00 00
sdb: assuming drive cache: write through
BUG: soft lockup detected on CPU#0!

Call Trace:
 <IRQ>  [<ffffffff802b1004>] softlockup_tick+0xdb/0xf6
 [<ffffffff8028f925>] update_process_times+0x42/0x68
 [<ffffffff80272084>] smp_local_timer_interrupt+0x34/0x55
 [<ffffffff80272760>] smp_apic_timer_interrupt+0x51/0x69
 [<ffffffff80253610>] mwait_idle+0x0/0x45
 [<ffffffff8025ace6>] apic_timer_interrupt+0x66/0x70
 <EOI>  [<ffffffff80253652>] mwait_idle+0x42/0x45
 [<ffffffff802462c0>] cpu_idle+0x8c/0xaf
 [<ffffffff80636792>] start_kernel+0x236/0x23b
 [<ffffffff8063615c>] _sinittext+0x15c/0x160

BUG: soft lockup detected on CPU#1!

Call Trace:
 <IRQ>  [<ffffffff802b1004>] softlockup_tick+0xdb/0xf6
 [<ffffffff8028f925>] update_process_times+0x42/0x68
 [<ffffffff80272084>] smp_local_timer_interrupt+0x34/0x55
 [<ffffffff80272760>] smp_apic_timer_interrupt+0x51/0x69
 [<ffffffff8025ace6>] apic_timer_interrupt+0x66/0x70
 <EOI>  [<ffffffff8022f452>] unix_poll+0x0/0x99
 [<ffffffff8021e527>] __pollwait+0xb6/0xe1
 [<ffffffff80260adb>] _spin_lock_irqsave+0x9/0xe
 [<ffffffff8022f46d>] unix_poll+0x1b/0x99
 [<ffffffff8022e937>] do_sys_poll+0x1b4/0x35f
 [<ffffffff8021e471>] __pollwait+0x0/0xe1
 [<ffffffff802864b5>] default_wake_function+0x0/0xe
 [<ffffffff802864b5>] default_wake_function+0x0/0xe
 [<ffffffff802864b5>] default_wake_function+0x0/0xe
 [<ffffffff802864b5>] default_wake_function+0x0/0xe
 [<ffffffff802864b5>] default_wake_function+0x0/0xe
 [<ffffffff802864b5>] default_wake_function+0x0/0xe
 [<ffffffff802864b5>] default_wake_function+0x0/0xe
 [<ffffffff802864b5>] default_wake_function+0x0/0xe
 [<ffffffff802864b5>] default_wake_function+0x0/0xe
 [<ffffffff802864b5>] default_wake_function+0x0/0xe
 [<ffffffff80260aa9>] _spin_unlock_irq+0x9/0xc
 [<ffffffff8025ef4a>] thread_return+0x5e/0xf9
 [<ffffffff8024913f>] sys_poll+0x2c/0x33
 [<ffffffff8025a11e>] system_call+0x7e/0x83

SCSI device sdb: 2023424 512-byte hdwr sectors (1036 MB)
sdb: Write Protect is off
sdb: Mode Sense: 03 00 00 00
sdb: assuming drive cache: write through
 sdb: sdb1
sd 4:0:0:0: Attached scsi removable disk sdb
sd 4:0:0:0: Attached scsi generic sg2 type 0
usb-storage: device scan complete
SELinux: initialized (dev sdb1, type vfat), uses genfs_contexts
Comment 3 Prarit Bhargava 2007-03-28 13:02:04 EDT
Johnathan, just curious if you've tried a more recent kernel (F7-test2 perhaps)?

I'd like to know if the problem still happens upstream :)

Thanks,

P.
Comment 4 Jonathan Underwood 2007-03-28 13:12:52 EDT
Hi Prarit,

I haven't I'm afraid - I just tried pulling over the F7 kernel and installing
that in FC-6, but unfortunately:

error: Failed dependencies:
        mkinitrd >= 6.0.4-1 is needed by kernel-2.6.20-1.3023.fc7.x86_64

I need to keep this machine relatively stable, as it's my main workbox, but I'll
look into maybe installing F7, or the live CD when I have a few mins spare.
Comment 5 Pete Zaitcev 2007-03-28 14:40:15 EDT
Just force the install, it'll work. It just asks for the latest RPMs
for things like lvm2. Most likely, not applicable to you. And you
can always re-run mkinitrd by hand after RPM has installed anyway.

Regardless how bad the flash key is, we should not lock up. Well, it's
possible to create a power outage or burn the port with a bad key, but
this does not seem the situation here.

I just wish I had the same situation locally reproducible...
Comment 6 Jonathan Underwood 2007-03-29 05:34:10 EDT
OK, I'll give that a go - unfortunately I won't be physically at that machine
until Monday now, though.
Comment 7 Jonathan Underwood 2007-04-02 10:20:11 EDT
OK, I did a rpm --nodeps -ivh to get the kernel to install, and that succesfully
boots. I am using kernel 2.6.20-1.3038.fc7 on an otherwise fully updated FC-6 box. 

Plugging in a USB stick no longer causes the soft lockups, so it seems that the
latest kernel fixes that. 

I'm attaching the output of dmesg after insertion of the memory key for
reference. This may be useful as it seems a lot more verbose about the hardware
etc as well than the FC6 kernels were. 

The output of lsusb and lspci for this machine can be found in BZ #230322.

Any chance of a kernel update for FC-6 that includes these fixes?

Is there any more information you'd like?
Comment 8 Jonathan Underwood 2007-04-02 10:21:02 EDT
Created attachment 151426 [details]
Output of dmesg

This is the output after booting and inserting the USB flash drive while in a
gnome session.
Comment 9 Jonathan Underwood 2007-04-02 10:50:46 EDT
Argh. On rebooting into kernel 2.6.20-1.2933.fc6, I am now finding that the soft
lockups don't occur on every insertion of a memory stick, so this is somewhat
intermittent. I rebooted into kernel 2.6.20-1.3038.fc7 and inserted the stick a
bunch more times, and didn't once lockup. But given that it's not occuring
everytime, that may not be conclusive.
Comment 10 Jonathan Underwood 2007-05-10 17:09:25 EDT
Still seeing lockups with the latest kernel. Different machine this time. Files
to follow.
Comment 11 Jonathan Underwood 2007-05-10 17:10:45 EDT
Created attachment 154498 [details]
dmesg output showing messages from boot until lockup on insertion of usb key
Comment 12 Jonathan Underwood 2007-05-10 17:12:10 EDT
Created attachment 154499 [details]
Output of lspci -vvv
Comment 13 Jonathan Underwood 2007-05-10 17:14:16 EDT
Regarding Comments 10, 11, and 12:

This is a USB key with the U3 junk removed by the U3 utility, and then
partitioned with one msdos partition and one ext 3 partition. 

I wonder if the lockup is occuring due to some race in trying to mount to
different filesystems simultaneously.
Comment 14 Jonathan Underwood 2007-05-10 17:18:54 EDT
Further to Comment 13:

# /sbin/fdisk -l /dev/sdb

Disk /dev/sdb: 2055 MB, 2055021056 bytes
255 heads, 63 sectors/track, 249 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes

   Device Boot      Start         End      Blocks   Id  System
/dev/sdb1   *         126         249      996030    c  W95 FAT32 (LBA)
/dev/sdb2               1         125     1004031   83  Linux

Partition table entries are not in disk order
Comment 15 Jonathan Underwood 2007-07-17 19:15:34 EDT
I haven't seen this issue arise at all in F7.
Comment 16 Jon Stanley 2008-01-07 20:55:28 EST
(This is a mass-update to all current FC6 kernel bugs in NEW state)

Hello,

I'm reviewing this bug list as part of the kernel bug triage project, an attempt
to isolate current bugs in the Fedora kernel.

http://fedoraproject.org/wiki/KernelBugTriage

I am CC'ing myself to this bug, however this version of Fedora is no longer
maintained.

Please attempt to reproduce this bug with a current version of Fedora (presently
Fedora 8). If the bug no longer exists, please close the bug or I'll do so in a
few days if there is no further information lodged.

Thanks for using Fedora!
Comment 17 Jonathan Underwood 2008-01-08 05:55:55 EST
Can't reproduce with F-8, so closing.

Note You need to log in before you can comment on or make changes to this bug.