Thema: Seltsamer Pagefault

[TheThing]

Hi,
ich habe momentan ein Problem bei dem ich nicht mehr weiter weiß. Vor ein paar Tagen hab ich mal wieder an meinem Kernel gebastelt und er ist nun so weit dass er einen simplen userspace-Prozess ausführen kann. Der userspace-Prozess ruft dabei einen simplen Syscall auf, der eine einfache Textzeile ausgibt. So sieht es aus, wenn es funktioniert:

Als ich dann anfing meinen simplen Prozess zu erweitern, fingen die Probleme an. Wenn der userspace-Prozess groß genug wird fällt der Kernel beim Sprung in den userspace auf die Nase, das scheint aufzutreten sobald der Prozess im RAM die Größe einer Page übersteigt. Das sieht dann folgendermaßen aus:

Um das Problem einzugrenzen hab ich dann meinen Testprozess vereinfacht, er sieht so aus:

Code: (asm) [Auswählen]

mov eax, 42
int 0x62
jmp $

xchg eax, eax
[...]Wie man sieht, keine Stackzugriffe und nur ein simpler Syscall, aufgeblasen wird das dann mit sehr vielen "xchg eax, eax"-Befehlen um das Programm groß genug zu bekommen um den Crash zu provozieren.
Natürlich hab ich mir dann das Logfile von qemu angesehen, ich hab es mal hier auf pastebin gepackt.
Was mich zunächst daran irritiert ist das cr2 die Adresse 0x00000000 angibt. Dort ist die obere Grenze des vom Kernel bereitgestellt usermode-Stacks, aber ein Zugriff auf den Stack findet ja gar nicht statt! Um ganz sicher zu sein hab ich mir zunächst per objdump die Anweisung an der von qemu angegebenen eip-Adresse angesehen, und dort steht ganz brav mein "mov eax, 42". Also, tatsächlich kein Stackzugriff, und beim instruction fetch scheints ja auch nicht zu krachen (sonst wäre ja cr2=eip), also was will die CPU an 0x00000000?
Ebenfalls seltsam ist, dass der error-code angibt, die Page sei nicht gemappt. Ich hab daher probiert per "info tlb" aus qemu mehr Infos herauszubekommen, und um das ganze vergleichen zu können hab ich das einmal mit einer funktionierenden Version des Programms (d.h. klein genug) und einmal mit der nicht funktionierenden Version getan:
1. Funktionierend
2. Nicht funktionierend
Ich hab die beiden Files dann mit einem diff-Tool (meld) verglichen, dabei fiel mir zunächst auf, dass in der nicht funktionierenden Version folgende Zeile fehlte: "00000000fffff000: 0000000000192000 ---DA--UW". D.h. der Stack ist nicht gemappt - wie bereits der Pagefault sagte. Auffällig ist auch das hier:
0000000040000000: 0000000000195000 ----A--UW
0000000040001000: 0000000000000000 -------UW
Die zweite Page des Programmes ist also nicht korrekt gemappt. Das sind zwar schon zwei Probleme, allerdings dürften beide nicht für den Pagefault verantwortlich sein. Es ist mir auch ein Rätsel, warum diese beiden Adressen nicht korrekt gemappt sind - die entsprechenden Code-Zeilen wurden definitiv ausgeführt.

Ich habe jetzt schon einige Stunden damit verbracht auf logs zu starren und an meinem Code herumzubasteln, aber die Ursache für den Pagefault und die zwei anderen Fehler konnte ich nicht finden, trotz zahlreicher eingefügter Print-Anweisungen. Daher poste ich mein Problem nun hier, in der Hoffnung dass jemand von euch eine Idee oder einen Tipp hat, damit ich dieses Problem endlich beheben kann. Der Code entspricht, abgesehen von ein paar zusätzlichen print-Anweisungen, der Version im Repository. Relevant für mein Problem dürften wohl vor allem elf.bas, modules.bas und vmm.bas sein.

Grüße,
TheThing


/edit: Ich hab mal eine ISO mit besagtem Problem hochgeladen: http://venom.improved-madness.de/frost.iso

[Jidder]

Ich hab da jetzt nur kurz reingeguckt, aber in elf.load_image rufst du in Zeile 92 vmm.resolve auf um die physische Adresse für den map_page-Aufruf zu bestimmen. Ich glaube ein Problem könnte sein, dass du den Rückgabewert nicht prüfst, weil die Funktion 0 zurückgeben kann. Auch verstehe ich nicht, warum in resolve free_pagetable aufgerufen wird. Kann das nicht zu Problemen führen?

[TheThing]

Der Aufruf von free_pagetable sollte eigentlich kein Problem sein, sofern ich da keinen Denkfehler drin habe. resolve kann ja auch Adressen auflösen, die außerhalb des aktuellen Kontext liegen, daher wird die pagetable dort auch per get_pagetable besorgt, und wenn get_pagetable sie gemappt hat, muss sie auch wieder per free_pagetable freigegeben werden. Wenn die pagetable zum aktuellen Kontext gehört mappt get_pagetable ja nichts und free_pagetable tut dann einfach nichts.

Zum Rückgabewert: Nun, ich könnte mich schlagen, dass ich darauf nicht gekommen bin. Nicht nur, dass ich den Rückgabewert nicht überprüft habe, ich habe auch noch den falschen Kontext übergeben, resolve hat nämlich im Kontext des Prozesses nach der physischen Adresse gesucht - das war natürlich völliger Unsinn. Und eine print-Anweisung und ein Test haben ergeben: Der erste Aufruf von resolve hat das korrekte Ergebnis ausgespuckt, der zweite hat 0 zurückgegeben. Das erklärt auch das mapping von 0x40001000 nach 0.
Ich habe den Code von elf.load_image jetzt geändert, bevor ich die Adresse meines Speicherbereichs an vmm.kernel_automap übergebe speichere ich mir nun die physische Adresse in phys_mem ab. Die Schleife, die den Speicher in den Prozess-Kontext überträgt, sieht nun so aus:

Code: (freebasic) [Auswählen]

'' map the pages into the context of the process
for counter as uinteger = 0 to pages-1
if (not (vmm.map_page(@process->vmm_context, cast(any ptr, min_addr + counter*pmm.PAGE_SIZE), _
  phys_mem+(counter*pmm.PAGE_SIZE), _
          (vmm.PTE_FLAGS.WRITABLE or vmm.PTE_FLAGS.PRESENT or vmm.PTE_FLAGS.USERSPACE)))) then
panic_error("Could not assign memory to the process")
end if
nextDie Verwendung von phys_mem dürfte nicht nur deutlich schneller sein, sondern erspart mir auch eine potenzielle Fehlerquelle. Oh, und ich habe bei der Schleife noch "0 to pages" auf "0 to pages-1" korrigiert, sonst zähle ich eine Page zu viel. Ich hab das ganze auch getestet und mir wieder von qemu den TLB ausgeben lassen, und siehe da:
0000000040000000: 0000000000195000 ----A--UW
0000000040001000: 0000000000196000 -------UW
Das Programm wird jetzt also korrekt gemappt. Aber: Der Stack ist immernoch nicht da und auch der mysteriöse Pagefault ist noch unverändert.

Erst mal vielen Dank, den Fehler hätte ich vermutlich noch tagelang übersehen. Ich hoffe du hast noch mehr gute Ideen auf Lager

/edit: Ok, das wird immer seltsamer... Der Stack war nämlich mal da. Ich hab gerade in thread_create den Kontext des Prozesses aktiviert und ein hlt eingefügt. Dann hab ich mir mit dem qemu Monitor den TLB angeguckt, und dort steht ganz unten ein 0xfffff000 -> 0x00193000 Mapping drin. Das heißt dann wohl, dass zwischen thread_create und dem Loslaufen des Prozesses irgendwas seltsames mit dem Kontext passiert.

[Jidder]

So direkt fällt mir auch nichts ein. Allerdings habe ich noch die Theorie, dass anstelle des Programms nur Pages, die mit Nullen gefüllt sind, gemappt werden. Die Nullen würden (glaube ich) als add [eax], al interpretiert werden. Da bei dir eax den Wert 0 hat, könnte das den Page Fault erklären. Wenn ich dich richtig verstanden habe, hast du bisher nur überprüft, ob in der Binary die richtigen Instruktionen stehen, aber im Speicher (virtueller Adressraum) könnte was ganz anderes landen. Das sollte sich mit einer Debugausgabe feststellen lassen, die direkt vor dem Sprung in den User Space die Werte an der Adresse 0x40000000 ausgibt. Ist leider nur eine Theorie und falls sie stimmt, wüsste ich eine konkrete Ursache dafür nicht.

[TheThing]

Und wieder hast du den richtigen Riecher...
Direkt bevor den Kernel in den userspace springt (in handle_interrupt) hab ich die vorgeschlagene Debugausgabe eingefügt. Ich lasse mir einfach die ersten vier Bytes an 0x40000000 ausgeben. Wenn ich den kleinen Prozess nehme (mit dem es ja bisher funktioniert) erhalte ich 0xB8575653. Das entspricht push ebx, push esi, push edi und dem ersten Byte von mov eax, 42. Das ist für den kleinen Prozess korrekt. Mit dem großen Prozess kommt 0x00000000 heraus - damit wäre der Pagefault ja dann erklärt. Jetzt stellt sich nur die Frage, wo diese Nullen herkommen und wie sie dort hingekommen sind.
Ich habe auch noch herausgefunden an welcher Stelle das Stack-Mapping "verschwindet": Es ist der memcpy-Aufruf mit dem das Programm in den reservierten Speicherbereich kopiert wird. Direkt davor ist der Stack noch da, direkt danach nicht mehr, und wenn ich memcpy auskommentiere bleibt der Stack auch da. Meine memcpy-Implementierung scheint nicht das Problem zu sein, ich hatte sie testweise mal durch eine simple for-Schleife ersetzt.
So, ich geh dann erstmal schlafen, mir fallen gerade ständig die Augen zu

[TheThing]

Ich hab jetzt mal genauer nachgesehen an welcher Stelle die Nullen ins Spiel kommen. Von GRUB bekomme ich das Modul ohne Probleme geladen, die ersten vier Bytes davon sind in Ordnung, auch nach dem memcpy-Aufruf. Im Zielspeicher stehen nach dem memcpy aber Nullen drin. Testweise hab ich auch mal das nachfolgende memset auskommentiert aber das hat nichts geändert. Ich weiß echt nicht mehr weiter - wie kann die Größe des größeren Programmes dafür sorgen, dass der Kernel sich so seltsam verhält?

/edit: Auch wenn das Stack-Mapping bei memcpy verschwindet, memcpy kopiert aber tatsächlich korrekt. Im Speicherbereich landen die richtigen Bytes, aber obwohl genau dieser Speicherbereich dann in den Prozesskontext gemappt wird (ich habs überprüft, es wird genau dieser physische Speicherbereich gemappt) stehen im Prozesskontext dann Nullen drin. Ich kapiers einfach nicht...

[MNemo]

Bin gerade dabei mir das mal Genauer anzugucken. Was ich kurioses gefunden habe ist, dass dein memcpy die erste PAGE nicht beschreibt.

Also vor dem 'rep movsb' befehl stimmt alles, der sollte nach 0x7000 schreiben, aber danach ist 0x7000 laut QEMU weder Dirty/ noch Accesed, 0x8000 dafür aber schon.
0x7000 wird einfach übersprungen.

BTW: in der pmm::alloc könnte eventuell auch ein if bitmap(counter) == 0 zu besserer Performance beitragen. Ist mir so beim singlesteppen aufgefallen.

EDIT: Also meine Vermutung ist das etwas mit dem INVALPG beim mappen schief geht, und an ein veraltetes mapping geschrieben wird. (Fals QEMU mit info tlb, nicht den TLB sondern das normale Mapping ausgibt wie es in der Beschreibung steht).
Das kann ich leider nur sehr schwer überprüfen weil die Sourcen im Repository(1c6bf59d20…) scheinbar nicht 100%ig mit dem ISO zusammen passen. GDB spring bei mir zumindest in der VMM.pas wirr in irgenwelchen Zeilen herum in denen kein code steht.

EDIT2:
Ich glaube ich habe das problem gefunden.

du rufst

Code: [Auswählen]

asm invlpg [v_addr]auf. Damit Invalidierst du die Speicherseite die die Variable V_ADDR enthält, nicht die Adresse die in V_ADDR drin steht. (Also das tut zumindest die Binärversion im ISO)

[TheThing]

BTW: in der pmm::alloc könnte eventuell auch ein if bitmap(counter) == 0 zu besserer Performance beitragen. Ist mir so beim singlesteppen aufgefallen.

Das ist eine super Idee, das bau ich gleich ein

Das kann ich leider nur sehr schwer überprüfen weil die Sourcen im Repository(1c6bf59d20…) scheinbar nicht 100%ig mit dem ISO zusammen passen. GDB spring bei mir zumindest in der VMM.pas wirr in irgenwelchen Zeilen herum in denen kein code steht.

Ja, ich hatte kurz bevor ich die ISO erstellt habe ein paar if's and verschiedenen Stellen eingefügt die Alarm schlagen wenn ungewöhnliche Werte auftauchen. Es wäre wohl schlauer gewesen auf den Repository-Stand zurückzugehen bevor ich die ISO erstellt hab.

du rufst

Code: [Auswählen]

asm invlpg [v_addr]auf. Damit Invalidierst du die Speicherseite die die Variable V_ADDR enthält, nicht die Adresse die in V_ADDR drin steht. (Also das tut zumindest die Binärversion im ISO)

Autsch... Der Fehler ist ja echt mies, da wäre ich absolut nicht drauf gekommen. Die Zeile ist schon so lange im Kernel und hat vorher nie Probleme gemacht, daher ging ich davon aus dass sie stimmt. Ich hab die Stelle jetzt geändert und meine Probleme sind verschwunden, so sieht die Stelle jetzt aus:

Code: (freebasic) [Auswählen]

asm
mov eax, dword ptr [v_addr]
invlpg [eax]
end asmDamit funktioniert es jetzt, ich hoffe dass es jetzt nicht auf irgendeine andere Weise falsch ist.

Schon mal vielen Dank für die Hilfe, aber darf ich dich noch fragen, wie du so etwas debuggst? Du hast ja vermutlich QEMU + GDB benutzt, aber benutzt du da eine GUI für GDB? Und wie geht man vor, wenn man so etwas debuggen will? Hast du da vielleicht eine Empfehlung für ein Tutorial, Dokumentation o.Ä. für mich? Mein "Debugging" bestand bisher immer nur aus eingebauten Debugausgaben und dem Ansehen von QEMU-logs, und ich würde in Zukunft solche Fehler gerne selbstständig aufspüren können.

[MNemo]

Code: (freebasic) [Auswählen]

asm
mov eax, dword ptr [v_addr]
invlpg [eax]
end asmDamit funktioniert es jetzt, ich hoffe dass es jetzt nicht auf irgendeine andere Weise falsch ist.

Es sieht Korrekt aus. Der Compiler scheint ja alle im ASM block verwendeten Register automagisch zu sichern.

Schon mal vielen Dank für die Hilfe, aber darf ich dich noch fragen, wie du so etwas debuggst? Du hast ja vermutlich QEMU + GDB benutzt, aber benutzt du da eine GUI für GDB?

Ja. Mit Qemu und GDB, aber ohne GUI.

Code: [Auswählen]

qemu-system-x86_64 -cdrom frost.iso -s -S # startet QEMU mit GDB-SERVER und wartet

Code: [Auswählen]

src/kernel$ gdb --tui frost.krn
target remote localhost:1234    (mit Qemu verbinden)
break ELF::LOAD_IMAGE
c
Und dann kannst du mit s / n durch den code steppen, mit print VAR variablen ausgeben lassen, und parallel in QEMU die register ausgeben.
(Du must fast alle Labels in deinem Kernel GROß-Schreiben)

Um meinen Verdacht zu überprüfen habe ich deinen kernel mit "objdum -d" disassembliert und einen breakpoint mit 'break *0x0123' an der Adresse der invpg-Instruktion gesetzt und mir in Qemu die Register angeguckt.

Alles andere kannst du dir sicher mit Google und dem Wiki (QEMU GDB) selbst aneignen.