[solved] print goes CRAZY when called from ISR

[oscoder]

I've got a kernel with protected mode, paging, and now also a jump to userspace. Next step is system calls - which I'm working on now.

However, I'm facing the WEIRDEST bug I've ever seen. The system call isr is triggered fine. It disables further interrupts and calls a function to trigger the right system call handler.

This system call handler has a bug I'm trying to track down - which isn't actually relevant to the current question. My problem is that every time I print the same variable, I'm getting a different output. Not only that, but the actual output is the colour code of the last k_print_hex call! So when I do this:

Code: Select all

    if ((event->type == EVENT_TYPE_SYSCALL) && (event_list->num_entries == 0))
    {
k_print_hex(event_list->num_entries, 0x01, 0, 22);
k_print_hex(event_list->num_entries, 0x02, 10, 22);
k_print_hex(event_list->num_entries, 0x03, 20, 22);
k_print_hex(event_list->num_entries, 0x04, 30, 22);

HANG();
    }

I get this output:

Code: Select all

00000000  00000001  00000002  00000003

How could this possibly happen?? My code's all rough round the edges atm, but I can't see how this would happen? And how it didn't happen any of the times I've printed values before - just with this interrupt handler that is triggered from ring3.

I haven't got the hang of debugging with QEMU yet but if there's any kind of output that would be helpful please let me know!

This is some of the relevant code re the ISR, print_hex, etc...

Code: Select all

void k_print_hex(uint32_t number, uint8_t attrib, ushort posx, ushort posy)
{
  char *video_mem;
  unsigned int i;
   /*Check parameters*/
    if(posy > TEXT_LINES)  /*don't try and print off screen (who knows what memory we'll overwrite!)*/
      return;

   /*Goto correct part of video memory*/
    video_mem = get_videomem(posx, posy);

   /*Write the text*/
    for(i=0; i<(sizeof(number)*2);  i++)  /*2 characters per byte in number*/
    {
      if(((number & 0xF0000000)>>28) <= 9)  /*it's a number digit*/
        video_mem = putc_videomem(video_mem, '0' + (char)((number & 0xF0000000)>>28), attrib);
      else  /*it's a letter digit*/
        video_mem = putc_videomem(video_mem, 'A' + (char)((number & 0xF0000000)>>28)-10, attrib);
      number = number << 4;  /*4 bits per hex digit*/
    }
}

char *get_videomem(ushort posx, ushort posy)
{
  return((char*)TEXT_VIDEOMEM_BASE + (TEXT_COLUMNS*2)*posy + 2*posx);  /*location of video mem + number of bytes on a line (2 per character) x number of lines down + number of chars across*/
}

char* putc_videomem(char* video_mem, const char c, uint8_t attrib)
{
  *video_mem = c;
  video_mem++;
  *video_mem = (char)attrib;
  video_mem++;
  return(video_mem);
}

Code: Select all

as_syscall_isr:
  cli
  pushad
  cld
    push edx
    push ecx
    push ebx
    push eax
    call syscall_stage2
    add esp, 16  ; reset stack to how it was
  popad
  IRET

Code: Select all

uint32_t syscall_stage2(uint32_t eax, uint32_t ebx, uint32_t ecx, uint32_t edx)
{
  event_t syscall_event;
    syscall_event.syscall.number = eax;
    syscall_event.syscall.param_1 = ebx;
    syscall_event.syscall.param_2 = ecx;
    syscall_event.syscall.param_3 = edx;
    syscall_event.type = EVENT_TYPE_SYSCALL;
    syscall_event.status = 0;

    event_trigger(&syscall_event);

  return((uintptr_t)syscall_event.status);
}

The following is related to the jump to usermode in the first place:

Code: Select all

as_usermode:
    mov ebp, esp
    cli  ;don't want to be interrupted half-way through this

   ; set up data & stack segments
    mov ax, [ebp+4]  ;first parameter is data segment selector
    mov ds, ax
    mov fs, ax
    mov es, ax
    mov gs, ax

   ; load stack ready for iret to userspace
    push ax  ;SS
    push dword [ebp+12]  ;third parameter is stack pointer
    pushf  ;eflags
     ; set interrupts enabled in new eflags -> re-enables interrupts on iret
      pop eax
      or eax, 0x200
      push eax
    push dword [ebp+8]  ;second parameter is code segment selector
    push dword [ebp+16]  ;fourth parameter is new eip
 ;fn cannot return so no need for LEAVE or RET
  IRET
  HLT

as_tss_load:
  ENTER 0,0
    mov ax, [ebp+8]
    ltr ax
  LEAVE
  RET

Code: Select all

#if defined SYSTEM_x86
      tss_set((uintptr_t)&k_stack,  /*won't be needed anything stored here again, so fine to start writing again from the top after switch to usermode*/
              SEL_RING0_DATA,
              as_cr3_get());
      as_usermode( SEL_RING3_DATA,
                   SEL_RING3_CODE,
                   NULL,  /*will set up its own stack*/
                   init_entry);
#else
      k_print("ERROR: system not supported for init loading", TEXT_DEBUG, 8);
#endif

and finally, the usermode code that gets called:

Code: Select all

extern main   ;main c file
global _entry

; code section
section .text
align 4

  ; reserve stack space - don't need laods it's just init
  STACKSIZE equ 0x3FFF          ; that's 16k.

  ; entry point, called by kernel
  _entry:
     ;int 100
     mov esp, stack+STACKSIZE   ;set up the stack
     mov ebp, esp
     call main
  _hang:
     jmp _hang

; uininitialised data
section .bss
align 4

  ; put the stack here
  stack:
     resb STACKSIZE-1

Code: Select all

uint32_t main()
{
    syscall_0(0);
  return(0);
}

Code: Select all

;syscall.asm - function for making syscalls from userspace
section .text
GLOBAL syscall_0

SYSCALL_INT equ 0x90

syscall_0:
  ENTER 0, 0
    mov eax, [ebp+8]
    int SYSCALL_INT
    ;syscall will set eax to return code, so we don't need to do anything more
  LEAVE
  RET

(yeah the code's horrible - sorry in advance!)

[thomasloven]

Without much to grab at, I'd guess your problem is related to the stack somehow.

When the arguments to k_print_hex are pushed to the stack, they overwrite parts of event_list.

You could try e.g.

Code: Select all

k_print_hex(event_list, 0x07, 0, 0);
for(;;);

and then after reading te address of event_list, open the qemu console (alt+2) and run "info registers" to see if ESP is anywhere close to that.

ymmw

[linuxyne]

Building upon the comment above this one, if the event_list is indeed sharing stack space with the parameters, then one of the possible reasons for that to occur is if event_list points to a local variable of a routine which returned it as its return value. In such a situation, the event_list variable points to a region of stack space which is free (since the frame of the routine which contained it has already been unwound).

[linguofreak]

In general, if one variable ends up with a value that should be in another variable, something going wonky on the stack is your prime suspect. This can include unmatched pushes and pops, not taking the automatic pushes and pops that the CPU does during interrupt service into account, buffer overflows, using stale values that have already been popped off the stack, etc.

[oscoder]

Ok now I feel stupid! Thanks for the help and explanation of how to do qemu debuging. I did a bit of digging with that, and turns out the problem was a typo in passing the pointer to the stack.

It should have been

Code: Select all

&k_stack_top

Instead of

Code: Select all

&k_stack

Because of course, the stack expands downwards