* Re: [linux-usb-devel] 2.6: USB Storage hangs machine on bootup for ~2 minutes
2005-02-22 20:41 ` Alan Stern
@ 2005-02-22 22:49 ` Parag Warudkar
2005-02-23 15:51 ` Alan Stern
0 siblings, 1 reply; 4+ messages in thread
From: Parag Warudkar @ 2005-02-22 22:49 UTC (permalink / raw)
To: Alan Stern; +Cc: USB development list, linux-kernel
[-- Attachment #1: Type: text/plain, Size: 6370 bytes --]
On Tuesday 22 February 2005 03:41 pm, Alan Stern wrote:
> usb_device_read acquires a couple of locks, one for the USB bus list and
> one for the root hub of the bus it's looking at. I don't know which one
> occurs at offset 229 on your system -- maybe you can tell. Oddly enough,
> neither of those locks is for a USB device like the Maxtor drive. So it's
> not at all clear why plugging in the drive should mess up kudzu. Or why
> the blockage should clear up after a couple of minutes.
>
> Perhaps we can find out by looking at other entries in the stack trace.
> Of particular interest are the khubd, usb-storage, and scsi_eh processes.
Alan,
See below for stack traces and also note that the stack traces are after I
modified usb_device_read to do down_interruptible instead of down. (kudzu
gets stuck regardless though.) Let me know if you want me to revert the
down_interruptible change and repost the stack trace.
I wrongly related this to the 2 minute hang - this one is forever if I let
kudzu start during boot. If I run kudzu after boot is complete, it gets stuck
and everything else on that drive (mount, unmount ..) also gets stuck. Sorry
about the confusion.
Attached is the disassembly of usb_device_read from my machine.
Parag
SysRQ + T for relevant processes
======================
hald D 00000020e12be31a 0 2558 1 3272 2545
(NOTLB)
ffff81002c76fb48 0000000000000082 ffff81002c76fb28 ffffffff88515044
000000862c76fb08 ffff81002eb10800 0000000000000249 ffff810001c56030
ffff81002c76fc08 0000000000000002
Call Trace:
<ffffffff88515044>{:scsi_mod:scsi_request_fn+2356}
<ffffffff80385f0f>{io_schedule+15} <ffffffff801698d6>{sync_page+70}
<ffffffff80386295>{__wait_on_bit_lock+69}
<ffffffff80169890>{sync_page+0}
<ffffffff8016a1b7>{__lock_page+167}
<ffffffff8015c860>{wake_bit_function+0}
<ffffffff8015c860>{wake_bit_function+0}
<ffffffff8016aed4>{do_generic_mapping_read+660}
<ffffffff8016b1f0>{file_read_actor+0}
<ffffffff8016d1d4>{__generic_file_aio_read+420}
<ffffffff8016d39b>{generic_file_read+187}
<ffffffff8015c820>{autoremove_wake_function+0}
<ffffffff80186150>{do_brk+720} <ffffffff801998d1>{vfs_read+225}
<ffffffff80199bd0>{sys_read+80} <ffffffff8010ed1e>{system_call+126}
scsi_eh_2 D 00000000ffffffff 0 3581 1 3582 3277
(L-TLB)
ffff81002bdc1d88 0000000000000046 00000000000001e3 ffff81002bed8800
ffff81002bdc1d48 ffff81002c25a800 0000000000000812 ffffffff803df080
ffff81002bdc1ed0 ffff81002c25a800
Call Trace:
<ffffffff803846d5>{wait_for_completion+437}
<ffffffff80133e30>{default_wake_function+0}
<ffffffff80133e30>{default_wake_function+0}
<ffffffff88535be3>{:usb_storage:usb_stor_stop_transport+35}
<ffffffff88534250>{:usb_storage:command_abort+256}
<ffffffff88511f9c>{:scsi_mod:scsi_error_handler+2172}
<ffffffff8010f7ef>{child_rip+8}
<ffffffff88511720>{:scsi_mod:scsi_error_handler+0}
<ffffffff8010f7e7>{child_rip+0}
usb-storage D 00000000ffffffff 0 3582 1 3627 3581
(L-TLB)
ffff81002b8e1c08 0000000000000046 ffff81002b9e1000 0000000000000010
000000762b8e1c98 ffff81002bed8800 00000000000003dd ffff81002eb10800
00000000c0040280 000000000000001f
Call Trace:
<ffffffff803846d5>{wait_for_completion+437}
<ffffffff803843e1>{thread_return+253}
<ffffffff80133e30>{default_wake_function+0}
<ffffffff80133e30>{default_wake_function+0}
<ffffffff88535166>{:usb_storage:usb_stor_msg_common+550}
<ffffffff80120426>{dma_unmap_sg+134}
<ffffffff8853570f>{:usb_storage:usb_stor_bulk_transfer_buf+143}
<ffffffff88535f8b>{:usb_storage:usb_stor_Bulk_transport+203}
<ffffffff885358eb>{:usb_storage:usb_stor_invoke_transport+59}
<ffffffff88534dfb>{:usb_storage:usb_stor_transparent_scsi_command+27}
<ffffffff88536974>{:usb_storage:usb_stor_control_thread+756}
<ffffffff801337c3>{finish_task_switch+195}
<ffffffff8010f7ef>{child_rip+8}
<ffffffff88536680>{:usb_storage:usb_stor_control_thread+0}
<ffffffff8010f7e7>{child_rip+0}
scsi_eh_3 S 00000000ffffffff 0 3627 1 3634 3582
(L-TLB)
ffff81002bd47d68 0000000000000046 ffff81002bd47d28 ffffffff80219b32
000000742bc387c0 ffff81002bc387c0 0000000000000226 ffff81002b9fc030
ffff81002bd47d48 ffffffff80147ab1
Call Trace:
<ffffffff80219b32>{_atomic_dec_and_lock+290} <ffffffff80147ab1>{free_uid+33}
<ffffffff80383bd6>{__down_interruptible+486}
<ffffffff80133e30>{default_wake_function+0}
<ffffffff80386928>{__down_failed_interruptible+53}
<ffffffff88512a75>{:scsi_mod:.text.lock.scsi_error+45}
<ffffffff8010f7ef>{child_rip+8}
<ffffffff88511720>{:scsi_mod:scsi_error_handler+0}
<ffffffff8010f7e7>{child_rip+0}
usb-storage S 00000020f04e3d81 0 3634 1 3627
(L-TLB)
ffff81002bc53df8 0000000000000046 ffff81002bc53d80 0000000000001000
000000732b9eba7c ffff81002b9fc030 00000000000005ad ffff81002ebc9800
ffff81002bc53de8 ffffffff8853570f
Call Trace:
<ffffffff8853570f>{:usb_storage:usb_stor_bulk_transfer_buf+143}
<ffffffff80383bd6>{__down_interruptible+486}
<ffffffff80133e30>{default_wake_function+0}
<ffffffff80386928>{__down_failed_interruptible+53}
<ffffffff88537bb8>{:usb_storage:.text.lock.usb+5}
<ffffffff801337c3>{finish_task_switch+195}
<ffffffff8010f7ef>{child_rip+8}
<ffffffff88536680>{:usb_storage:usb_stor_control_thread+0}
<ffffffff8010f7e7>{child_rip+0}
khubd S 0000001ddd381da1 0 125 1 182 9
(L-TLB)
ffff810001ecbe18 0000000000000046 0000000000000246 ffff81002ba2c400
0000007401ecbdd8 ffff810001e9a800 0000000000003023 ffff81002bed8070
ffff810001ecbe18 ffffffff8015c4c9
Call Trace:
<ffffffff8015c4c9>{prepare_to_wait+345} <ffffffff802e0216>{hub_thread+4118}
<ffffffff8016f0cf>{free_pages_bulk+1007}
<ffffffff8015c820>{autoremove_wake_function+0}
<ffffffff8015c820>{autoremove_wake_function+0}
<ffffffff8010f7ef>{child_rip+8}
<ffffffff802df200>{hub_thread+0} <ffffffff8010f7e7>{child_rip+0}
[-- Attachment #2: usb_dv_rd.dis --]
[-- Type: text/plain, Size: 5873 bytes --]
0000000000000970 <usb_device_read>:
970: 55 push %rbp
971: 48 89 e5 mov %rsp,%rbp
974: 48 83 ec 60 sub $0x60,%rsp
978: 4c 89 75 f0 mov %r14,0xfffffffffffffff0(%rbp)
97c: 4c 89 7d f8 mov %r15,0xfffffffffffffff8(%rbp)
980: 45 31 ff xor %r15d,%r15d
983: 48 89 55 d0 mov %rdx,0xffffffffffffffd0(%rbp)
987: 48 89 5d d8 mov %rbx,0xffffffffffffffd8(%rbp)
98b: 49 89 ce mov %rcx,%r14
98e: 4c 89 65 e0 mov %r12,0xffffffffffffffe0(%rbp)
992: 4c 89 6d e8 mov %r13,0xffffffffffffffe8(%rbp)
996: 48 c7 c2 ea ff ff ff mov $0xffffffffffffffea,%rdx
99d: 48 89 75 c0 mov %rsi,0xffffffffffffffc0(%rbp)
9a1: 48 8b 01 mov (%rcx),%rax
9a4: 48 85 c0 test %rax,%rax
9a7: 48 89 45 c8 mov %rax,0xffffffffffffffc8(%rbp)
9ab: 0f 88 63 01 00 00 js b14 <usb_device_read+0x1a4>
9b1: 31 d2 xor %edx,%edx
9b3: 48 83 7d d0 00 cmpq $0x0,0xffffffffffffffd0(%rbp)
9b8: 0f 84 56 01 00 00 je b14 <usb_device_read+0x1a4>
9be: 48 89 f2 mov %rsi,%rdx
9c1: 65 48 8b 04 25 18 00 mov %gs:0x18,%rax
9c8: 00 00
9ca: 48 03 55 d0 add 0xffffffffffffffd0(%rbp),%rdx
9ce: 48 19 c9 sbb %rcx,%rcx
9d1: 48 39 90 48 e0 ff ff cmp %rdx,0xffffffffffffe048(%rax)
9d8: 48 83 d9 00 sbb $0x0,%rcx
9dc: 48 85 c9 test %rcx,%rcx
9df: 48 89 c8 mov %rcx,%rax
9e2: 48 c7 c2 f2 ff ff ff mov $0xfffffffffffffff2,%rdx
9e9: 0f 85 25 01 00 00 jne b14 <usb_device_read+0x1a4>
9ef: 48 c7 c6 00 00 00 00 mov $0x0,%rsi
9f6: 48 c7 c7 00 00 00 00 mov $0x0,%rdi
9fd: 49 c7 c5 00 00 00 00 mov $0x0,%r13
a04: e8 00 00 00 00 callq a09 <usb_device_read+0x99>
a09: be 84 00 00 00 mov $0x84,%esi
a0e: 48 c7 c7 00 00 00 00 mov $0x0,%rdi
a15: e8 00 00 00 00 callq a1a <usb_device_read+0xaa>
a1a: 4c 89 ef mov %r13,%rdi
a1d: ff 0d 00 00 00 00 decl 0(%rip) # a23 <usb_device_read+0xb3>
a23: 0f 88 c8 02 00 00 js cf1 <.text.lock.devices+0x14>
a29: 31 c0 xor %eax,%eax
a2b: 4c 63 e0 movslq %eax,%r12
a2e: 4d 85 e4 test %r12,%r12
a31: 4c 89 e2 mov %r12,%rdx
a34: 0f 85 da 00 00 00 jne b14 <usb_device_read+0x1a4>
a3a: eb 17 jmp a53 <usb_device_read+0xe3>
a3c: 4c 89 ef mov %r13,%rdi
a3f: ff 05 00 00 00 00 incl 0(%rip) # a45 <usb_device_read+0xd5>
a45: 0f 8e b0 02 00 00 jle cfb <.text.lock.devices+0x1e>
a4b: 4c 89 e2 mov %r12,%rdx
a4e: e9 c1 00 00 00 jmpq b14 <usb_device_read+0x1a4>
a53: 48 c7 c6 00 00 00 00 mov $0x0,%rsi
a5a: 48 c7 c7 00 00 00 00 mov $0x0,%rdi
a61: 31 c0 xor %eax,%eax
a63: e8 00 00 00 00 callq a68 <usb_device_read+0xf8>
a68: 48 8b 15 00 00 00 00 mov 0(%rip),%rdx # a6f <usb_device_read+0xff>
a6f: 48 8d 5a c0 lea 0xffffffffffffffc0(%rdx),%rbx
a73: 48 8b 43 40 mov 0x40(%rbx),%rax
a77: 0f 18 08 prefetcht0 (%rax)
a7a: 48 81 fa 00 00 00 00 cmp $0x0,%rdx
a81: 74 6a je aed <usb_device_read+0x17d>
a83: 48 8b 7b 38 mov 0x38(%rbx),%rdi
a87: 48 85 ff test %rdi,%rdi
a8a: 74 54 je ae0 <usb_device_read+0x170>
a8c: e8 00 00 00 00 callq a91 <usb_device_read+0x121>
a91: 4c 8b 43 38 mov 0x38(%rbx),%r8
a95: 48 8d 55 c8 lea 0xffffffffffffffc8(%rbp),%rdx
a99: 48 8d 75 d0 lea 0xffffffffffffffd0(%rbp),%rsi
a9d: 48 8d 7d c0 lea 0xffffffffffffffc0(%rbp),%rdi
aa1: 49 89 d9 mov %rbx,%r9
aa4: 4c 89 f1 mov %r14,%rcx
aa7: c7 44 24 10 00 00 00 movl $0x0,0x10(%rsp)
aae: 00
aaf: c7 44 24 08 00 00 00 movl $0x0,0x8(%rsp)
ab6: 00
ab7: c7 04 24 00 00 00 00 movl $0x0,(%rsp)
abe: e8 bd f5 ff ff callq 80 <usb_device_dump>
ac3: 48 8b 7b 38 mov 0x38(%rbx),%rdi
ac7: 49 89 c4 mov %rax,%r12
aca: e8 00 00 00 00 callq acf <usb_device_read+0x15f>
acf: 4d 85 e4 test %r12,%r12
ad2: 0f 88 64 ff ff ff js a3c <usb_device_read+0xcc>
ad8: 4d 01 e7 add %r12,%r15
adb: 66 data16
adc: 66 data16
add: 90 nop
ade: 66 data16
adf: 90 nop
ae0: 48 8b 53 40 mov 0x40(%rbx),%rdx
ae4: 48 8d 42 c0 lea 0xffffffffffffffc0(%rdx),%rax
ae8: 48 89 c3 mov %rax,%rbx
aeb: eb 86 jmp a73 <usb_device_read+0x103>
aed: 4c 89 ef mov %r13,%rdi
af0: ff 05 00 00 00 00 incl 0(%rip) # af6 <usb_device_read+0x186>
af6: 0f 8e 09 02 00 00 jle d05 <.text.lock.devices+0x28>
afc: 48 c7 c6 00 00 00 00 mov $0x0,%rsi
b03: 48 c7 c7 00 00 00 00 mov $0x0,%rdi
b0a: 31 c0 xor %eax,%eax
b0c: e8 00 00 00 00 callq b11 <usb_device_read+0x1a1>
b11: 4c 89 fa mov %r15,%rdx
b14: 48 8b 5d d8 mov 0xffffffffffffffd8(%rbp),%rbx
b18: 4c 8b 65 e0 mov 0xffffffffffffffe0(%rbp),%r12
b1c: 48 89 d0 mov %rdx,%rax
b1f: 4c 8b 6d e8 mov 0xffffffffffffffe8(%rbp),%r13
b23: 4c 8b 75 f0 mov 0xfffffffffffffff0(%rbp),%r14
b27: 4c 8b 7d f8 mov 0xfffffffffffffff8(%rbp),%r15
b2b: c9 leaveq
b2c: c3 retq
b2d: 66 data16
b2e: 66 data16
b2f: 90 nop
^ permalink raw reply [flat|nested] 4+ messages in thread