Strange Behaviour (Enabling paging)

pcmattman · Post by **pcmattman** » Sun Sep 30, 2007 7:30 pm

I've had paging working for quite a while now, but recently I went back through my code and made some modifications, only to find that my kernel suddenly started triple faulting (this was about a week ago).

So I threw hundreds of kprintf() and while( 1 ); calls into my code and narrowed it down to my paging initialization code.

Once I realized that the problem was a lot deeper than that I pulled out the Bochs debugger. Working through the problem with kmcguire, I found out that the problem lies here:

Code: Select all

/// Writes data to CR3
void write_cr3( unsigned int cr3 )
{
	if( cr3 == 0 )
	{
		kprintf( "null cr3 write attempted!\n" );
		while( 1 );
	}
	__asm__ __volatile__ ( "movl %0,%eax; movl %eax,%cr3" : : "r" (cr3) );
}

This is called here:

Code: Select all

// fill CR3 and CR0
write_cr3( (unsigned int) pagedir ); // put page directory address into cr3
write_cr0( read_cr0() | 0x80000000 ); // set paging bit to 1

After CR0 is modified the triple fault occurs - three page faults.

The CR3 value Bochs reports in the log is 0x00000000 - definitely not what I put into CR3 (it should be 0x9C000). The problem is, when I step through in the debugger, everything works perfectly - no problems at all (when done CR3 = 0x9C000).

This has me stumped. Any ideas?

frank · Post by **frank** » Sun Sep 30, 2007 8:21 pm

Does it work in other emulators? Also did you try printing the value of the function parameter cr3?

Brynet-Inc · Post by **Brynet-Inc** » Sun Sep 30, 2007 8:52 pm

I'm not entirely sure about your problem, but personally I'd use:

Code: Select all

/// Writes data to CR3
static __inline void write_cr3( unsigned int cr3 )
{
   if( cr3 == 0 )
   {
      kprintf( "null cr3 write attempted!\n" );
      while( 1 );
   }
   __asm__ __volatile__ ( "movl %0,%%cr3" : : "r" (cr3) );
}

/// Writes data to CR0
static __inline void write_cr0( unsigned int cr0 )
{
   if( cr0 == 0 )
   {
      kprintf( "null cr0 write attempted!\n" );
      while( 1 );
   }
   __asm__ __volatile__ ( "movl %0,%%cr0" : : "r" (cr0) );
}

/// Reads data from CR3
static __inline unsigned int read_cr3( void )
{
   unsigned int cr3;
   __asm__ __volatile__ ( "movl %%cr3,%0" : "=r" (cr3) );
   return cr3;
}

/// Reads data from CR0
static __inline unsigned int read_cr0( void )
{
   unsigned int cr0;
   __asm__ __volatile__ ( "movl %%cr0,%0" : "=r" (cr0) );
   return cr0;
}

Good luck

- Just a suggestion..

pcmattman · Post by **pcmattman** » Sun Sep 30, 2007 9:14 pm

frank wrote:Does it work in other emulators? Also did you try printing the value of the function parameter cr3?

Doesn't work in VPC, and I do print the parameter and get the correct value.

@Brynet: That was my implementation before, it still didn't work. I've since changed it to what's in my first post.

Edit: it appears the problem lies here (rewritten into Intel syntax):

Code: Select all

mov eax,<pagedir addy>
mov cr3,eax

Any read of cr3 will give the correct value, but in Bochs (and, it seems, VPC) the actual system does not recognize the value of CR3:

Code: Select all

00125160000i[CPU0 ] protected mode
00125160000i[CPU0 ] CS.d_b = 32 bit
00125160000i[CPU0 ] SS.d_b = 32 bit
00125160000i[CPU0 ] | EAX=0009c000  EBX=0010e020  ECX=0009c000  EDX=00000ffc
00125160000i[CPU0 ] | ESP=00112148  EBP=00112148  ESI=0002bea8  EDI=0002bead
00125160000i[CPU0 ] | IOPL=0 id vip vif ac vm rf nt of df IF tf sf zf AF pf cf
00125160000i[CPU0 ] | SEG selector     base    limit G D
00125160000i[CPU0 ] | SEG sltr(index|ti|rpl)     base    limit G D
00125160000i[CPU0 ] |  CS:0008( 0001| 0|  0) 00000000 000fffff 1 1
00125160000i[CPU0 ] |  DS:0010( 0002| 0|  0) 00000000 000fffff 1 1
00125160000i[CPU0 ] |  SS:0010( 0002| 0|  0) 00000000 000fffff 1 1
00125160000i[CPU0 ] |  ES:0010( 0002| 0|  0) 00000000 000fffff 1 1
00125160000i[CPU0 ] |  FS:0010( 0002| 0|  0) 00000000 000fffff 1 1
00125160000i[CPU0 ] |  GS:0010( 0002| 0|  0) 00000000 000fffff 1 1
00125160000i[CPU0 ] | EIP=00100072 (00100072)
00125160000i[CPU0 ] | CR0=0x00000011 CR1=0 CR2=0x00000000
00125160000i[CPU0 ] | CR3=0x00000000 CR4=0x00000000
00125160000i[CPU0 ] >> jmp .+0xfffffffe (0x00100072) : EBFE

From the execution of:

Code: Select all

__asm_write_cr3:

	push %ebp			# use a standard prologue because it's faster than ENTER ...
	movl %esp,%ebp
	
	movl 8(%ebp),%eax	# set CR3 to the page directory address
	movl %eax,%cr3
	movl %cr3,%ecx
	
	l:					# debugging: this allows us to quit bochs and see if CR3 and EAX are right
	jmp .
	
	leave				# ... but use LEAVE because it takes less cycles
	ret

As you can see from the Bochs log, EAX and ECX equal 0x9C000, but the value of CR3 still equals 0x0.

Any ideas why this happens? Does anyone agree with me when I say that there is no reason why this should not be working?

pcmattman · Post by **pcmattman** » Mon Oct 01, 2007 12:08 am

I fixed the problem by doing this:

Code: Select all

// fill CR3 and CR0
write_cr3( (unsigned int) pagedir ); // put page directory address into cr3
kprintf( " " ); // somehow this makes it work?
write_cr0( read_cr0() | 0x80000000 ); // set paging bit to 1

I have a problem with this - it's a hack. Does anyone know any other method?

AJ · Post by AJ » Mon Oct 01, 2007 1:40 am

OK - I'm *sure* you have checked for this, but 'pagedir' is definitely holding the pointer to the PD rather than the value of the first PDE, isn't it? Also, could pagedir possibly be a pointer to the PD in virtual RAM rather than the correct physical RAM value?

Sorry for mentioning the obvious, but I have done both of these things before

The only effects I can thing of that kprintf can possibly be doing are:

* Causing a delay - which as you know should not be necessary.
* Somehow invoking your PFE handler - I guess this shouldn't be possible because paging isn't enabled yet.

I'll follow the link in your sig and see if I can find some code to look at...
Cheers,
Adam

pcmattman · Post by **pcmattman** » Mon Oct 01, 2007 1:57 am

Causing a delay - which as you know should not be necessary.

It shouldn't (be necessary), but it works.

Somehow invoking your PFE handler - I guess this shouldn't be possible because paging isn't enabled yet.

Interrupts disabled, no valid IDT initialized yet (paging done first in my OS, because the IDT/GDT init calls use paging calls to map their relevant structures).

I'll follow the link in your sig and see if I can find some code to look at...

SourceForge Site Status wrote:As of 2007-09-29 at 10:00PM Pacific, we have a CVS outage due to unplanned maintenance. This affects developer CVS access (including ViewVC) for projects starting with the letters m, n and q.

What a coincidence... My project starts with an "m".

Once it comes back up I'll commit my current changes (the revision with the kprintf( " " ); call) and then you can read through it. The current version (which is not accessible anyway) is old (by about a week).

AJ · Post by AJ » Mon Oct 01, 2007 1:58 am

OK - one more thought on why kprintf() makes it work. Is it possible that this leaves enough time for your tick counter and thereefore resched() to get called?

It may be that your task scheduler then has enough time to write the incoming task's CR3 itself and all is well. Just pondering...

Also, it looks like there is a new(ish) version of Bochs out (2.3.5). I haven't looked at it much yet, but there may be improvements to the debugger that will help you (just an outside chance!).

Cheers,
Adam

pcmattman · Post by **pcmattman** » Mon Oct 01, 2007 2:13 am

Interrupts are disabled, multitasking isn't enabled at that point in time.

I'll have to look into the new version of Bochs.

JamesM · Post by **JamesM** » Mon Oct 01, 2007 2:21 am

This is very strange. I've just read the intel manual section about "MOV CR*", and it mentions nothing like this.

My only (pure guesswork) instinct is that bochs is somehow validating the directory address you give it, and deciding that it's foobar, thus not showing it.

Very strange behaviour though...

pcmattman · Post by **pcmattman** » Mon Oct 01, 2007 2:58 am

I think it may be time for some guru meditation

Combuster · Post by **Combuster** » Mon Oct 01, 2007 3:14 am

What seems likely is that the compiler attempts to optimize your functions which apparently causes a rescheduling of instructions around cr0 and cr3. the kprintf makes it work because it causes all instructions before it to be executed before entering the function, hence the cr3 load is executed prior to the cr0 one.

I do not know what version of gcc you are using, and how much you are letting gcc optimize, but I would personally try to move the CRx reads/writes to a seperate compilation unit so that the compiler is forced to keep them in order.

pcmattman · Post by **pcmattman** » Mon Oct 01, 2007 3:16 am

I changed the optimization level from 2 to 0 (thinking that the calls may be optimized out), but the problem remained.

GCC version 4.2.0.

JamesM · Post by **JamesM** » Mon Oct 01, 2007 3:21 am

Have you tried objdumping the resulting executable to triple-check what order the instructions are executed in?

Code: Select all

objdump -d kernel

(just in case you're a windows person and have never used objdump before!

)

pcmattman · Post by **pcmattman** » Mon Oct 01, 2007 9:50 pm

CVS is back up, so I committed what I have to the repository.

Currently the only problem is in CPP_Kernel/syscore/paging.cc where I need to have the kprintf( " " ); between the write to CR3 and CR0.