Opened 11 years ago

Closed 11 years ago

Last modified 6 years ago

#3983 closed bug (fixed)

KDL when ejecting not mounted CD

Reported by: anevilyak Owned by: axeld
Priority: normal Milestone: R1/alpha1
Component: System/Kernel Version: R1/pre-alpha1
Keywords: Cc: Jens.Arm@…, lurohh@…
Blocked By: Blocking: #3964
Has a Patch: no Platform: All

Description (last modified by 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.

Attachments (1)

devfs_serial_trace.zip (35.3 KB ) - added by anevilyak 11 years ago.
Serial log with devfs tracing enabled.

Download all attachments as: .zip

Change History (26)

comment:1 by anevilyak, 11 years ago

Description: modified (diff)

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

comment:2 by anevilyak, 11 years ago

Description: modified (diff)

comment:3 by anevilyak, 11 years ago

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

comment:4 by bonefish, 11 years ago

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

comment:5 by luroh, 11 years ago

#3962 and #3964 look related, fwiw.

comment:6 by anevilyak, 11 years ago

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

comment:7 by anevilyak, 11 years ago

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

comment:8 by stippi, 11 years ago

Milestone: R1R1/alpha1

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.

comment:9 by mmlr, 11 years ago

Blocking: 3964 added

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

by anevilyak, 11 years ago

Attachment: devfs_serial_trace.zip added

Serial log with devfs tracing enabled.

comment:10 by anevilyak, 11 years ago

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.

comment:11 by anevilyak, 11 years ago

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.

comment:12 by anevilyak, 11 years ago

Make that between hrev30700 and hrev30770.

comment:13 by jahaiku, 11 years ago

Cc: Jens.Arm@… added

comment:14 by jahaiku, 11 years ago

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.

in reply to:  14 comment:15 by anevilyak, 11 years ago

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.

comment:16 by anevilyak, 11 years ago

hrev30726 confirmed.

comment:17 by anevilyak, 11 years ago

Owner: changed from bonefish to axeld

comment:18 by anevilyak, 11 years ago

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

comment:19 by anevilyak, 11 years ago

Owner: changed from axeld to anevilyak
Status: newassigned

Looking into it.

comment:20 by anevilyak, 11 years ago

Owner: changed from anevilyak to axeld
Status: assignednew

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().

comment:21 by luroh, 11 years ago

Cc: lurohh@… added

comment:22 by axeld, 11 years ago

Resolution: fixed
Status: newclosed

Thanks Rene, should be fixed with hrev30961.

comment:23 by anevilyak, 11 years ago

Confirmed, thanks Axel!

comment:24 by dsuden, 6 years ago

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.

comment:25 by ttcoder, 6 years ago

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.

Note: See TracTickets for help on using tickets.