Opened 11 years ago

Closed 11 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:
Has a Patch: no 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 Changed 11 years ago by mmlr

Do you have any directions on how to reproduce that? What was the shell up to when this happened (stack traces would be helpful)?

comment:2 Changed 11 years ago by emitrax

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 Changed 11 years ago by bonefish

Component: - GeneralSystem/Kernel
Milestone: R1R1/alpha1
Priority: normalhigh

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

comment:4 Changed 11 years ago by axeld

Resolution: fixed
Status: newclosed

Fixed in hrev28551.

Note: See TracTickets for help on using tickets.