KDL when using multiple serial devices

[pulkomandy]

I have two USB serial devices connected to my machine. If I open one in SerialConnect, and then try to open the other (from the same instance of SerialConnect, so I think a quick close-then-open sequence will happen) I get the following KDL (it's continuable):

KERN: PANIC: _mutex_lock(): double lock of 0xd97f92b4 by thread 17774
KERN: Welcome to Kernel Debugging Land...
KERN: Thread 17774 "SerialConnect" running on CPU 2
KERN: stack trace for thread 17774 "SerialConnect"
KERN:     kernel stack: 0x82755000 to 0x82759000
KERN:       user stack: 0x70e02000 to 0x71e02000
KERN: frame               caller     <image>:function + offset
KERN:  0 82758708 (+  32) 8014bcaa   <kernel_x86> arch_debug_stack_trace + 0x12
KERN:  1 82758728 (+  16) 800a8233   <kernel_x86> stack_trace_trampoline(NULL) + 0x0b
KERN:  2 82758738 (+  12) 8013d796   <kernel_x86> arch_debug_call_with_fault_handler + 0x1b
KERN:  3 82758744 (+  48) 800a9cbc   <kernel_x86> debug_call_with_fault_handler + 0x60
KERN:  4 82758774 (+  64) 800a8447   <kernel_x86> kernel_debugger_loop(0x8018fbd7 "PANIC: ", 0x8018aa60 "_mutex_lock(): double lock of %p by thread %ld", 0x82758820 "E", int32: 2) + 0x20f
KERN:  5 827587b4 (+  48) 800a87eb   <kernel_x86> kernel_debugger_internal(0x8018fbd7 "PANIC: ", 0x8018aa60 "_mutex_lock(): double lock of %p by thread %ld", 0x82758820 "E", int32: 2) + 0x77
KERN:  6 827587e4 (+  48) 800aa03e   <kernel_x86> panic + 0x3a
KERN:  7 82758814 (+  80) 800962d6   <kernel_x86> _mutex_lock + 0xea
KERN:  8 82758864 (+ 224) 827c9e49   </boot/system/add-ons/kernel/generic/tty> tty_control(tty_cookie*: 0xd90567c0, uint32: 0x8001 (32769), 0x82758984, uint32: 0x20 (32)) + 0xd1
KERN:  9 82758944 (+  96) 82740c94   </boot/system/add-ons/kernel/drivers/dev/ports/usb_serial> SerialDevice<0xd628fcc0>::SetModes(termios*: 0xd97b0988) + 0x224
KERN: 10 827589a4 (+  64) 82740f77   </boot/system/add-ons/kernel/drivers/dev/ports/usb_serial> SerialDevice<0xd628fcc0>::Service(tty*: 0xd97b0960, uint32: 0x1 (1), 0xd97b0988, uint32: 0x20 (32)) + 0x1ef
KERN: 11 827589e4 (+  64) 82740108   </boot/system/add-ons/kernel/drivers/dev/ports/usb_serial> usb_serial_service + 0x78
KERN: 12 82758a24 (+ 224) 827ca06e   </boot/system/add-ons/kernel/generic/tty> tty_control(tty_cookie*: 0xd8e2dce0, uint32: 0x8001 (32769), 0x82758b44, uint32: 0x20 (32)) + 0x2f6
KERN: 13 82758b04 (+  96) 82740c94   </boot/system/add-ons/kernel/drivers/dev/ports/usb_serial> SerialDevice<0xd60cbd98>::SetModes(termios*: 0xd97f92d0) + 0x224
KERN: 14 82758b64 (+  64) 82740f77   </boot/system/add-ons/kernel/drivers/dev/ports/usb_serial> SerialDevice<0xd60cbd98>::Service(tty*: 0xd97f92a8, uint32: 0x1 (1), 0xd97f92d0, uint32: 0x20 (32)) + 0x1ef
KERN: 15 82758ba4 (+  64) 82740108   </boot/system/add-ons/kernel/drivers/dev/ports/usb_serial> usb_serial_service + 0x78
KERN: 16 82758be4 (+ 224) 827ca06e   </boot/system/add-ons/kernel/generic/tty> tty_control(tty_cookie*: 0xd90567c0, uint32: 0x8001 (32769), 0xd60cbe14, uint32: 0x20 (32)) + 0x2f6
KERN: 17 82758cc4 (+  48) 8274124a   </boot/system/add-ons/kernel/drivers/dev/ports/usb_serial> SerialDevice<0xd60cbd98>::Open(uint32: 0x182 (386)) + 0x25a
KERN: 18 82758cf4 (+  48) 82740219   </boot/system/add-ons/kernel/drivers/dev/ports/usb_serial> usb_serial_open(0x82758d94 "ports/usb0", uint32: 0x182 (386), 0xd97b26a0) + 0xb1
KERN: 19 82758d24 (+  48) 800c8b94   <kernel_x86> _GLOBAL_.N..._.._haiku_src_system_kernel_device_manager_legacy_drivers.cppcTiTnb::LegacyDevice<0xd321adc0>::Open(0x82758d94 "ports/usb0", int32: 386, 0xd97b26a0) + 0x20
KERN: 20 82758d54 (+ 320) 800c32c9   <kernel_x86> devfs_open(fs_volume*: 0x82ac5960, fs_vnode*: 0xd9004090, int32: 386, 0x82758ec0) + 0x9d
KERN: 21 82758e94 (+  48) 800faab1   <kernel_x86> open_vnode(vnode*: 0xd9004090, int32: 386, false) + 0x29
KERN: 22 82758ec4 (+  64) 800fb369   <kernel_x86> file_open(int32: -1, 0xdf071e88 "/dev", int32: 386, false) + 0x91
KERN: 23 82758f04 (+  64) 8010118f   <kernel_x86> _user_open + 0xab
KERN: 24 82758f44 (+ 100) 8014028f   <kernel_x86> handle_syscall + 0xdc
KERN: user iframe at 0x82758fa8 (end = 0x82759000)
KERN:  eax 0x6b          ebx 0x241d5ac      ecx 0x71e0131c  edx 0x61d62114
KERN:  esi 0x71e01378    edi 0x71e0198c     ebp 0x71e01348  esp 0x82758fdc
KERN:  eip 0x61d62114 eflags 0x3202    user esp 0x71e0131c
KERN:  vector: 0x63, error code: 0x0
KERN: 25 82758fa8 (+   0) 61d62114   <commpage> commpage_syscall + 0x04
KERN: 26 71e01348 (+ 112) 0141d4ee   <libdevice.so> BSerialPort<0x71e0198c>::Open(0x321988 "usb0") + 0x72
KERN: 27 71e013b8 (+ 432) 0103d975   <_APP_> SerialApp<0x71e01884>::MessageReceived(BMessage*: 0xde08e0) + 0xc9
KERN: 28 71e01568 (+  48) 0164c543   <libbe.so> BLooper<0x71e01884>::DispatchMessage(BMessage*: 0xde08e0, BHandler*: 0x71e01884) + 0x5b
KERN: 29 71e01598 (+ 512) 01641c5d   <libbe.so> BApplication<0x71e01884>::DispatchMessage(BMessage*: 0xde08e0, BHandler*: 0x71e01884) + 0x4e9
KERN: 30 71e01798 (+  64) 0164de35   <libbe.so> BLooper<0x71e01884>::task_looper() + 0x205
KERN: 31 71e017d8 (+  64) 0164c98d   <libbe.so> BLooper<0x71e01884>::Loop() + 0x65
KERN: 32 71e01818 (+  48) 016405d6   <libbe.so> BApplication<0x71e01884>::Run() + 0x2a
KERN: 33 71e01848 (+ 400) 0103f183   <_APP_> main + 0x2f
KERN: 34 71e019d8 (+  48) 0103ca6b   <_APP_> _start + 0x5b
KERN: 35 71e01a08 (+  64) 01cc17b4   </boot/system/runtime_loader@0x01caf000> <unknown> + 0x127b4
KERN: 36 71e01a48 (+   0) 61d62258   <commpage> commpage_thread_exit + 0x00

Apparently open calls usb_serial_service which eventually recurses, first with a different cookie but then with the same as the first call. So of course we end up with a recursive locking situation.

If I understand tty locking correctly, calling tty->service_func should indeed be done with the lock held, as it accesses the tty settings. It looks strange that the tty implementation of the serial device (usb_serial_service) always operates on all serial devices? I would expect it to work on the currently open one, but then again that's the work of usb_serial_control, so maybe _service is indeed supposed to be global?

[korli]

I see that usb_serial_service() calls Service() on every device, and Service() checks the given tty. Maybe try to check fDeviceOpen in Service(). Maybe also reset fMasterTTY in SerialDevice::Close().

[pulkomandy]

Yes, that fixes it, thanks! Somewhat AFK today but I'll submit the patch later.

[pulkomandy]

​https://review.haiku-os.org/c/haiku/+/1551

[waddlesplash]

Merged in hrev53225.

[nielx]

Assign tickets with status=closed and resolution=fixed within the R1/beta2 development window to the R1/beta2 Milestone