Auf der Jagd nach dem ungewöhnlichen Elefanten

Käfer jagen macht Spaß. Und ab und zu kommt man mit einer Geschichte davon, mit der man seine Enkel langweilen kann ("Zu meiner Zeit haben wir noch mit Stöcken und Steinen Käfer gejagt" und so).

Die GDC 2014 hielt wieder eine solche trophäenwürdige Jagdsafari für uns bereit. Wir waren fünf Tage davon entfernt, Unity 5 der Welt zu präsentieren, als wir einen hässlichen kleinen Elefanten von einem Fehler entdeckten: Unser glänzender neuer 64-Bit-Editor stürzte unter OSX willkürlich ab und war völlig unbrauchbar. Es gibt einfach nichts Besseres, als auf der Bühne zu stehen und alle paar Minuten zu zeigen, wie großartig dein Fehlerreporter ist.

Also ließen Levi, Jonathan und ich all die tollen Sachen fallen, an denen wir gerade arbeiten (weitere Geschichten, mit denen wir unsere Enkel langweilen wollen), und gingen auf die Pirsch. Alles, was wir zu diesem Zeitpunkt wussten, war, dass es irgendwo in dem nativen Code, den Mono zur Laufzeit generiert, zum Absturz kam.

Wie jeder Programmierer weiß, beginnt man bei einem nicht offensichtlichen Fehler einfach damit, Beweise zu sammeln. Wenn Sie genug über die Verhaltensmuster des Käfers gelernt haben, können Sie ihn schließlich angreifen. Und da die Uhr tickte, waren wir bereit, auf so ziemlich alles zu schießen.

Aber wir waren verblüfft. Für einen Elefanten erwies sich der Käfer als erstaunlich flink und hinterhältig.

Es schien nur unter OSX 10.9 aufzutreten, obwohl Kim etwas gesehen hat, das unter Windows mit seinem Hochleistungs-Speicherdebugger-Zweig sehr ähnlich aussah. Und wenn man Guard Malloc in früheren Versionen von OSX aktiviert hat, sah das Ganze auch ziemlich ähnlich aus. Da der Absturz jedoch in zufälligem Skriptcode an beliebiger Stelle in der Aufrufhierarchie auftrat, war es schwierig, mit Sicherheit zu sagen, was derselbe Absturz war und was nicht. Und der Absturz kann zehnmal hintereinander gleichmäßig verlaufen, um dann bei den nächsten fünf Fahrten völlig anders zu sein.

Während Kim und ich also kniehoch durch den Speicher und oberschenkelhoch durch den Assemblercode wateten, führte Levi einen umfangreichen Trace über alle geheimen und nicht so geheimen Aktivitäten von Mono durch, um ein Gigabyte großes Protokoll und einen Editor zu erstellen, der mit der Geschwindigkeit meiner Großmutter lief. Das ergab die erste interessante Erkenntnis: Offenbar kompilierten wir immer die Methode, in der wir abstürzten, kurz bevor die Dinge unschön wurden.

Aber was hat ihn zum Absturz gebracht? Die unmittelbare Ursache war, dass wir versucht haben, Code von einer ungültigen Adresse auszuführen. Wie sind wir dorthin gekommen? Ein Fehler in der Signalverarbeitung von Mono, bei dem wir nicht richtig fortfahren können? Ein Fehler im JIT-Compiler von Mono, der nicht richtig zum kompilierten Code zurückspringt? Ein anderer Thread, der den Stapelspeicher des Hauptthreads beschädigt? Feen und Grumkins? (eine Zeit lang schien Letzteres am wahrscheinlichsten).

Nach zwei Tagen Jagd war der Elefant immer noch gesund und munter und unterwegs.

Also rüstete ich mich am Samstagabend mit einem Notizbuch, vier verschiedenen Farbstiften und einem reichlichen Vorrat an Bier aus unserem Unity-Kühlschrank aus (wobei ich sorgfältig darauf achtete, dass ich das schreckliche Weihnachtsbier aus der Dose nicht anrührte, das wir immer noch in seinen Ritzen stecken haben). Dann habe ich die Unity-Instanzen hochgefahren, bis ich vier verschiedene Abstürze im Debugger eingefroren hatte, habe sie mit "Roter Absturz", "Blauer Absturz", "Grüner Absturz" und "Schwarzer Absturz" beschriftet und mich mit meinen jeweiligen farbigen Stiften an die Arbeit gemacht, um Notizen zu machen und ein paar nicht ganz so hübsche Diagramme von allem zu zeichnen, was ich gefunden habe.

Hier sind meine Notizen für Blue Crash:

Und da machte ich meine erste Entdeckung: In jedem Fall war der Stack 16 Bytes größer als er sein sollte!

Das führte zur nächsten Entdeckung: Bei allen Abstürzen ergab die Betrachtung dieser zusätzlichen 16 Bytes eine Rücksprungadresse zurück in die Funktion, in der wir abgestürzt sind. Aus einem Trace ging hervor, dass wir in allen Fällen bereits einige Aufrufe derselben Methode ausgeführt hatten, und zunächst dachte ich, die Adresse stamme von dem letzten Aufruf, den wir verfolgt hatten. Bei näherer Betrachtung stellte sich jedoch heraus, dass es sich um die Rücksprungadresse eines Aufrufs handelte, dessen Methode noch nicht kompiliert worden war!

Dies verwirrte mich für einen Moment, da in einigen Fällen mehrere Aufrufe zwischen der letzten verfolgten Methode und diesem Aufruf lagen, die ebenfalls noch nicht kompiliert worden waren. Bei näherem Hinsehen stellte sich jedoch heraus, dass wir immer um sie herumgesprungen waren.

Dann habe ich mir die Funktion angesehen, von der wir anscheinend zurückkehren sollten...

Und da haben wir es (blau hervorgehoben): Wir sind in die falsche Richtung gesprungen!

Mono erstellt hier kleine "Trampolin"-Funktionen, die nur einen Aufruf an den JIT-Compiler und einige Daten enthalten, die nach dem Aufruf in den Befehlsstrom kodiert werden (damit der JIT-Compiler weiß, welche Methode er kompilieren muss). Sobald der JIT-Compiler seine Arbeit getan hat, löscht er diese Trampoline und beseitigt alle Spuren des Methodenaufrufs.

Bei dem dort zu sehenden Aufrufbefehl handelt es sich jedoch um einen so genannten "Beinahe-Aufruf", der im Übrigen einen vorzeichenbehafteten 32-Bit-Offset verwendet, um relativ zum nächsten Befehl zu springen.

Und da eine vorzeichenbehaftete 32-Bit-Zahl nur 2 GB nach oben und unten erreichen kann und wir hier mit 64-Bit arbeiten, wussten wir plötzlich, warum das Heap-Speicherlayout eine so entscheidende Rolle bei der Reproduktion des Fehlers spielte: Sobald Monos Trampoline weiter als 2 GB vom JIT-Compiler entfernt waren, passten Offsets nicht mehr in 32-Bit und wurden bei der Ausgabe der Aufrufanweisung abgeschnitten.

Jonathan hat dann schnell die richtige Lösung gefunden, und als sein Sonntag vorbei war, hatten wir rechtzeitig zur GDC ein stabiles, funktionierendes Build fertig.

Sie alle kennen die Geschichte von dort. Wir haben Unity 5 auf der GDC 2014 erfolgreich und mit begeisterten Kritiken vorgestellt, und nach der Markteinführung wurde es schnell zum beliebtesten Softwareprodukt aller Zeiten. Oh, warten Sie, dieser Teil kommt noch...

Vor dem Start gibt es noch eine ganze Reihe von schwarzen und blauen Abstürzen zu beheben :).