KDL when ejecting not mounted CD

[anevilyak]

I seem to be able to quite reliably panic Haiku by ejecting an iso9660 CD. Panic message:

PANIC: vm_page_fault: unhandled page fault in kernel space at 0xdeadbf1f, ip 0x80078d2e

Backtrace:

stack trace for thread 29 "media checker"
    kernel stack: 0x806a3000 to 0x806a7000
frame               caller     <image>:function + offset
 0 806a68f4 (+  48) 80065bcd   <kernel_x86>:invoke_debugger_command + 0x00f5
 1 806a6924 (+  64) 800659bd   <kernel_x86> invoke_pipe_segment(debugger_command_pipe*: 0x80137b20, int32: 0, 0x0 "<NULL>") + 0x0079
 2 806a6964 (+  64) 80065d44   <kernel_x86>:invoke_debugger_command_pipe + 0x009c
 3 806a69a4 (+  48) 800672f4   <kernel_x86> ExpressionParser<0x806a6a58>::_ParseCommandPipe(0x806a6a54) + 0x0234
 4 806a69d4 (+  64) 8006672e   <kernel_x86> ExpressionParser<0x806a6a58>::EvaluateCommand(0x80128200 "bt", 0x806a6a54) + 0x02ba
 5 806a6a14 (+ 224) 8006871c   <kernel_x86>:evaluate_debug_command + 0x0088
 6 806a6af4 (+  64) 80063a82   <kernel_x86> kernel_debugger_loop() + 0x01ae
 7 806a6b34 (+  32) 8006494d   <kernel_x86>:kernel_debugger + 0x004d
 8 806a6b54 (+ 192) 800648f5   <kernel_x86>:panic + 0x0029
 9 806a6c14 (+  64) 800ca366   <kernel_x86>:vm_page_fault + 0x013a
10 806a6c54 (+  64) 800da571   <kernel_x86>:page_fault_exception + 0x00d9
11 806a6c94 (+  12) 800ddc86   <kernel_x86>:int_bottom + 0x0036
kernel iframe at 0x806a6ca0 (end = 0x806a6cf0)
 eax 0xdeadbeef     ebx 0x811b33f8      ecx 0x811a167c   edx 0x811a36d8
 esi 0xf            edi 0xf             ebp 0x806a6e28   esp 0x806a6cd4
 eip 0x80078d2e  eflags 0x210287
 vector: 0xe, error code: 0x0
12 806a6ca0 (+ 392) 80078d2e   <kernel_x86> devfs_ioctl(fs_volume*: 0x811ad730, fs_vnode*: 0x811ae550, 0x811a36d0, uint32: 0xf (15), 0x811b33f8, uint32: 0x811a167c) + 0x0212
13 806a6e28 (+  64) 800a7ae4   <kernel_x86> common_ioctl(file_descriptor*: 0x811adde8, uint32: 0xf (15), 0x811b33f8, uint32: 0x811a167c) + 0x0038
14 806a6e68 (+  48) 8009579f   <kernel_x86> fd_ioctl(true, int32: 5, uint32: 0xf (15), 0x811b33f8, uint32: 0x811a167c) + 0x005f
15 806a6e98 (+  80) 80096f12   <kernel_x86>:_kern_ioctl + 0x0046
16 806a6ee8 (+  48) 800e98bc   <kernel_x86>:ioctl + 0x001c
17 806a6f18 (+  64) 8008a5d7   <kernel_x86> BPrivate::DiskDevice::KDiskDevice<0x811b3300>::GetMediaStatus(0x811b33f8) + 0x0023
18 806a6f58 (+  32) 8008a2a9   <kernel_x86> BPrivate::DiskDevice::KDiskDevice<0x811b3300>::UpdateMediaStatusIfNeeded(0x806a0001, 0x0) + 0x0025
19 806a6f78 (+  64) 8008d731   <kernel_x86> BPrivate::DiskDevice::KDiskDeviceManager<0x8119faf0>::_CheckMediaStatus(0x81998800, 0x8005967d, 0x801276b4, 0x0, int8: 0, 0x806a6ff8, int8: -9, 0x8119faf0, 0x0, 0x0, 0x0, int8: 0, 0x0, 0x0, int32: -2147117420) + 0x008d
20 806a6fb8 (+  32) 8008d8c2   <kernel_x86> BPrivate::DiskDevice::KDiskDeviceManager<0x8119faf0>::_CheckMediaStatusDaem(NULL) + 0x0012
21 806a6fd8 (+  32) 800596f7   <kernel_x86> _create_kernel_thread_kentry() + 0x001b
22 806a6ff8 (+2140508168) 80059694   <kernel_x86> thread_kthread_exit() + 0x0000

I'd assume this is relatively recent since I don't recall anything like this happening back when I was testing iso9660 bugs for Axel, but that was several hundred revisions ago. In any case, environment is hrev30933, gcc2 + gcc4 hybrid using the ata bus manager. Let me know what other information I can pull out here.

[anevilyak]

On second thought, it KDLs if the disc is mounted also. Updated description accordingly.

[anevilyak]

Note also, in the mounted case, the panic occurs after the CD has ejected and the volume has been removed from the desktop.

[bonefish]

Helpful information might be: "vnode" on the "fs_vnode*" parameter of devfs_ioctl() and a "devfs_node" for the printed "private_node".

[luroh]

#3962 and #3964 look related, fwiw.

[anevilyak]

kdebug> vnode 0x811ae550
VNODE: 0x811ae550
 device:        2
 id:            9
 ref_count:     1
 private_node:  0x811bc440
 mount:         0x811bb438
 covered_by:    0x00000000
 cache:         0x00000000
 flags:         ---
 advisory_lock: 0x00000000
kdebug> devfs_node 0x811bc440
DEVFS NODE: 0x811bc440
 id:          9
 name:        "raw"
 type:        21a4
 parent:      0x811bc400
 dir next:    0x00000000
 device:      0x811b20b0
 node:        0xdeadbeef
 partition:   0x00000000

[anevilyak]

Is there any particular set of kernel tracing options I could enable that might provide extra info for this particular case?

[stippi]

For me, this is always reproducable. But I have no time currently to look into it, or to binary search the revision that caused this.

[mmlr]

(In #3964) OK, closing this one as well, as a duplicate of #3983 as this holds the most accessible information.

[anevilyak]

Serial log with devfs tracing enabled.

[anevilyak]

Attached serial log with devfs tracing enabled. I can't see any obvious culprits in there myself right now, but I don't really know the devfs that well.

[anevilyak]

Still working on binary searching what revision caused this...I've managed to narrow it to somewhere between 30500 and 30770 so far, working on narrowing it down further.

[anevilyak]

Make that between hrev30700 and hrev30770.

[jahaiku]

This is just a guess, but it could be around hrev30726 (axeld: * Instead of deleting the device directly, we now only remove it from its ...) 3 weeks ago.

[anevilyak]

Replying to jahaiku:

This is just a guess, but it could be around hrev30726 (axeld: * Instead of deleting the device directly, we now only remove it from its ...) 3 weeks ago.

Looks quite likely, at least hrev30726 also exhibits the problem, testing one or two more revisions to make sure it's in fact the culprit.

[anevilyak]

hrev30726 confirmed.

[anevilyak]

Will see if I can have a look after work unless you get to it first Axel :)

[anevilyak]

Looking into it.

[anevilyak]

The problem seems to be the change on line 256 of devfs.cpp:

 	255	                // pass the call through to the underlying device 
 	256	                vnode->stream.u.dev.device->Removed(); 

Removed() winds up getting called on eject, which results in the raw device deleting itself, hence the 0xdeadbeef above. What I'm uncertain about is how to determine when we should and should not be calling Removed().

[axeld]

Thanks Rene, should be fixed with hrev30961.

[anevilyak]

Confirmed, thanks Axel!

[dsuden]

I'm getting regular KDLs when inserting and removing CDs from my computer. I have tried various recent versions of Haiku and experience it with all of them. When ripping audio from CDs, I'll eject each after done ripping, and inevitably, a few CDs into the process, I get a KDL. I have most-recently tried 46104 (last pre-PM version) and also a PM version from a couple days ago). I'll try and attach a photo of screen.

[ttcoder]

Dane, it seems I beat you to it after all, please see #10259 ;-) Though there are differences in symptoms, so I'm not 100% certain you won't have to re-open this one ticket yet.. hold on.