Opened 10 years ago

Closed 10 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 10 years ago.
Serial log with devfs tracing enabled.

Download all attachments as: .zip

Change History (26)

comment:1 Changed 10 years ago by anevilyak

Description: modified (diff)

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

comment:2 Changed 10 years ago by anevilyak

Description: modified (diff)

comment:3 Changed 10 years ago by anevilyak

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

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

comment:5 Changed 10 years ago by luroh

#3962 and #3964 look related, fwiw.

comment:6 Changed 10 years ago by 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

comment:7 Changed 10 years ago by anevilyak

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

comment:8 Changed 10 years ago by stippi

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 Changed 10 years ago by mmlr

Blocking: 3964 added

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

Changed 10 years ago by anevilyak

Attachment: devfs_serial_trace.zip added

Serial log with devfs tracing enabled.

comment:10 Changed 10 years ago by 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.

comment:11 Changed 10 years ago by 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.

comment:12 Changed 10 years ago by anevilyak

Make that between hrev30700 and hrev30770.

comment:13 Changed 10 years ago by jahaiku

Cc: Jens.Arm@… added

comment:14 Changed 10 years ago by 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.

comment:15 in reply to:  14 Changed 10 years ago by 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.

comment:16 Changed 10 years ago by anevilyak

hrev30726 confirmed.

comment:17 Changed 10 years ago by anevilyak

Owner: changed from bonefish to axeld

comment:18 Changed 10 years ago by anevilyak

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

comment:19 Changed 10 years ago by anevilyak

Owner: changed from axeld to anevilyak
Status: newassigned

Looking into it.

comment:20 Changed 10 years ago by anevilyak

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 Changed 10 years ago by luroh

Cc: lurohh@… added

comment:22 Changed 10 years ago by axeld

Resolution: fixed
Status: newclosed

Thanks Rene, should be fixed with hrev30961.

comment:23 Changed 10 years ago by anevilyak

Confirmed, thanks Axel!

comment:24 Changed 6 years ago by 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.

comment:25 Changed 6 years ago by 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.

Note: See TracTickets for help on using tickets.