Bug 138755

Summary: USB devices no longer recognized after disconnect/reconnect
Product: [Fedora] Fedora Reporter: Flavio Cardone <fcardone>
Component: kernelAssignee: Dave Jones <davej>
Status: CLOSED RAWHIDE QA Contact: Brian Brock <bbrock>
Severity: medium Docs Contact:
Priority: medium    
Version: 3CC: anvil, morgwai, peter.klotz99, pfrields, stig-redhat-bugzilla, wtogami
Target Milestone: ---   
Target Release: ---   
Hardware: i686   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2005-04-22 03:36:52 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
kernel oops & context (kernel 2.6.9-1.1032_FC4) none

Description Flavio Cardone 2004-11-10 23:59:14 UTC 
From Bugzilla Helper:
User-Agent: Mozilla/5.0 (X11; U; Linux i686; rv:1.7.3) Gecko/20040914
Firefox/0.10

Description of problem:
Using a Lite-ON DVD writer (external, USB) on an Acer laptop. Worked
OK with FC2. After upgrading to FC3, when the DVD writer is plugged in
to the USB port, it is correctly recognized at /dev/scd0 and can be
mounted/unmounted at will. However, if disconnected from the USB port,
when I reconnect it (to the same USB port or to any of the others),
the command

mount /dev/scd0

gives

mount: special device /dev/scd0 does not exist

as output and the device cannot be attached. Only solution is reboot.

Version-Release number of selected component (if applicable):
kernel-2.6.9-1.667

How reproducible:
Always

Steps to Reproduce:
1. Attach USB device, mount, unmount
2. Remove USB device
3. Attach again USB device, and it will not mount
    

Actual Results:  USB device was no longer recognized

Expected Results:  USB device should have been recognized

Additional info:

Everything was OK until FC3
Comment 1 Josef Bacik 2004-11-14 22:13:16 UTC 
Here's a stack trace from somebody else who's having this issue.

Nov 14 15:15:40 emiri kernel: usb 2-1: USB disconnect, address 3
Nov 14 15:15:41 emiri fstab-sync[6207]: removed mount point
/media/cdrecorder for /dev/scd0
Nov 14 15:15:45 emiri kernel: scsi: Device offlined - not ready after
error recovery: host 0 channel 0 id 0 lun 0
Nov 14 15:15:45 emiri kernel: sr 0:0:0:0: Illegal state transition
cancel->offline
Nov 14 15:15:45 emiri kernel: Badness in scsi_device_set_state at
drivers/scsi/scsi_lib.c:1688
Nov 14 15:15:45 emiri kernel:  [<16d8f645>]
scsi_device_set_state+0xc8/0xd3 [scsi_mod]
Nov 14 15:15:45 emiri kernel:  [<16d8cb8b>]
scsi_eh_offline_sdevs+0x49/0x5e [scsi_mod]
Nov 14 15:15:45 emiri kernel:  [<16d8d146>]
scsi_unjam_host+0x22d/0x23e [scsi_mod]
Nov 14 15:15:45 emiri kernel:  [<16d8d291>]
scsi_error_handler+0x13a/0x191 [scsi_mod]
Nov 14 15:15:45 emiri kernel:  [<0211b3d9>] schedule_tail+0xc/0x37
Nov 14 15:15:45 emiri kernel:  [<16d8d157>]
scsi_error_handler+0x0/0x191 [scsi_mod]
Nov 14 15:15:45 emiri kernel:  [<021041d9>] kernel_thread_helper+0x5/0xb
Nov 14 15:15:45 emiri kernel: Unable to handle kernel NULL pointer
dereference at virtual address 00000008
Nov 14 15:15:45 emiri kernel:  printing eip:
Nov 14 15:15:45 emiri kernel: 0224fb8f
Nov 14 15:15:45 emiri kernel: *pde = 00000000
Nov 14 15:15:45 emiri kernel: Oops: 0000 [#1]
Nov 14 15:15:45 emiri kernel: Modules linked in: sr_mod usb_storage
scsi_mod vfat fat i915 md5 ipv6 parport_pc lp parport i8k ds
hsfmc97ali(U) hsfmc97via(U) hsfmc97ich(U) hsfpcibasic2(U) hsfserial(U)
hsfengine(U) hsfosspec(U) hsfsoar(U) ipt_REJECT ipt_state ip_conntrack
iptable_filter ip_tables dm_mod button battery ac joydev yenta_socket
pcmcia_core uhci_hcd hw_random snd_intel8x0m snd_intel8x0
snd_ac97_codec snd_pcm_oss snd_mixer_oss snd_pcm snd_timer
snd_page_alloc gameport snd_mpu401_uart snd_rawmidi snd_seq_device snd
soundcore 3c59x floppy ext3 jbd
Nov 14 15:15:45 emiri kernel: CPU:    0
Nov 14 15:15:45 emiri kernel: EIP:    0060:[<0224fb8f>]    Tainted: P
  VLI
Nov 14 15:15:45 emiri kernel: EFLAGS: 00010046   (2.6.9-1.667)
Nov 14 15:15:45 emiri kernel: EIP is at cfq_insert_request+0x45/0xdf
Nov 14 15:15:45 emiri kernel: eax: 1586b290   ebx: 033f72b0   ecx:
00000001   edx: 033f72b0
Nov 14 15:15:45 emiri kernel: esi: 00000001   edi: 00000000   ebp:
00000000   esp: 0c3c7efc
Nov 14 15:15:45 emiri kernel: ds: 007b   es: 007b   ss: 0068
Nov 14 15:15:45 emiri kernel: Process scsi_eh_0 (pid: 5689,
threadinfo=0c3c7000 task=0b93a7d0)
Nov 14 15:15:45 emiri kernel: Stack: 1586b290 1586b290 00000001
033f72b0 00000202 02246367 1586b290 00000001
Nov 14 15:15:45 emiri kernel:        033f72b0 02246329 00000000
022484d8 11051c40 04fecc00 04fec400 00001057
Nov 14 15:15:45 emiri kernel:        16d8d576 11051c40 00000001
11051c40 0c3c7f74 0c3c7f74 0c3c7f7c 16d8cec8
Nov 14 15:15:45 emiri kernel: Call Trace:
Nov 14 15:15:45 emiri kernel:  [<02246367>] __elv_add_request+0x3c/0x71
Nov 14 15:15:45 emiri kernel:  [<02246329>] elv_requeue_request+0x29/0x2b
Nov 14 15:15:45 emiri kernel:  [<022484d8>] blk_insert_request+0xba/0x18b
Nov 14 15:15:45 emiri kernel:  [<16d8d576>]
scsi_queue_insert+0x84/0x8d [scsi_mod]
Nov 14 15:15:45 emiri kernel:  [<16d8cec8>]
scsi_eh_flush_done_q+0x7d/0xce [scsi_mod]
Nov 14 15:15:45 emiri kernel:  [<16d8d14f>]
scsi_unjam_host+0x236/0x23e [scsi_mod]
Nov 14 15:15:45 emiri kernel:  [<16d8d291>]
scsi_error_handler+0x13a/0x191 [scsi_mod]
Nov 14 15:15:45 emiri kernel:  [<0211b3d9>] schedule_tail+0xc/0x37
Nov 14 15:15:45 emiri kernel:  [<16d8d157>]
scsi_error_handler+0x0/0x191 [scsi_mod]
Nov 14 15:15:45 emiri kernel:  [<021041d9>] kernel_thread_helper+0x5/0xb
Nov 14 15:15:45 emiri kernel: Code: 74 29 eb 51 83 f9 03 74 33 eb 4a
8b 04 24 89 fa e8 f8 fa ff ff 85 c0 75 f2 8b 47 08 8b 50 04 89 03 89
58 04 89 1a 89 53 04 eb 3f <8b> 47 08 8b 10 89 5a 04 89 13 89 43 04 89
18 eb 2e f6 42 08 10
Comment 2 morgwai kotarbinski 2004-11-21 14:25:29 UTC 
the problem i also present in new kernel-2.6.9-1.678_FC3. i've
reproduced it also with usb lite-on dvd recorder and with my minolta
d-image x20 digital camera.
here are my logs from /var/log/messages:
------------------
Nov 21 14:35:57 darkstorm kernel: usb 1-3: new high speed USB device
using address 2
Nov 21 14:35:58 darkstorm kernel: SCSI subsystem initialized
Nov 21 14:35:58 darkstorm kernel: Initializing USB Mass Storage driver...
Nov 21 14:35:58 darkstorm kernel: scsi0 : SCSI emulation for USB Mass
Storage devices
Nov 21 14:35:59 darkstorm kernel:   Vendor: LITE-ON   Model: DVDRW
SOHW-832S   Rev: VS0A
Nov 21 14:35:59 darkstorm kernel:   Type:   CD-ROM                   
         ANSI SCSI revision: 02
Nov 21 14:35:59 darkstorm scsi.agent[5478]: cdrom at
/devices/pci0000:00/0000:00:10.3/usb1/1-3/1-3:1.0/host0/0:0:0:0
Nov 21 14:35:59 darkstorm kernel: usbcore: registered new driver
usb-storage
Nov 21 14:35:59 darkstorm kernel: USB Mass Storage support registered.
Nov 21 14:35:59 darkstorm kernel: sr0: scsi3-mmc drive: 40x/40x writer
cd/rw xa/form2 cdda tray
Nov 21 14:36:00 darkstorm fstab-sync[5539]: added mount point
/media/cdrecorder for /dev/scd0
Nov 21 14:37:45 darkstorm kernel: usb 1-3: USB disconnect, address 2
Nov 21 14:37:45 darkstorm fstab-sync[5580]: removed mount point
/media/cdrecorder for /dev/scd0
Nov 21 14:37:50 darkstorm kernel: scsi: Device offlined - not ready
after error recovery: host 0 channel 0 id 0 lun 0
Nov 21 14:37:50 darkstorm kernel: sr 0:0:0:0: Illegal state transition
cancel->offline
Nov 21 14:37:50 darkstorm kernel: Badness in scsi_device_set_state at
drivers/scsi/scsi_lib.c:1688
Nov 21 14:37:50 darkstorm kernel:  [<42c3e645>]
scsi_device_set_state+0xc8/0xd3 [scsi_mod]
Nov 21 14:37:50 darkstorm kernel:  [<42c3bb8b>]
scsi_eh_offline_sdevs+0x49/0x5e [scsi_mod]
Nov 21 14:37:50 darkstorm kernel:  [<42c3c146>]
scsi_unjam_host+0x22d/0x23e [scsi_mod]
Nov 21 14:37:50 darkstorm kernel:  [<42c3c291>]
scsi_error_handler+0x13a/0x191 [scsi_mod]
Nov 21 14:37:50 darkstorm kernel:  [<0211b3d5>] schedule_tail+0xc/0x37
Nov 21 14:37:50 darkstorm kernel:  [<42c3c157>]
scsi_error_handler+0x0/0x191 [scsi_mod]
Nov 21 14:37:50 darkstorm kernel:  [<021041d9>]
kernel_thread_helper+0x5/0xb
Nov 21 14:37:50 darkstorm kernel: Unable to handle kernel NULL pointer
dereference at virtual address 00000008
Nov 21 14:37:50 darkstorm kernel:  printing eip:
Nov 21 14:37:50 darkstorm kernel: 02250207
Nov 21 14:37:50 darkstorm kernel: *pde = 00000000
Nov 21 14:37:50 darkstorm kernel: Oops: 0000 [#1]
Nov 21 14:37:50 darkstorm kernel: Modules linked in: sr_mod
usb_storage scsi_mod nls_utf8 radeon parport_pc lp parport autofs4
i2c_dev i2c_core ds vfat fat dm_mod button battery ac md5 ipv6
ohci1394 ieee1394 yenta_socket pcmcia_core uhci_hcd ehci_hcd
snd_via82xx snd_ac97_codec snd_pcm_oss snd_mixer_oss snd_pcm snd_timer
snd_page_alloc gameport snd_mpu401_uart snd_rawmidi snd_seq_device snd
soundcore via_rhine mii floppy ext3 jbd
Nov 21 14:37:50 darkstorm kernel: CPU:    0
Nov 21 14:37:50 darkstorm kernel: EIP:    0060:[<02250207>]    Not
tainted VLI
Nov 21 14:37:50 darkstorm kernel: EFLAGS: 00010046   (2.6.9-1.678_FC3)
Nov 21 14:37:50 darkstorm kernel: EIP is at cfq_insert_request+0x45/0xdf
Nov 21 14:37:50 darkstorm kernel: eax: 39e9e4b8   ebx: 39e198b0   ecx:
00000001   edx: 39e198b0
Nov 21 14:37:50 darkstorm kernel: esi: 00000001   edi: 00000000   ebp:
00000000   esp: 2eee7efc
Nov 21 14:37:50 darkstorm kernel: ds: 007b   es: 007b   ss: 0068
Nov 21 14:37:50 darkstorm kernel: Process scsi_eh_0 (pid: 5450,
threadinfo=2eee7000 task=38ad60f0)
Nov 21 14:37:50 darkstorm kernel: Stack: 39e9e4b8 39e9e4b8 00000001
39e198b0 00000202 022469e3 39e9e4b8 00000001
Nov 21 14:37:50 darkstorm kernel:        39e198b0 022469a5 00000000
02248b52 28e7bac0 3a371c00 393d9800 00001057
Nov 21 14:37:50 darkstorm kernel:        42c3c576 28e7bac0 00000001
28e7bac0 2eee7f74 2eee7f74 2eee7f7c 42c3bec8
Nov 21 14:37:50 darkstorm kernel: Call Trace:
Nov 21 14:37:50 darkstorm kernel:  [<022469e3>]
__elv_add_request+0x3c/0x71
Nov 21 14:37:50 darkstorm kernel:  [<022469a5>]
elv_requeue_request+0x29/0x2b
Nov 21 14:37:50 darkstorm kernel:  [<02248b52>]
blk_insert_request+0xba/0x18b
Nov 21 14:37:50 darkstorm kernel:  [<42c3c576>]
scsi_queue_insert+0x84/0x8d [scsi_mod]
Nov 21 14:37:50 darkstorm kernel:  [<42c3bec8>]
scsi_eh_flush_done_q+0x7d/0xce [scsi_mod]
Nov 21 14:37:50 darkstorm kernel:  [<42c3c14f>]
scsi_unjam_host+0x236/0x23e [scsi_mod]
Nov 21 14:37:50 darkstorm kernel:  [<42c3c291>]
scsi_error_handler+0x13a/0x191 [scsi_mod]
Nov 21 14:37:50 darkstorm kernel:  [<0211b3d5>] schedule_tail+0xc/0x37
Nov 21 14:37:50 darkstorm kernel:  [<42c3c157>]
scsi_error_handler+0x0/0x191 [scsi_mod]
Nov 21 14:37:50 darkstorm kernel:  [<021041d9>]
kernel_thread_helper+0x5/0xb
Nov 21 14:37:50 darkstorm kernel: Code: 74 29 eb 51 83 f9 03 74 33 eb
4a 8b 04 24 89 fa e8 f8 fa ff ff 85 c0 75 f2 8b 47 08 8b 50 04 89 03
89 58 04 89 1a 89 53 04 eb 3f <8b> 47 08 8b 10 89 5a 04 89 13 89 43 04
89 18 eb 2e f6 42 08 10
------------

additionaly after this i get a kernel oops when trying to powerdown my
machine. it looks somelike this:
-----------
null ptr deref at vaddr 0000 0004
eip: 0224 5929
*pde = 0
oops: 0000 [#2]
cpu: 0
eip: 0060:[<0224 5929>] Not tained VLI
eflags: 0001 0246
eip is at device_shutdown+0x34/0x72
eax: ffff ffc0 ebx: ffff ffc0 ecx: 0 edx: 0 
esi: 0236 bb28 edi: 0123 4567 ebp: 4051 1000 esp: 4051 1ea8
ds: 007b es: 007b ss 0068
process reboot (pid 4939 threadinfo = 4051 1000 task = 3a05 5370)
call trace:
0212 fa1f sys_reboot      + 0x199 / 0x51f
0230 60a4 __cond_resched  +  0x14 /  0x36
022a e18c netdev_run_todo +  0x29 / 0x26f
022e 88cc devinet_ioctl   + 0x577 / 0x5a8
0218 35dd destroy_inode   +  0x36 /  0x45
0217 f3b3 dput            +  0x33 / 0x4f3
0216 652a __fput          +  0xc9 /  0xee
0216 4d90 flip_close      +  0x59 /  0x59
code: bad eip value
----------------------
(i can provide the stack values if it helps)
Comment 3 morgwai kotarbinski 2004-11-22 13:41:02 UTC 
not every usb device emulating scsi reproduces this bug - my kingston
memory stick works fine (i can plug and unplug it as many times as i want)
Comment 4 Stig Hackvan 2004-11-28 01:52:58 UTC 
I have the same problem with usb-storage devices...  here's one trace
from turning on-and-then-off my LITE-ON dvd+rw drive:

## /home/stig >> uname -a
Linux usul.sietch.net 2.6.9-1.681_FC3 #1 Thu Nov 18 15:10:10 EST 2004
i686 athlon i386 GNU/Linux


Nov 27 17:45:35 usul kernel: usb 1-4: new high speed USB device using
address 5
Nov 27 17:45:35 usul kernel: scsi3 : SCSI emulation for USB Mass
Storage devices
Nov 27 17:45:35 usul kernel:   Vendor: LITE-ON   Model: DVD+RW
LDW-401S   Rev: ES0J
Nov 27 17:45:35 usul kernel:   Type:   CD-ROM                        
    ANSI SCSI revision: 02
Nov 27 17:45:35 usul scsi.agent[9758]: cdrom at
/devices/pci0000:00/0000:00:13.2/usb1/1-4/1-4:1.0/host3/3 :0:0:0
Nov 27 17:45:35 usul kernel: usb 1-4: new high speed USB device using
address 5
Nov 27 17:45:35 usul kernel: scsi3 : SCSI emulation for USB Mass
Storage devices
Nov 27 17:45:35 usul kernel:   Vendor: LITE-ON   Model: DVD+RW
LDW-401S   Rev: ES0J
Nov 27 17:45:35 usul kernel:   Type:   CD-ROM                        
    ANSI SCSI revision: 02
Nov 27 17:45:35 usul scsi.agent[9758]: cdrom at
/devices/pci0000:00/0000:00:13.2/usb1/1-4/1-4:1.0/host3/3 :0:0:0
Nov 27 17:45:36 usul kernel: sr0: scsi3-mmc drive: 94x/40x writer
cd/rw xa/form2 cdda tray
Nov 27 17:45:36 usul kernel: Uniform CD-ROM driver Revision: 3.20
Nov 27 17:45:36 usul kernel: sr0: scsi3-mmc drive: 94x/40x writer
cd/rw xa/form2 cdda tray
Nov 27 17:45:36 usul kernel: Uniform CD-ROM driver Revision: 3.20
Nov 27 17:45:57 usul kernel: usb 1-4: USB disconnect, address 5
Nov 27 17:45:57 usul kernel: usb 1-4: USB disconnect, address 5
Nov 27 17:46:02 usul kernel: scsi: Device offlined - not ready after
error recovery: host 3 channel 0 id 0 lun 0
Nov 27 17:46:02 usul kernel: sr 3:0:0:0: Illegal state transition
cancel->offline
Nov 27 17:46:02 usul kernel: Badness in scsi_device_set_state at
drivers/scsi/scsi_lib.c:1691
Nov 27 17:46:02 usul kernel:  [<4285f643>]
scsi_device_set_state+0xc8/0xd3 [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<4285cb8b>]
scsi_eh_offline_sdevs+0x49/0x5e [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<4285d146>] scsi_unjam_host+0x22d/0x23e
[scsi_mod]
Nov 27 17:46:02 usul kernel:  [<4285d291>]
scsi_error_handler+0x13a/0x191 [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<0211b669>] schedule_tail+0xc/0x37
Nov 27 17:46:02 usul kernel:  [<4285d157>]
scsi_error_handler+0x0/0x191 [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<021041d9>] kernel_thread_helper+0x5/0xb
Nov 27 17:46:02 usul kernel: Unable to handle kernel NULL pointer
dereference at virtual address 00000008
Nov 27 17:46:02 usul kernel:  printing eip:
Nov 27 17:46:02 usul kernel: 02250a37
Nov 27 17:46:02 usul kernel: *pde = 00000000
Nov 27 17:46:02 usul kernel: Oops: 0000 [#1]
Nov 27 17:46:02 usul kernel: Modules linked in: sr_mod mga nfsd
exportfs lockd iptable_filter ip_tables m d5 ipv6 parport_pc lp
parport autofs4 i2c_dev i2c_core ds sunrpc nls_utf8 loop dm_mod button
battery ac y enta_socket pcmcia_core usb_storage ohci_hcd uhci_hcd
ehci_hcd snd_ens1371 snd_rawmidi snd_seq_device snd _pcm_oss
snd_mixer_oss snd_pcm snd_timer snd_page_alloc snd_ac97_codec snd
soundcore gameport 8139too mii  sis900 floppy ext3 jbd initio sd_mod
scsi_mod
Nov 27 17:46:02 usul kernel: CPU:    0
Nov 27 17:46:02 usul kernel: EIP:    0060:[<02250a37>]    Not tainted VLI
Nov 27 17:46:02 usul kernel: EFLAGS: 00010046   (2.6.9-1.681_FC3)
Nov 27 17:46:02 usul kernel: EIP is at cfq_insert_request+0x45/0xdf
Nov 27 17:46:02 usul kernel: eax: 3ec6a0c8   ebx: 1550d0b0   ecx:
00000001   edx: 1550d0b0
Nov 27 17:46:02 usul kernel: esi: 00000001   edi: 00000000   ebp:
00000000   esp: 15be9efc
Nov 27 17:46:02 usul kernel: ds: 007b   es: 007b   ss: 0068
Nov 27 17:46:02 usul kernel: Process scsi_eh_3 (pid: 9722,
threadinfo=15be9000 task=17a1f450)
Nov 27 17:46:02 usul kernel: Stack: 3ec6a0c8 3ec6a0c8 00000001
1550d0b0 00000202 02247213 3ec6a0c8 000000 01
Nov 27 17:46:02 usul kernel:        1550d0b0 022471d5 00000000
02249382 41cb6ac0 153a8c00 174b8400 000010 57
Nov 27 17:46:02 usul kernel:        4285d576 41cb6ac0 00000001
41cb6ac0 15be9f74 15be9f74 15be9f7c 4285ce c8
Nov 27 17:46:02 usul kernel: Call Trace:
Nov 27 17:46:02 usul kernel:  [<02247213>] __elv_add_request+0x3c/0x71
Nov 27 17:46:02 usul kernel:  [<022471d5>] elv_requeue_request+0x29/0x2b
Nov 27 17:46:02 usul kernel:  [<02249382>] blk_insert_request+0xba/0x18b
Nov 27 17:46:02 usul kernel:  [<4285d576>] scsi_queue_insert+0x84/0x8d
[scsi_mod]
Nov 27 17:46:02 usul kernel:  [<4285cec8>]
scsi_eh_flush_done_q+0x7d/0xce [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<4285d14f>] scsi_unjam_host+0x236/0x23e
[scsi_mod]
Nov 27 17:46:02 usul kernel:  [<4285d291>]
scsi_error_handler+0x13a/0x191 [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<0211b669>] schedule_tail+0xc/0x37
Nov 27 17:46:02 usul kernel:  [<4285d157>]
scsi_error_handler+0x0/0x191 [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<021041d9>] kernel_thread_helper+0x5/0xb
Nov 27 17:46:02 usul kernel: Code: 74 29 eb 51 83 f9 03 74 33 eb 4a 8b
04 24 89 fa e8 f8 fa ff ff 85 c0 7 5 f2 8b 47 08 8b 50 04 89 03 89 58
04 89 1a 89 53 04 eb 3f <8b> 47 08 8b 10 89 5a 04 89 13 89 43 04 89 18
 eb 2e f6 42 08 10
Nov 27 17:46:02 usul kernel: scsi: Device offlined - not ready after
error recovery: host 3 channel 0 id 0 lun 0
Nov 27 17:46:02 usul kernel: sr 3:0:0:0: Illegal state transition
cancel->offline
Nov 27 17:46:02 usul kernel: Badness in scsi_device_set_state at
drivers/scsi/scsi_lib.c:1691
Nov 27 17:46:02 usul kernel:  [<4285f643>]
scsi_device_set_state+0xc8/0xd3 [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<4285cb8b>]
scsi_eh_offline_sdevs+0x49/0x5e [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<4285d146>] scsi_unjam_host+0x22d/0x23e
[scsi_mod]
Nov 27 17:46:02 usul kernel:  [<4285d291>]
scsi_error_handler+0x13a/0x191 [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<0211b669>] schedule_tail+0xc/0x37
Nov 27 17:46:02 usul kernel:  [<4285d157>]
scsi_error_handler+0x0/0x191 [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<021041d9>] kernel_thread_helper+0x5/0xb
Nov 27 17:46:02 usul kernel: Unable to handle kernel NULL pointer
dereference at virtual address 00000008
Nov 27 17:46:02 usul kernel:  printing eip:
Nov 27 17:46:02 usul kernel: 02250a37
Nov 27 17:46:02 usul kernel: *pde = 00000000
Nov 27 17:46:02 usul kernel: Oops: 0000 [#1]
Nov 27 17:46:02 usul kernel: Modules linked in: sr_mod mga nfsd
exportfs lockd iptable_filter ip_tables m d5 ipv6 parport_pc lp
parport autofs4 i2c_dev i2c_core ds sunrpc nls_utf8 loop dm_mod button
battery ac y enta_socket pcmcia_core usb_storage ohci_hcd uhci_hcd
ehci_hcd snd_ens1371 snd_rawmidi snd_seq_device snd _pcm_oss
snd_mixer_oss snd_pcm snd_timer snd_page_alloc snd_ac97_codec snd
soundcore gameport 8139too mii  sis900 floppy ext3 jbd initio sd_mod
scsi_mod
Nov 27 17:46:02 usul kernel: CPU:    0
Nov 27 17:46:02 usul kernel: EIP:    0060:[<02250a37>]    Not tainted VLI
Nov 27 17:46:02 usul kernel: EFLAGS: 00010046   (2.6.9-1.681_FC3)
Nov 27 17:46:02 usul kernel: EIP is at cfq_insert_request+0x45/0xdf
Nov 27 17:46:02 usul kernel: eax: 3ec6a0c8   ebx: 1550d0b0   ecx:
00000001   edx: 1550d0b0
Nov 27 17:46:02 usul kernel: esi: 00000001   edi: 00000000   ebp:
00000000   esp: 15be9efc
Nov 27 17:46:02 usul kernel: ds: 007b   es: 007b   ss: 0068
Nov 27 17:46:02 usul kernel: Process scsi_eh_3 (pid: 9722,
threadinfo=15be9000 task=17a1f450)
Nov 27 17:46:02 usul kernel: Stack: 3ec6a0c8 3ec6a0c8 00000001
1550d0b0 00000202 02247213 3ec6a0c8 000000 01
Nov 27 17:46:02 usul kernel:        1550d0b0 022471d5 00000000
02249382 41cb6ac0 153a8c00 174b8400 000010 57
Nov 27 17:46:02 usul kernel:        4285d576 41cb6ac0 00000001
41cb6ac0 15be9f74 15be9f74 15be9f7c 4285ce c8
Nov 27 17:46:02 usul kernel: Call Trace:
Nov 27 17:46:02 usul kernel:  [<02247213>] __elv_add_request+0x3c/0x71
Nov 27 17:46:02 usul kernel:  [<022471d5>] elv_requeue_request+0x29/0x2b
Nov 27 17:46:02 usul kernel:  [<02249382>] blk_insert_request+0xba/0x18b
Nov 27 17:46:02 usul kernel:  [<4285d576>] scsi_queue_insert+0x84/0x8d
[scsi_mod]
Nov 27 17:46:02 usul kernel:  [<4285cec8>]
scsi_eh_flush_done_q+0x7d/0xce [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<4285d14f>] scsi_unjam_host+0x236/0x23e
[scsi_mod]
Nov 27 17:46:02 usul kernel:  [<4285d291>]
scsi_error_handler+0x13a/0x191 [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<0211b669>] schedule_tail+0xc/0x37
Nov 27 17:46:02 usul kernel:  [<4285d157>]
scsi_error_handler+0x0/0x191 [scsi_mod]
Nov 27 17:46:02 usul kernel:  [<021041d9>] kernel_thread_helper+0x5/0xb
Nov 27 17:46:02 usul kernel: Code: 74 29 eb 51 83 f9 03 74 33 eb 4a 8b
04 24 89 fa e8 f8 fa ff ff 85 c0 7 5 f2 8b 47 08 8b 50 04 89 03 89 58
04 89 1a 89 53 04 eb 3f <8b> 47 08 8b 10 89 5a 04 89 13 89 43 04 89 18
 eb 2e f6 42 08 10
Comment 5 Stig Hackvan 2004-11-28 02:04:07 UTC 
here's another trace from unmounting and removing a sandisk 512m SD
card from a sandisk reader.  

****WHAT WAS PARTICULARLY INTERESTING ABOUT THIS GOOF IS/WAS THAT THE
COMMAND TO COPY DATA TO THE CARD HAD COMPLETED, BUT THE BUFFER HADN'T
FLUSHED WHEN THE UNMOUNT COMMAND WAS ISSUED.  INSTEAD OF WAITING FOR
I/O ON THE CARD TO COMPLETE (AS I'VE GROWN TO EXPECT FROM PREVIOUSLY
WELL-BEHAVED KERNELS), MOUNT JUST OFFLINED THE DEVICE, GENERATING A
SLEW OF I/O ERRORS BEFORE THE OOPS...***

Nov 25 11:30:03 usul kernel: SCSI error : <1 0 0 0> return code = 0x70000
Nov 25 11:30:03 usul kernel: end_request: I/O error, dev sda, sector
265929
Nov 25 11:30:03 usul kernel: Buffer I/O error on device sda1, logical
block 265692
Nov 25 11:30:03 usul kernel: lost page write due to I/O error on sda1
Nov 25 11:30:24 usul ntpd[3024]: kernel time sync disabled 0041
Nov 25 11:30:33 usul kernel: scsi: Device offlined - not ready after
error recovery: host 1 channel 0 id 0 lun 0
Nov 25 11:30:33 usul kernel: sd 1:0:0:0: Illegal state transition
cancel->offline
Nov 25 11:30:33 usul kernel: Badness in scsi_device_set_state at
drivers/scsi/scsi_lib.c:1691
Nov 25 11:30:33 usul kernel:  [<4285f643>]
scsi_device_set_state+0xc8/0xd3 [scsi_mod]
Nov 25 11:30:33 usul kernel:  [<4285cb8b>]
scsi_eh_offline_sdevs+0x49/0x5e [scsi_mod]
Nov 25 11:30:33 usul kernel:  [<4285d146>] scsi_unjam_host+0x22d/0x23e
[scsi_mod]
Nov 25 11:30:33 usul kernel:  [<4285d291>]
scsi_error_handler+0x13a/0x191 [scsi_mod]
Nov 25 11:30:33 usul kernel:  [<0211b669>] schedule_tail+0xc/0x37
Nov 25 11:30:33 usul kernel:  [<4285d157>]
scsi_error_handler+0x0/0x191 [scsi_mod]
Nov 25 11:30:33 usul kernel:  [<021041d9>] kernel_thread_helper+0x5/0xb
Nov 25 11:30:33 usul kernel: SCSI error : <1 0 0 0> return code = 0x70000
Nov 25 11:30:33 usul kernel: end_request: I/O error, dev sda, sector
265930
Nov 25 11:30:33 usul kernel: Buffer I/O error on device sda1, logical
block 265693
Nov 25 11:30:33 usul kernel: lost page write due to I/O error on sda1
Nov 25 11:30:43 usul kernel: scsi: Device offlined - not ready after
error recovery: host 1 channel 0 id 0 lun 0
Nov 25 11:30:43 usul kernel: sd 1:0:0:0: Illegal state transition
cancel->offline
Nov 25 11:30:43 usul kernel: Badness in scsi_device_set_state at
drivers/scsi/scsi_lib.c:1691
Nov 25 11:30:43 usul kernel:  [<4285f643>]
scsi_device_set_state+0xc8/0xd3 [scsi_mod]
Nov 25 11:30:43 usul kernel:  [<4285cb8b>]
scsi_eh_offline_sdevs+0x49/0x5e [scsi_mod]
Nov 25 11:30:43 usul kernel:  [<4285d146>] scsi_unjam_host+0x22d/0x23e
[scsi_mod]
Nov 25 11:30:43 usul kernel:  [<428595c5>]
__scsi_iterate_devices+0x123/0x12b [scsi_mod]
Nov 25 11:30:43 usul kernel:  [<4285d291>]
scsi_error_handler+0x13a/0x191 [scsi_mod]
Nov 25 11:30:43 usul kernel:  [<0211b669>] schedule_tail+0xc/0x37
Nov 25 11:30:43 usul kernel:  [<4285d157>]
scsi_error_handler+0x0/0x191 [scsi_mod]
Nov 25 11:30:43 usul kernel:  [<021041d9>] kernel_thread_helper+0x5/0xb
Nov 25 11:30:43 usul kernel: Unable to handle kernel NULL pointer
dereference at virtual address 00000008
Nov 25 11:30:43 usul kernel:  printing eip:
Nov 25 11:30:43 usul kernel: 02250a37
Nov 25 11:30:43 usul kernel: *pde = 00000000
Nov 25 11:30:43 usul kernel: Oops: 0000 [#1]
Nov 25 11:30:43 usul kernel: Modules linked in: vfat fat mga nfsd
iptable_filter ip_tables exportfs lockd md5 ipv6 parport_pc lp parport
autofs4 i2c_dev i2c_core ds sunrpc nls_utf8 loop dm_mod button battery
ac yenta_socket pcmcia_core usb_storage ohci_hcd uhci_hcd ehci_hcd
snd_ens1371 snd_rawmidi snd_seq_device snd_pcm_oss snd_mixer_oss
snd_pcm snd_timer snd_page_alloc snd_ac97_codec snd soundcore gameport
8139too mii sis900 floppy ext3 jbd initio sd_mod scsi_mod
Nov 25 11:30:43 usul kernel: CPU:    0
Nov 25 11:30:43 usul kernel: EIP:    0060:[<02250a37>]    Not tainted VLI
Nov 25 11:30:43 usul kernel: EFLAGS: 00010046   (2.6.9-1.681_FC3)
Nov 25 11:30:43 usul kernel: EIP is at cfq_insert_request+0x45/0xdf
Nov 25 11:30:43 usul kernel: eax: 3fd34d78   ebx: 39e79cb0   ecx:
00000001   edx: 39e79cb0
Nov 25 11:30:43 usul kernel: esi: 00000001   edi: 00000000   ebp:
00000000   esp: 3fca2efc
Nov 25 11:30:43 usul kernel: ds: 007b   es: 007b   ss: 0068
Nov 25 11:30:43 usul kernel: Process scsi_eh_1 (pid: 1565,
threadinfo=3fca2000 task=403f0e90)
Nov 25 11:30:43 usul kernel: Stack: 3fd34d78 3fd34d78 00000001
39e79cb0 00000202 02247213 3fd34d78 00000001
Nov 25 11:30:43 usul kernel:        39e79cb0 022471d5 00000000
02249382 41cbd340 40b08400 3fc33800 00001057
Nov 25 11:30:43 usul kernel:        4285d576 41cbd340 00000001
41cbd340 3fca2f74 3fca2f74 3fca2f7c 4285cec8
Nov 25 11:30:43 usul kernel: Call Trace:
Nov 25 11:30:43 usul kernel:  [<02247213>] __elv_add_request+0x3c/0x71
Nov 25 11:30:43 usul kernel:  [<022471d5>] elv_requeue_request+0x29/0x2b
Nov 25 11:30:43 usul kernel:  [<02249382>] blk_insert_request+0xba/0x18b
Nov 25 11:30:43 usul kernel:  [<4285d576>] scsi_queue_insert+0x84/0x8d
[scsi_mod]
Nov 25 11:30:43 usul kernel:  [<4285cec8>]
scsi_eh_flush_done_q+0x7d/0xce [scsi_mod]
Nov 25 11:30:43 usul kernel:  [<4285d14f>] scsi_unjam_host+0x236/0x23e
[scsi_mod]
Nov 25 11:30:43 usul kernel:  [<428595c5>]
__scsi_iterate_devices+0x123/0x12b [scsi_mod]
Nov 25 11:30:43 usul kernel:  [<4285d291>]
scsi_error_handler+0x13a/0x191 [scsi_mod]
Nov 25 11:30:43 usul kernel:  [<0211b669>] schedule_tail+0xc/0x37
Nov 25 11:30:43 usul kernel:  [<4285d157>]
scsi_error_handler+0x0/0x191 [scsi_mod]
Nov 25 11:30:43 usul kernel:  [<021041d9>] kernel_thread_helper+0x5/0xb
Nov 25 11:30:43 usul kernel: Code: 74 29 eb 51 83 f9 03 74 33 eb 4a 8b
04 24 89 fa e8 f8 fa ff ff 85 c0 75 f2 8b 47 08 8b 50
04 89 03 89 58 04 89 1a 89 53 04 eb 3f <8b> 47 08 8b 10 89 5a 04 89 13
89 43 04 89 18 eb 2e f6 42 08 10
Comment 6 Dams 2004-12-06 13:34:55 UTC 
*** Bug 141900 has been marked as a duplicate of this bug. ***
Comment 7 petrosyan 2004-12-22 06:50:36 UTC 
this bug has been fixed in kernel-2.6.9-1.715_FC3
you can grab it from
http://download.fedora.redhat.com/pub/fedora/linux/core/updates/testing/3/i386/
Comment 8 Dams 2004-12-22 08:17:32 UTC 
Fix confirmed. I've booted this kernel, plugged/unplugged my usb dvdrom device
and... i'm still alive to talk about it. Thanks.
Comment 9 petrosyan 2004-12-22 16:04:26 UTC 
kernel-2.6.9-1.715_FC3 turned out to be very unstable for me: it would crash
when logging out of GNOME. I upgraded to kernel-2.6.9-1.1048_FC4 and it is
working fine.
Comment 10 Stig Hackvan 2004-12-25 00:45:58 UTC 
Created attachment 109118 [details]
kernel oops & context (kernel 2.6.9-1.1032_FC4)

kernel 2.6.9-1.1032_FC4 mostly works but still fails to get along well with my
usb dvd writer...
Comment 11 Stig Hackvan 2004-12-28 23:24:36 UTC 
kernel-2.6.9-1.1048_FC4 has been working better with my lite-on dvd+rw drive
(usb), but locked up the scsi subsystem (cat /proc/scsi/scsi would hang) upon
the disconnect/reconnect of a sandisk 6-in-1 memory card reader.
Comment 12 Dave Jones 2005-04-22 03:36:52 UTC 
this should be fixed in both fc3 and rawhide now.
please reopen if it reoccurs.

thanks