Opened 10 years ago

Last modified 11 months ago

#11079 new bug

"PANIC: _mutex_lock(): double lock" on medium error on audio CD

Reported by: mmu_man Owned by: nobody
Priority: normal Milestone: R1
Component: Drivers/Disk Version: R1/Development
Keywords: Cc:
Blocked By: Blocking:
Platform: All

Description

I just tried using an audio CD from inside VirtualBox, and it currently panics after a lot of check sense errors.

It seems the CD driver ends up calling periph_media_changed_public() which tries to acquire the mutex, when trying to read from the drive from its set_capacity callback called from periph_check_capacity(). The callback is called with the mutex held...

I'm wondering about making the mutex a recursive_lock...

Syslog:

atapi 1-0 error: device indicates transfer error after dma
ata 1 error: device still expects data transfer
check_sense: Medium error
atapi 1-0 error: device indicates transfer error after dma
ata 1 error: device still expects data transfer
check_sense: Medium error
atapi 1-0 error: device indicates transfer error after dma
ata 1 error: device still expects data transfer
check_sense: Medium error
atapi 1-0 error: device indicates transfer error after dma
ata 1 error: device still expects data transfer
check_sense: Medium error
atapi 1-0 error: device indicates transfer error after dma
ata 1 error: device still expects data transfer
check_sense: Medium error
ata 1 error: timeout waiting for interrupt
ata 1 error: RecoverLostInterrupt: lost interrupt, status 0x41
atapi 1-0 error: device indicates transfer error after dma
PANIC: _mutex_lock(): double lock of 0x82b2ff00 by thread 143
Welcome to Kernel Debugging Land...
Thread 143 "media checker" running on CPU 0
stack trace for thread 143 "media checker"
    kernel stack: 0x81a09000 to 0x81a0d000
frame               caller     <image>:function + offset
 0 81a0c448 (+  32) 80142282   <kernel_x86> arch_debug_stack_trace + 0x12
 1 81a0c468 (+  16) 800a219f   <kernel_x86> stack_trace_trampoline(NULL) + 0x0b
 2 81a0c478 (+  12) 80133fbe   <kernel_x86> arch_debug_call_with_fault_handler + 0x1b
 3 81a0c484 (+  48) 800a3d0a   <kernel_x86> debug_call_with_fault_handler + 0x5a
 4 81a0c4b4 (+  64) 800a23bb   <kernel_x86> kernel_debugger_loop(0x80185bd7 "PANIC: ", 0x80180c80 "_mutex_lock(): double lock of %p by thread %ld", 0x81a0c560 "", int32: 0) + 0x217
 5 81a0c4f4 (+  48) 800a2737   <kernel_x86> kernel_debugger_internal(0x80185bd7 "PANIC: ", 0x80180c80 "_mutex_lock(): double lock of %p by thread %ld", 0x81a0c560 "", int32: 0) + 0x53
 6 81a0c524 (+  48) 800a4092   <kernel_x86> panic + 0x3a
 7 81a0c554 (+  64) 80090948   <kernel_x86> _mutex_lock + 0xe8
 8 81a0c594 (+  48) 819e4309   <scsi_periph> periph_media_changed_public(scsi_periph_device_info*: 0x82b2fed8) + 0x25
 9 81a0c5c4 (+ 112) 819e421d   <scsi_periph> periph_media_changed(scsi_periph_device_info*: 0x82b2fed8, scsi_ccb*: 0x8274fd9c) + 0x4d
10 81a0c634 (+  48) 819e2cd5   <scsi_periph> check_sense(scsi_periph_device_info*: 0x81a0c71c, scsi_ccb*: 0x82b2fed8) + 0x1b1
11 81a0c664 (+  48) 819e3236   <scsi_periph> check_scsi_status(scsi_periph_device_info*: 0x81a0c71c, scsi_ccb*: 0x82b2fed8) + 0xfa
12 81a0c694 (+  48) 819e34b6   <scsi_periph> periph_check_error(scsi_periph_device_info*: 0x81a0c71c, scsi_ccb*: 0x82b2fed8) + 0x226
13 81a0c6c4 (+  96) 819e3d4b   <scsi_periph> read_write(scsi_periph_device_info*: 0x82b2fed8, scsi_ccb*: 0x8274fd9c, IOOperation*: NULL, uint64: 0x7ffd3 (524243), uint32: 0x2 (2), physical_entry*: 0x81a0c804, uint32: 0x2 (2), false, 0x81a0c7f4) + 0x327
14 81a0c724 (+  80) 819e40c3   <scsi_periph> periph_read_write(scsi_periph_device_info*: 0x82b2fed8, scsi_ccb*: 0x8274fd9c, uint64: 0x7ffd3 (524243), uint32: 0x2 (2), physical_entry*: 0x81a0c804, uint32: 0x2 (2), false, 0x81a0c7f4) + 0x47
15 81a0c774 (+ 208) 81a2f38c   <scsi_cd> test_capacity(cd_driver_info*: 0x82a64ae0) + 0x194
16 81a0c844 (+  64) 81a308ab   <scsi_cd> cd_set_capacity(cd_driver_info*: 0x82a64ae0, uint64: 0x7ffff (524287), uint32: 0x800 (2048)) + 0x1db
17 81a0c884 (+  80) 819e267f   <scsi_periph> periph_check_capacity(scsi_periph_device_info*: 0x82b2fed8, scsi_ccb*: 0x8274f6d4) + 0x1d3
18 81a0c8d4 (+  48) 81a30951   <scsi_cd> cd_media_changed(cd_driver_info*: 0x82a64ae0, scsi_ccb*: 0x8274f6d4) + 0x49
19 81a0c904 (+ 112) 819e4286   <scsi_periph> periph_media_changed(scsi_periph_device_info*: 0x82b2fed8, scsi_ccb*: 0x8274f6d4) + 0xb6
20 81a0c974 (+  48) 819e2cd5   <scsi_periph> check_sense(scsi_periph_device_info*: 0x81a0ca7c, scsi_ccb*: 0x82b2fed8) + 0x1b1
21 81a0c9a4 (+  48) 819e3236   <scsi_periph> check_scsi_status(scsi_periph_device_info*: 0x81a0ca7c, scsi_ccb*: 0x82b2fed8) + 0xfa
22 81a0c9d4 (+  48) 819e34b6   <scsi_periph> periph_check_error(scsi_periph_device_info*: 0x81a0ca7c, scsi_ccb*: 0x82b2fed8) + 0x226
23 81a0ca04 (+  48) 819e43cb   <scsi_periph> send_tur(scsi_periph_device_info*: 0x81a0ca7c, scsi_ccb*: 0x82b2fed8) + 0x93
24 81a0ca34 (+  80) 819e4410   <scsi_periph> wait_for_ready(scsi_periph_device_info*: 0x81a0cabc, scsi_ccb*: 0x82b2fed8) + 0x34
25 81a0ca84 (+  64) 819e452c   <scsi_periph> periph_get_media_status(scsi_periph_handle_info*: 0x82b41c80) + 0xa0
26 81a0cac4 (+ 320) 819e3ebb   <scsi_periph> periph_ioctl(scsi_periph_handle_info*: 0x82b41c80, int32: 15, 0x82a4a45c, uint32: 0x3282 (12930)) + 0x6f
27 81a0cc04 (+ 112) 81a306c4   <scsi_cd> cd_ioctl(0x80bffdd0, uint32: 0xf (15), 0x82a4a45c, uint32: 0x3282 (12930)) + 0x404
28 81a0cc74 (+  48) 800b45db   <kernel_x86> BPrivate::AbstractModuleDevice<0x82a64b10>::Control(0x80bffdd0, int32: 15, int32: -2103139236, uint32: 0x3282 (12930)) + 0x23
29 81a0cca4 (+ 352) 800b9de5   <kernel_x86> devfs_ioctl(fs_volume*: 0x82a63230, fs_vnode*: 0x82b2fac8, 0x80bffde0, uint32: 0xf (15), 0x82a4a45c, uint32: 0x3282 (12930)) + 0x229
30 81a0ce04 (+  64) 800f09a0   <kernel_x86> common_ioctl(file_descriptor*: 0x82a64e70, uint32: 0xf (15), 0x82a4a45c, uint32: 0x3282 (12930)) + 0x38
31 81a0ce44 (+  48) 800db86f   <kernel_x86> fd_ioctl(true, int32: 6, uint32: 0xf (15), 0x82a4a45c, uint32: 0x3282 (12930)) + 0x5f
32 81a0ce74 (+  80) 800dd154   <kernel_x86> _kern_ioctl + 0x4c
33 81a0cec4 (+  48) 80154068   <kernel_x86> ioctl + 0x1c
34 81a0cef4 (+  64) 800cffcf   <kernel_x86> BPrivate::DiskDevice::KDiskDevice<0x82a4a380>::GetMediaStatus(0x82a4a45c) + 0x23
35 81a0cf34 (+  32) 800cfc73   <kernel_x86> BPrivate::DiskDevice::KDiskDevice<0x82a4a380>::UpdateMediaStatusIfNeeded(0x81a00001) + 0x2b
36 81a0cf54 (+  64) 800d3205   <kernel_x86> BPrivate::DiskDevice::KDiskDeviceManager<0x82819900>::_CheckMediaStatus(0xcccccccc) + 0x8d
37 81a0cf94 (+  32) 800d3396   <kernel_x86> BPrivate::DiskDevice::KDiskDeviceManager<0x82819900>::_CheckMediaStatusDaemon(0xcccccccc) + 0x12
38 81a0cfb4 (+  48) 80081edb   <kernel_x86> common_thread_entry(0x81a0cff0) + 0x3b
kdebug> mutex  0x82b2ff00
mutex 0x82b2ff00:
  name:            SCSI_PERIPH
  flags:           0x0
  holder:          143
  waiting threads:
kdebug> thread
THREAD: 0x829bb840
id:                 143 (0x8f)
serial_number:      143
name:               "media checker"
hash_next:          0x00000000
team_next:          0x829bc0a0
priority:           10 (I/O: -1)
state:              running
cpu:                0x801bf9c0 (0)
sig_pending:        0x0 (blocked: 0x0, before sigsuspend(): 0x0)
in_kernel:          1
fault_handler:      0x00000000
team:               0x8290f600, "kernel_team"
  exit.sem:         565
  exit.status:      0x0 (No error)
  exit.waiters:
kernel_stack_area:  263
kernel_stack_base:  0x81a09000
user_stack_area:    -1
user_stack_base:    0x00000000
user_local_storage: 0x00000000
user_thread:        0x00000000
kernel_errno:       0x0 (No error)
kernel_time:        7435501
user_time:          0
flags:              0x0
architecture dependant section:
	esp: 0x81a0c3c8
	ss: 0x82a60010
	fpu_state at 0x829bba30
scheduler data:
	priority_penalty:	3
	additional_penalty:	6 (24898)
	effective_priority:	1
	time_used:		6 us (quantum: 4700 us)
	stolen_time:		32206 us
	quantum_start:		22040432552 us
	needed_load:		0%
	went_sleep:		22030416374
	went_sleep_active:	4220906585
	core:			0
	cache affinity has expired

Change History (2)

comment:1 by mmu_man, 10 years ago

I guess it actually happens when ejecting the drive while it's trying to read from it.

comment:2 by Starcrasher, 11 months ago

Although it's a different bus, it's seems similar to #18431. Could it be fixed the same way? ... If it wasn't already.

Note: See TracTickets for help on using tickets.