X86_64 hobby OS user-space page fault heisenbug

help
1

Hello. I'm working on an x86_64 hobby OS in Rust, and I've been fighting a weird heisenbug for more than a month now with no success; After a tiny amount of allocations from user-space, the allocated memory address page faults even though it's supposedly mapped. Source code's located here: GitHub - ChefKissInc/Firework: The Firework Operating System.
Here's a log: https://gist.github.com/ChefKissInc/4f3ba516f1284a4ab71b8a72f0e4dd82
Any help's appreciated.

2

can you describe the situation in detail please? the full log is too noisy and overwhelming for someone who knows nothing about your kernel. you can't throw a pile of code to any forum user and say "here I got a crash and figure out the reason".

you didn't even describe what's the problem, at least explain what's the intended and expected behavior, and what's actually happened, like, where is the error in that over 16k lines of logs???

2 Likes
3

Hey there, to find the two crashes you just need to search for “received”. The intend of the noisy log is for sanity checking the allocator, I can provide a less noisy log if that is a problem. I don’t see the problem with my description; it’s simple: the user-space process sends the memory allocation system call a few times, and it seems like it works fine, however, all of a sudden even though (the tiny amount of) previous allocations worked fine upon accessing the address it gets a page fault, as if it is not mapped even though it is.
The task scheduler and user-space stuff (including system call implementations) are located at Kernel/src/system/proc, exception handling at Kernel/src/system/exc, and the system calls made by the user-space for the allocations are in the allocator provided by the FireworkKit crate, specifically in Libraries/FireworkKit/src/userspace/allocator.rs

4

your log says

Received page fault exception in user-land: There was a page-level protection violation while writing a user page at 0xC5817200.

I don't know how your address space is organized,

some random guesses:

  • page is meant to be writable but incorrectly set as readonly
  • address 0xc5817200 is a mapped kernel address, meaning the allocation syscall returned wrong address
  • address 0xc5817200 is in user space, but the page table entry is incorrectly set to be supervisor
  • your user land process moved to a different core and changes to page table or TLB are not properly propagated.
5

The virtual address base for

  • kernel code is 0xFFFFFFFF80000000,
  • all other kernel accesses is 0xFFFF800000000000, and
  • user-space is 0xC0000000.

Unlikely.

There's no multi-tasking support yet, so it moving to a different AP is not possible.

I'll check the rest when I can. Thanks.

6 
DEBUG kernel::system::proc::userland::page_table > Setting CR3 to 0x4B89000
DEBUG kernel::system::proc::userland::page_table > Mapping 1 pages at 0xC5813000 to 0x5813000 with flags PageTableFlags { present: true, writable: false, user: true, pat_index: 0 }
DEBUG kernel::system::proc::userland::page_table > Allocated page table at 0x5814000
DEBUG kernel::system::proc::userland::handlers::alloc > Process CR3 is 0x4B89000
DEBUG kernel::system::proc::userland::page_table > Mapping 1 pages at 0xC5815000 to 0x5815000 with flags PageTableFlags { present: true, writable: true, user: true, pat_index: 0 }
Received page fault exception in user-land: There was a page-level protection violation while writing a user page at 0xC5815200.
R15: 0x0000000000000007, R14: 0x00000000C5815200, R13: 0x00000000C57E6E88, R12: 0x0000000000000007
R11: 0x0000000000000000, R10: 0x0000000000000200, R9:  0x0000000000000008, R8:  0x0000000000000000
RBP: 0x0000000000000004, RDI: 0x00000000C5815200, RSI: 0x0000000000000002, RDX: 0x00000000C5815200
RCX: 0x0000000000000002, RBX: 0x00000000C57E6CC0, RAX: 0xFFFFFFFFFFFFFFFF, RIP: 0x00000000C4B86E69
CS:  0x000000000000001B, RFL: 0x0000000000000246, RSP: 0x00000000C57E6C50, SS:  0x0000000000000023
INT: 0x000000000000000E, ERR: 0x0000000000000007
Image Base: 0x00000000C4412000
Process Path: com.ChefKiss.AC97Audio

Doesn't seem like any of the other guesses either.
There might be an issue with my paging implementation (Libraries/AMD64/src/paging.rs)

7

you already dumped the registers, why not also dump the page table entries when the fault occurs? maybe that will give more clues.

8

Here

DEBUG kernel::system::proc::userland::page_table > Setting CR3 to 0x4B89000
DEBUG kernel::system::proc::userland::page_table > Mapping 1 pages at 0xC5815000 to 0x5815000 with flags PageTableFlags { present: true, writable: false, user: true, pat_index: 0 }
DEBUG kernel::system::proc::userland::handlers::alloc > Process CR3 is 0x4B89000
DEBUG kernel::system::proc::userland::page_table > Mapping 1 pages at 0xC5816000 to 0x5816000 with flags PageTableFlags { present: true, writable: true, user: true, pat_index: 0 }
Received page fault exception in user-land: There was a page-level protection violation while writing a user page at 0xC5816200.
CR3: 0x4B89000
R15: 0x0000000000000007, R14: 0x00000000C5816200, R13: 0x00000000C57E6E88, R12: 0x0000000000000007
R11: 0x0000000000000000, R10: 0x0000000000000200, R9:  0x0000000000000008, R8:  0x0000000000000000
RBP: 0x0000000000000004, RDI: 0x00000000C5816200, RSI: 0x0000000000000002, RDX: 0x00000000C5816200
RCX: 0x0000000000000002, RBX: 0x00000000C57E6CC0, RAX: 0xFFFFFFFFFFFFFFFF, RIP: 0x00000000C4B86E69
CS:  0x000000000000001B, RFL: 0x0000000000000246, RSP: 0x00000000C57E6C50, SS:  0x0000000000000023
INT: 0x000000000000000E, ERR: 0x0000000000000007
Image Base: 0x00000000C4412000
Process Path: com.ChefKiss.AC97Audio
9

you mean this? correct me if I'm wrong since I don't understand how your kernel works, but I suppose those are the log messages when the allocation happens, right? I was talking about dumping the actual in-memory page table entries when the page fault happens, presumably in the page fault handler, is that doable?

another suggestion, since you have the registers dumped, especially RIP and RSP, maybe you can pin point the offending instruction and a stack trace of the userland program to hopefully get some more insights?

10

I can do that.

Insight into what? It's just heap allocations like Box or Vec. The particular instructions are usually some memcpy or similar.

11

I attempted to print the mapping of the address in cr2 inside of the page fault handler. It yielded in a double fault then triple fault.

12

Nevermind. There was a bug in my PageTable::from_cr3 method. Here's the output

Received page fault exception in user-land: There was a page-level protection violation while writing a user page at 0xC5816200.
CR3: 0x4B89000
Mapping: Some(
    0x5816200,
)
R15: 0x0000000000000007, R14: 0x00000000C5816200, R13: 0x00000000C57E6E88, R12: 0x0000000000000007
R11: 0x0000000000000000, R10: 0x0000000000000200, R9:  0x0000000000000008, R8:  0x0000000000000000
RBP: 0x0000000000000004, RDI: 0x00000000C5816200, RSI: 0x0000000000000002, RDX: 0x00000000C5816200
RCX: 0x0000000000000002, RBX: 0x00000000C57E6CC0, RAX: 0xFFFFFFFFFFFFFFFF, RIP: 0x00000000C4B86E69
CS:  0x000000000000001B, RFL: 0x0000000000000246, RSP: 0x00000000C57E6C50, SS:  0x0000000000000023
INT: 0x000000000000000E, ERR: 0x0000000000000007
Image Base: 0x00000000C4412000
Process Path: com.ChefKiss.AC97Audio
13

never mind. I was thinking the possibilities that a SIMD instruction could cause the fault. at a second thought, SIMD should not cause page faults.

the reason I suggest you to dump the page table is to make sure the content of the table entry is indeed what you written to, not some corrupted data.

what are we looking here? is 0x5816200 the page table entry? let me see, the bit pattern is 0b0000_0101_1000_0001_0110_0010_0000_0000, is that the correct value? it doesn't seem a valid PTE to me, or maybe you are printing a different value.

anyway, I am just making guesses. if you can reproduce the crash consistently, I highly suspect your page table is corrupted。

14

It's the resolved physical address from the virtual address, using the page table. the 0x200 comes from the | addr & 0xFFF inside the resolution method.

15

I dumped it. It's here: Warp. (At the bottom)
(every Setting CR3 to 0x... is a context switch)

16

so what? you got an unexpected fault, the first thing is to check the error code and PTE to figure out what caused the fault. I suggest print the value of PTE just to make sure it is indeed the value you intended. why do you think the resolved the physical address is important, while ignores the actual PTE attribute bits?

where did the fault happen then? I'm not suggesting dump the enitre page table of the process, just focus on the relevant part which caused the fault to happen at the first place.

17

That address came from the PML4 -> PDP -> PD -> PT translation...

That page table dump is when the page fault happened. I understood that you wanted me to dump the entire thing, and that takes too long, so I cut it off. The one accessed has a <--.
A log focusing on the mapping of the faulty address:

DEBUG kernel::system::proc::userland::page_table > Setting CR3 to 0x4B89000
DEBUG kernel::system::proc::userland::page_table > Mapping 1 pages at 0xC5815000 to 0x5815000 with flags PageTableFlags { present: true, writable: false, user: true, pat_index: 0 }
DEBUG kernel::system::proc::userland::handlers::alloc > Process CR3 is 0x4B89000
DEBUG kernel::system::proc::userland::page_table > Mapping 1 pages at 0xC5816000 to 0x5816000 with flags PageTableFlags { present: true, writable: true, user: true, pat_index: 0 }
Received page fault exception in user-land: There was a page-level protection violation while writing a user page at 0xC5816200.
CR3: 0x4B89000
Mapping: Some(
    (
        0x5816200,
        PageTableFlags {
            present: true,
            writable: true,
            user: true,
            pat_index: 0x0,
        },
    ),
)
R15: 0x0000000000000007, R14: 0x00000000C5816200, R13: 0x00000000C57E6E88, R12: 0x0000000000000007
R11: 0x0000000000000000, R10: 0x0000000000000200, R9:  0x0000000000000008, R8:  0x0000000000000000
RBP: 0x0000000000000004, RDI: 0x00000000C5816200, RSI: 0x0000000000000002, RDX: 0x00000000C5816200
RCX: 0x0000000000000002, RBX: 0x00000000C57E6CC0, RAX: 0xFFFFFFFFFFFFFFFF, RIP: 0x00000000C4B86E69
CS:  0x000000000000001B, RFL: 0x0000000000000246, RSP: 0x00000000C57E6C50, SS:  0x0000000000000023
INT: 0x000000000000000E, ERR: 0x0000000000000007
Image Base: 0x00000000C4412000
Process Path: com.ChefKiss.AC97Audio
18

that looks a good PTE, it should not cause a page fault at all, it's present, writable, and is user level. and the fact it always happens for the same process baffles me too.

how do you debug the code, are you using an emulator, or are you debugging on real hardware?

to be honest, at this point, I am completely out of ideas. just one last thought, could it be a TLB problem? just as an experiment, try flush all the TLB after you allocated new pages for this process, and see if the fault still occurs.

19

I’m using QEMU.

20

Well, it’s basically doing the reverse of the mapping code. If there’s a problem with it, then I wouldn’t know. I personally don’t see the problem with it, but maybe you will; a 2nd pair of eyes is always helpful.