Re: [linux-usb-devel] Fw: [BUG] USB Storage OOPS and a D state process in 2.6.10

[Srihari Vijayaraghavan <harisri@internode.on.net>]

[-- Attachment #1: Type: text/plain, Size: 5906 bytes --]

On Saturday 08 January 2005 11:43, Srihari Vijayaraghavan wrote:
> ...
> 1. While it is still easy to trigger this bug without USB Storage Debug
> Option in vanilla 2.6.10, I cannot reproduce the bug with debug option.
> Perhaps it changes some timings.

(Am sorry for replying to my own email.)
Though I could not trigger an OOPS with debug option yet, I have managed to 
trigger a D state "hald" process:

Jan  8 12:41:45 desktop kernel: hald          D 000001003fb24478     0  3369      
1          4163  3006 (NOTLB)
Jan  8 12:41:45 desktop kernel: 00000100374bb9b8 0000000000000006 
000000732d933078 000001003fb241f0
Jan  8 12:41:45 desktop kernel:        00000000000b08ff 00000100371bc170 
0000010037d71440 000001002e0db800
Jan  8 12:41:45 desktop kernel:        000001002d933078 00000100374bba58
Jan  8 12:41:45 desktop kernel: Call 
Trace:<ffffffff802c11eb>{wait_for_completion+139} 
<ffffffff8012dc20>{default_wake_function+0}
Jan  8 12:41:45 desktop kernel:        
<ffffffff8012dc20>{default_wake_function+0} 
<ffffffffa0004f7b>{:scsi_mod:scsi_wait_req+91}
Jan  8 12:41:45 desktop kernel:        
<ffffffffa0000038>{:scsi_mod:scsi_allocate_request+56}
Jan  8 12:41:45 desktop kernel:        <ffffffffa023e99a>{:sr_mod:sr_open+234} 
<ffffffff80110000>{do_stack_segment+128}
Jan  8 12:41:45 desktop kernel:        <ffffffff80240000>{cdrom_open+2080} 
<ffffffff8026cbfc>{alloc_skb+108}
Jan  8 12:41:45 desktop kernel:        
<ffffffff8026b4e1>{sock_alloc_send_pskb+113} 
<ffffffff8026e747>{memcpy_toiovec+55}
Jan  8 12:41:45 desktop kernel:        
<ffffffff8015f119>{find_mergeable_anon_vma+137} 
<ffffffff801af4ba>{avc_has_perm+90}
Jan  8 12:41:45 desktop kernel:        <ffffffff801af4ba>{avc_has_perm+90} 
<ffffffff801af4ba>{avc_has_perm+90}
Jan  8 12:41:45 desktop kernel:        
<ffffffff801b02b4>{task_has_capability+100} 
<ffffffff801c2992>{kobject_get+18}
Jan  8 12:41:45 desktop kernel:        <ffffffff8021e61c>{get_disk+44} 
<ffffffff801c2992>{kobject_get+18}
Jan  8 12:41:45 desktop kernel:        
<ffffffffa023e730>{:sr_mod:sr_block_open+176} <ffffffff8017286a>{do_open+170}
Jan  8 12:41:45 desktop kernel:        <ffffffff80172c5f>{blkdev_open+47} 
<ffffffff8016aa36>{dentry_open+230}
Jan  8 12:41:45 desktop kernel:        <ffffffff8016ab7e>{filp_open+62} 
<ffffffff8016abc7>{get_unused_fd+55}
Jan  8 12:41:45 desktop kernel:        <ffffffff8016ad4c>{sys_open+76} 
<ffffffff8010e1da>{system_call+126}
Jan  8 12:41:45 desktop kernel:


This (kernel badness in scsi_lib.c:1717) I have it in the system logs just 
before the process went in to D state:

Jan  8 12:34:00 desktop kernel: ehci_hcd 0000:00:10.4: port 5 reset error -110
Jan  8 12:34:00 desktop kernel: hub 1-0:1.0: hub_port_status failed (err = 
-32)
Jan  8 12:34:00 desktop kernel: usb 1-5: new high speed USB device using 
ehci_hcd and address 9
Jan  8 12:34:00 desktop kernel: scsi9 : SCSI emulation for USB Mass Storage 
devices
Jan  8 12:34:05 desktop kernel:   Vendor: PIONEER   Model: DVD-RW  DVR-107D  
Rev: 1.13
Jan  8 12:34:05 desktop kernel:   Type:   CD-ROM                             
ANSI SCSI revision: 00
Jan  8 12:34:05 desktop kernel: sr1: scsi3-mmc drive: 40x/40x writer cd/rw 
xa/form2 cdda tray
Jan  8 12:34:05 desktop scsi.agent[6565]: cdrom 
at /devices/pci0000:00/0000:00:10.4/usb1/1-5/1-5:1.0/host9/target9:0:0/9:0:0:0
Jan  8 12:34:06 desktop kernel: usb 1-5: USB disconnect, address 9
Jan  8 12:34:36 desktop kernel: scsi: Device offlined - not ready after error 
recovery: host 9 channel 0 id 0 lun 0
Jan  8 12:34:36 desktop kernel:  9:0:0:0: Illegal state transition 
deleted->offline
Jan  8 12:34:36 desktop kernel: Badness in scsi_device_set_state at 
drivers/scsi/scsi_lib.c:1717
Jan  8 12:34:36 desktop kernel:
Jan  8 12:34:36 desktop kernel: Call 
Trace:<ffffffffa0006808>{:scsi_mod:scsi_device_set_state+264}
Jan  8 12:34:36 desktop kernel:        
<ffffffffa000481c>{:scsi_mod:scsi_error_handler+2732}
Jan  8 12:34:36 desktop kernel:        <ffffffff8010ebf3>{child_rip+8} 
<ffffffffa0003d70>{:scsi_mod:scsi_error_handler+0}
Jan  8 12:34:36 desktop kernel:        <ffffffff8010ebeb>{child_rip+0}
Jan  8 12:35:10 desktop kernel: ehci_hcd 0000:00:10.4: port 5 reset error -110
Jan  8 12:35:10 desktop kernel: hub 1-0:1.0: hub_port_status failed (err = 
-32)
Jan  8 12:35:10 desktop kernel: ehci_hcd 0000:00:10.4: port 5 reset error -110
Jan  8 12:35:10 desktop kernel: hub 1-0:1.0: hub_port_status failed (err = 
-32)
Jan  8 12:35:11 desktop kernel: usb 1-5: new high speed USB device using 
ehci_hcd and address 10
Jan  8 12:35:11 desktop kernel: ehci_hcd 0000:00:10.4: port 5 reset error -110
Jan  8 12:35:11 desktop kernel: hub 1-0:1.0: hub_port_status failed (err = 
-32)
Jan  8 12:35:11 desktop kernel: scsi10 : SCSI emulation for USB Mass Storage 
devices
Jan  8 12:35:15 desktop kernel: usb 1-5: USB disconnect, address 10
Jan  8 12:35:28 desktop kernel: usb 1-5: new high speed USB device using 
ehci_hcd and address 11
Jan  8 12:35:28 desktop kernel: ehci_hcd 0000:00:10.4: port 5 reset error -110
Jan  8 12:35:28 desktop kernel: hub 1-0:1.0: hub_port_status failed (err = 
-32)
Jan  8 12:35:28 desktop kernel: ehci_hcd 0000:00:10.4: port 5 reset error -110
Jan  8 12:35:28 desktop kernel: hub 1-0:1.0: hub_port_status failed (err = 
-32)
Jan  8 12:35:29 desktop kernel: scsi11 : SCSI emulation for USB Mass Storage 
devices
Jan  8 12:35:34 desktop kernel:   Vendor: PIONEER   Model: DVD-RW  DVR-107D  
Rev: 1.13
Jan  8 12:35:34 desktop kernel:   Type:   CD-ROM                             
ANSI SCSI revision: 00
Jan  8 12:35:34 desktop kernel: sr2: scsi3-mmc drive: 40x/40x writer cd/rw 
xa/form2 cdda tray
Jan  8 12:35:36 desktop kernel: usb 1-5: USB disconnect, address 11


The complete copy of system logs is attached to this email.

I think I have seen this "Badness in scsi_lib.c:1717" in 2.6.10 before (even 
without USB Storage Debug option that is).

Thanks.
Hari

[-- Attachment #2: dmesg-2.6.10-1.bz2 --]
[-- Type: application/x-bzip2, Size: 20270 bytes --]