Opened 16 years ago
Closed 16 years ago
#2535 closed bug (fixed)
Deadlock discovered: usb explore (legacy mutex) - sh (devfs mutex)
| Reported by: | emitrax | Owned by: | axeld |
|---|---|---|---|
| Priority: | high | Milestone: | R1/alpha1 |
| Component: | System/Kernel | Version: | R1/pre-alpha1 |
| Keywords: | Cc: | ||
| Blocked By: | Blocking: | ||
| Platform: | All |
Description
Since I don't know which lock should be held first (there should be an order) I'll leave it to someone else.
kdebug> thread 738
THREAD: 0x914de000
id: 738 (0x2e2)
name: "sh"
all_next: 0x9149d800
team_next: 0x00000000
q_next: 0x913c4800
priority: 10 (next 10)
state: waiting
next_state: waiting
cpu: 0x00000000
sig_pending: 0x0 (blocked: 0x0)
in_kernel: 1
waiting for: mutex 0x8010129c
fault_handler: 0x00000000
args: 0x90d1c4b0 0x00000000
entry: 0x800458ac
team: 0x90cc42e8, "sh"
exit.sem: 8263
exit.status: 0x0 (No error)
exit.reason: 0x0
exit.signal: 0x0
exit.waiters:
kernel_stack_area: 15626
kernel_stack_base: 0x90b11000
user_stack_area: 15628
user_stack_base: 0x7efef000
user_local_storage: 0x7ffef000
kernel_errno: 0x0 (No error)
kernel_time: 10903338
user_time: 3868782
flags: 0x0
architecture dependant section:
esp: 0x90b149a8
ss: 0x00000010
fpu_state at 0x914de380
kdebug> mutex 0x8010129c
mutex 0x8010129c:
name: legacy driver
flags: 0x0
holder: 25
waiting threads: 738
kdebug> thread 25
THREAD: 0x913c3800
id: 25 (0x19)
name: "usb explore"
all_next: 0x00000000
team_next: 0x913c3000
q_next: 0x800f79c0
priority: 5 (next 5)
state: waiting
next_state: waiting
cpu: 0x00000000
sig_pending: 0x0 (blocked: 0x0)
in_kernel: 1
waiting for: mutex 0x90b7d9b8
fault_handler: 0x00000000
args: 0x90b6d500 0x00000000
entry: 0x80700858
team: 0x90b7b000, "kernel_team"
exit.sem: 100
exit.status: 0x0 (No error)
exit.reason: 0x0
exit.signal: 0x0
exit.waiters:
kernel_stack_area: 115
kernel_stack_base: 0x8016e000
user_stack_area: -1
user_stack_base: 0x00000000
user_local_storage: 0x00000000
kernel_errno: 0x0 (No error)
kernel_time: 452272
user_time: 0
flags: 0x0
architecture dependant section:
esp: 0x80171cbc
ss: 0x00000010
fpu_state at 0x913c3b80
kdebug> mutex 0x90b7d9b8
mutex 0x90b7d9b8:
name: devfs lock
flags: 0x0
holder: 738
waiting threads: 25 2786 2820 2825
Change History (4)
comment:1 by , 16 years ago
comment:2 by , 16 years ago
Honestly I don't remember. Perhaps it was while unpacking a tarball. I'm sorry, but I totally forgot to get a stack trace of the threads.
comment:3 by , 16 years ago
| Component: | - General → System/Kernel |
|---|---|
| Milestone: | R1 → R1/alpha1 |
| Priority: | normal → high |
Just ran into the same problem (unplugging/replugging my USB keyboard). This is a locking order reversal issue between the devfs lock and the legacy driver lock.
thread -s 12828
thread id state wait for object cpu pri stack team name
0x818ea000 12828 waiting mutex 0x8012cf44 - 104 0x8a7b8000 95 USB Keyboard 1 watcher
kdebug> mutex 0x8012cf44
mutex 0x8012cf44:
name: legacy driver
flags: 0x0
holder: 39
waiting threads: 12828
kdebug> thread -s 39
thread id state wait for object cpu pri stack team name
0x817f0000 39 waiting mutex 0x80f875f8 - 5 0x802bf000 1 usb explore
kdebug> mutex 0x80f875f8
mutex 0x80f875f8:
name: devfs lock
flags: 0x0
holder: 12828
waiting threads: 39 241146 241158
kdebug> sc 12828
stack trace for thread 12828 "USB Keyboard 1 watcher"
kernel stack: 0x8a7b8000 to 0x8a7bc000
user stack: 0x70104000 to 0x70144000
frame caller <image>:function + offset
0 8a7bbd24 (+ 48) 80059c28 <kernel_x86> context_switch(thread*: 0x818ea000, thread*: 0x817f0000) + 0x003c
1 8a7bbd54 (+ 64) 80059f0f <kernel_x86> simple_reschedule() + 0x029f
2 8a7bbd94 (+ 48) 8003e421 <kernel_x86>:_mutex_lock + 0x01b1
3 8a7bbdc4 (+ 48) 8003d42b <kernel_x86>:recursive_lock_lock + 0x0053
4 8a7bbdf4 (+ 48) 80075374 <kernel_x86> LegacyDevice<0x81199460>::UninitDevice(0x0, 0x8a7bbe54, 0x835b805c) + 0x0028
5 8a7bbe24 (+ 64) 8006e021 <kernel_x86> devfs_free_cookie(fs_volume*: 0x80f77284, fs_vnode*: 0x81269cc0, 0x8101ebd0) + 0x0071
6 8a7bbe64 (+ 48) 8009be42 <kernel_x86> file_free_fd(file_descriptor*: 0x812bbd48) + 0x002e
7 8a7bbe94 (+ 48) 8008a7d0 <kernel_x86>:put_fd + 0x0038
8 8a7bbec4 (+ 64) 8008a8ba <kernel_x86>:close_fd_index + 0x0032
9 8a7bbf04 (+ 32) 8008b3b5 <kernel_x86> common_close(int32: 12, false) + 0x0031
10 8a7bbf24 (+ 32) 8008bc8c <kernel_x86>:_user_close + 0x0018
11 8a7bbf44 (+ 100) 800d2491 <kernel_x86>:handle_syscall + 0x00be
user iframe at 0x8a7bbfa8 (end = 0x8a7bc000)
eax 0x8a ebx 0x573240 ecx 0x5bb800 edx 0x1800fc30
esi 0x18060f80 edi 0x4 ebp 0x70143d2c esp 0x8a7bbfdc
eip 0xffff0102 eflags 0x203 user esp 0x70143d00
vector: 0x63, error code: 0x0
12 8a7bbfa8 (+ 0) ffff0102 <commpage>:commpage_syscall + 0x0002
13 70143d2c (+ 48) 005b3929 <keyboard> KeyboardDevice<0x18060f80>::Stop(0x1, 0x5b4a3c70143d9c, 0x22cf5c, 0x18060f80, int32: 402717744, int8: 125, 0x0, 0x18060ec0) + 0x002d
14 70143d5c (+ 48) 005b4a4f <keyboard> KeyboardInputDevice<0x1800fc30>::Stop(0x1806b428 "USB Keyboard 1", 0x18060f80) + 0x001f
15 70143d8c (+ 48) 00211fc3 <_APP_> InputDeviceListItem<0x18060ec0>::Stop(0x1806b440, 0x1802c420, 0x21549a) + 0x0033
16 70143dbc (+ 80) 00215544 <_APP_> InputServer<0x1802c420>::UnregisterDevices(BInputServerDevice&: 0x1800fc30, input_device_ref*: 0x70143e74) + 0x00b8
17 70143e0c (+ 48) 00217b18 <_APP_> BInputServerDevice<0x1800fc30>::UnregisterDevices(input_device_ref*: 0x70143e74) + 0x002c
18 70143e3c (+ 64) 005b4d14 <keyboard> KeyboardInputDevice<0x1800fc30>::_RemoveDevice(0x18060fc0 "/dev/input/keyboard/usb/0") + 0x0048
19 70143e7c (+ 256) 005b3c93 <keyboard> KeyboardDevice<0x18060f80>::_Thread(0x0, 0x0, 0x5b3bd8, 0x573240) + 0x009f
20 70143f7c (+ 48) 005b3beb <keyboard> KeyboardDevice<0x18060f80>::_ThreadEntry(NULL) + 0x001f
21 70143fac (+ 48) 004e697c <libroot.so>:_get_next_team_info (nearest) + 0x005c
22 70143fdc (+ 0) 70143fec 259800:USB Keyboard 1 watcher_12828_st@0x70104000 + 0x3ffec
kdebug> sc 39
stack trace for thread 39 "usb explore"
kernel stack: 0x802bf000 to 0x802c3000
frame caller <image>:function + offset
0 802c2cf8 (+ 48) 80059c28 <kernel_x86> context_switch(thread*: 0x817f0000, thread*: 0x80123870) + 0x003c
1 802c2d28 (+ 64) 80059f0f <kernel_x86> simple_reschedule() + 0x029f
2 802c2d68 (+ 48) 8003e421 <kernel_x86>:_mutex_lock + 0x01b1
3 802c2d98 (+ 48) 8003d42b <kernel_x86>:recursive_lock_lock + 0x0053
4 802c2dc8 (+ 48) 8006da48 <kernel_x86> devfs_get_vnode(fs_volume*: 0x80f77284, int64: 212, fs_vnode*: 0xbbf33e14, 0x802c2e3c, 0x802c2e40, true) + 0x0028
5 802c2df8 (+ 80) 800954a8 <kernel_x86> get_vnode(int32: 2, int64: 212, vnode*: 0x802c2e94, true, int32: 1) + 0x0168
6 802c2e48 (+ 80) 80099023 <kernel_x86>:get_vnode + 0x003f
7 802c2e98 (+ 48) 8006f50b <kernel_x86> devfs_unpublish_device(BaseDevice*: 0x811993f0, true) + 0x0023
8 802c2ec8 (+ 80) 80073095 <kernel_x86> republish_driver(legacy_driver*: 0x810b4d20) + 0x02ed
9 802c2f18 (+ 48) 80075721 <kernel_x86>:legacy_driver_rescan + 0x0075
10 802c2f48 (+ 32) 8006f592 <kernel_x86>:devfs_rescan_driver + 0x0012
11 802c2f68 (+ 48) 80748f73 <usb> Stack<0x80f99690>::RescanDrivers(rescan_item*: 0x8101eb68) + 0x001b
12 802c2f98 (+ 64) 80748d07 <usb> Stack<0x80f99690>::ExploreThread(NULL) + 0x0107
13 802c2fd8 (+ 32) 800532ab <kernel_x86> _create_kernel_thread_kentry() + 0x001b
14 802c2ff8 (+2144587784) 80053248 <kernel_x86> thread_kthread_exit() + 0x0000
Note:
See TracTickets
for help on using tickets.
Do you have any directions on how to reproduce that? What was the shell up to when this happened (stack traces would be helpful)?