Printf-Debugging mit dem GM

    • GM 8

    Diese Seite verwendet Cookies. Durch die Nutzung unserer Seite erklären Sie sich damit einverstanden, dass wir Cookies setzen. Weitere Informationen

    • Printf-Debugging mit dem GM

      Anlässlich dieser Technikfrage fühlte ich mich mal motiviert, eine kleine Anleitung zu schreiben, wie man "printf"-Debugging auch mit dem GM betreiben kann.

      An wen richtet sich dieses Tutorial?
      Hauptsächlich an jene, die sich bisher nur auf Windows rumgetrieben haben, und sich neben dem GM nur wenige andere Sprachen angesehen haben. Allen anderen dürfte ich hier nur wenig Neues erzählen.

      Wieso heißt das printf-Debugging?
      In jedem Programm hat man bisweilen zwei Ausgabekanäle, einen für Standardausgabe und einen für Fehlerausgabe. Wenn man ein Programm aus einer Shell heraus startet (oder unter Windows mit cmd.exe (oder command.com)), landet der über diese Kanäle rausgeschriebene Text hinter dem Aufruf des Programms. Beide Kanäle unterscheiden sich eigentlich nur darin, dass man sie unterschiedlich umleiten kann (um z.B. die Standardausgabe eines Programms als Eingabe für ein anderes zu Benutzen, während Fehler und Warnungen immer noch angezeigt werden). Und in C heißt die Funktion für diese Ausgabe "printf".

      Wozu brauche ich sowas beim GM, wo es doch den Debugmodus gibt?
      Bisweilen gibt es im GM nicht die Möglichkeit, im Code Haltepunkte zu setzen, d.h. dem GM zu sagen "Halt das Spiel mal an, wenn du in dieser Zeile angekommen bist." D.h. man hat nicht die Möglichkeit, sich durch den Code zu "hangeln", oder zwischen zwei Operationen mal die Werte von Variablen zu überprüfen. Auch kann es vorkommen, dass das Spiel irgendwann einfach abstürzt, obwohl der Code syntaktisch korrekt ist.

      Wenn man also festhalten will, wann welche Zeile des Codes ausgeführt wird, und welchen Wert gewisse Variablen zu der Zeit haben, schreibt man einfach den Wert dieser Variablen oder Zeichenketten wie "Generiere Weltkarte" nach draußen, und kann dann bei Bedarf nachlesen. Auch, wenn viele Informationen auf einen Schlag festgehalten werden, man z.B. bei einem Aufeinandertreffen zweier Armeen in einem RTS überprüfen möchte, ob der Schaden richtig berechnet wird, kann man so Schritt für Schritt festhalten, welche Einheit welcher anderen wieviel Schaden verursacht, um danach nach Auffälligkeiten zu suchen.

      Und wenn man schonmal dabei ist, kann man auf diese Weise auch das festhalten, was man normalerweise im Debugmodus überprüfen will, um so den Zustand direkt vor einem Absturz zu erhalten.

      Ok, wie mach ich das nun?
      Ganz einfach: Da niemand ein GM-Spiel aus cmd.exe heraus starten wird (und ich bei einer oberflächlichen Suche keinen Zugriff auf die Ausgabekanäle finden konnte), schreiben wir direkt in die Datei, in die wir die Ausgabe sonst umgeleitet hätten:

      scr_printf:

      GML-Quellcode

      1. var tmpFile;
      2. // Datei öffnen; dabei anhängen und nicht überschreiben
      3. tmpFile = file_text_open_append(working_directory + "\debug.log");
      4. // den "Text" sicherheitshalber nochmals in einen String umwandeln und dann mit Zeitstempel ausgeben
      5. file_text_write_string(tmpFile, "[" + date_datetime_string(date_current_datetime()) + "] " + string(argument0));
      6. // Zeilenumbruch
      7. file_text_writeln(tmpFile);
      8. // Datei wieder schließen; _jetzt_ steht die neue Zeile in der Datei
      9. file_text_close(tmpFile);
      Alles anzeigen


      Wichtig ist, dass die Datei nach jedem Aufruf dieses Skripts geschlossen wird, da erst beim Schließen die neue Zeile auch wirklich in der Datei steht.
      Im Falle eines Absturzes ist der Log somit so aktuell wie möglich (stürzt das Spiel ab, bevor die Datei geschlossen wird, gehen alle seit dem Öffnen geschriebenen Informationen verloren).

      Nun kann man obiges Skript einfach aufrufen, und so Text oder Variablen (Dank obiger Umwandlung beliebigen Typs) rausschreiben:

      GML-Quellcode

      1. scr_printf("foo");
      2. scr_printf(42);
      3. scr_printf(myString);
      4. scr_printf(myReal);


      Durch die Zeitstempel kann man außerdem auf die Sekunde genau nachlesen, in welchen zeitlichen Abständen Funktionen ausgeführt werden.
      Auch, wenn man irgendwann feststellt, dass das Spiel abgestürzt ist, weil eine Variable den Wert 0 hatte, kann man so herausfinden, wann dieser Wert in die Variable geschrieben wurde.

      Ist das nicht ein wenig Umständlich, immer wieder eine Datei zu öffnen, wenn ich neue Zeilen lesen will?
      So. Kommen wir also nun zu dem Grund, warum ich sowas triviales wie das bisschen da oben als eigenes Tutorial verfasst habe: Wenn man immer nur kleinere Änderungen macht, das Spiel startet und dann in den Log gucken muss, oder wenn man nebenbei die Ausgabe mitlesen will, während das Spiel läuft, müsste man die Datei eigentlich immer wieder neu öffnen oder refreshen.

      In Kombination mit der Generation eines Logs wollte ich hiermit auf diverse UN*X-Tools hinweisen, die bei der Auswertung recht nützlich sein können. Hier hat sich jemand die Mühe gemacht, diese Programme ohne eine zusätzliche Abstraktionsschicht wie Cygwin für Windows zu kompilieren, und hier kann man sie als Paket herunterladen. Wenn man es entpackt, findet man im Unterordner usr\local\wbin jede Menge Programme, von denen man sich die unten genannten entweder ins Windowsverzeichnis entpacken kann (was keine gute Idee ist, da man dieses Verzeichnis nicht unnötig zumüllen sollte), oder sich an einem Ort ablegt, den man dann in seine "PATH"-Variable hinzufügt (siehe unten). Danach kann man sie überall von seinem System aus aufrufen.

      Für alle diese Programme gilt, dass sie aus cmd.exe heraus aufgerufen werden. Für diejenigen, die noch nie damit gearbeitet haben:
      • Mit einem Druck auf die Windowstaste und R könnt ihr direkt sagen, welches Programm ihr ausführen wollt; gebt dort "cmd" ein.
      • Dort könnt ihr direkt Befehle eingeben, die bei betätigen von Enter ausgeführt werden.
      • Mit "Befehlen" wie

        Quellcode

        1. c:
        oder

        Quellcode

        1. d:
        wechselt ihr das Laufwerk.
      • Mit dem Befehl "cd" (= "Change Directory") könnt ihr durch eure Verzeichnisse navigieren. Ordnernamen könnt ihr dabei mit der Tabulatortaste vervollständigen (das ist die links neben Q, über der allseits beliebten Capslock-Taste). Der Ordner ".." ist dabei das übergeordnete Verzeichnis. Beispiele:

        Quellcode

        1. cd foo
        2. cd foo\
        3. cd ..
        4. cd foo\bar\baz

      • Der Befehl "dir" listet alle Unterordner im aktuellen Verzeichnis auf.
      • Man kann auch absolute Pfade angeben:

        Quellcode

        1. cd c:\foo\bar

      • Mit Strg + C kann man ein Programm wieder beenden, das man gestartet hat.


      Startet also cmd.exe (in älteren Windowsversionen command.com) und navigiert in den Ordner, in dem euer Debuglog geschrieben wird.

      Das erste dieser Programme, die ich nun vorstellen möchte, heißt "tail". Mit tail kann man sich das Ende einer Datei ausgeben lassen. Mit dem Parameter -f (force) bleibt tail danach offen, und zeigt jede Zeile an, die ab jetzt in die Datei geschrieben wird. D.h. mit dem Befehl

      Quellcode

      1. tail -f debug.log
      könnt ihr nun eurem Log beim wachsen zusehen. Wenn ihr also dieses Konsolenfenster im Auge behaltet, während ihr euer Spiel testet, sehr ihr sofort, wenn was erscheint, das für euch von interesse ist.

      Das zweite Programm heißt "grep". Angenommen, ihr debuggt ein RTS, schreibt für jede Einheit alle Informationen raus, die für diese Einheit wichtig sind, und gebt bei jeder Ausgabe die Instanz-ID an. Wenn ihr nun nur die Zeilen sehen wollt, die sich mit einer bestimmten Instanz beschäftigen (im Zweifelsfall der, die ihr als Ursache eines Absturzes ausmachen konntet), könnt ihr mit grep die Zeilen herausfiltern, in denen die ID dieser Instanz auftaucht.

      Quellcode

      1. grep "42" debug.log
      zeigt euch alle Zeilen aus debug.log an, die die Zeichenfolge "42" (ohne die Anführungszeichen) enthalten.

      Als letztes möchte ich noch kurz erwähnen, wie man Programmausgaben wie oben erwähnt umleitet. Das Zeichen ">" (links neben Y) leitet die Ausgabe des Aufrufs links von diesem Zeichen in die Datei rechts von diesem Zeichen. Das Zeichen "|" (AltGr + die gleiche Taste, wie eben) leitet die Ausgabe des Aufrufs links von diesem Zeichen in die Eingabe des Aufrufs rechts von diesem Zeichen. Diese Umleitung nennt sich "pipen" (damit ihr was zum Googlen habt).
      D.h. mit dem Aufruf

      Quellcode

      1. tail -f debug.log | grep "42" > 42.log
      würdet ihr alle neuen Zeilen aus debug.log auslesen, davon nur die Zeilen nehmen, die die Zeichenfolge "42" enthalten (ohne die Anführungsstriche) und diese Zeilen in die Datei 42.log schreiben. So könnt ihr also neben der Logdatei, in der alles drin steht, weitere Dateien anlegen, die nur die Zeilen des Logs enthalten, die für die jeweilige Datei gerade interessant sind.

      Wenn man tail mit dem Parameter -f aufruft, arbeitet tail übrigens solange weiter, bis man es durch schließen von cmd.exe oder mit Strg + C beendet.

      Dieser kurze Überblick sollte eigentlich reichen, um neue Ansätze zum Debuggen von Spielen zu liefern, wenn die alten bisher versagten. Wer mehr dazu wissen will, kann sich entweder im Internet informieren (der Name des Programms in Google eingegeben liefert meist gute Ergebnisse) oder die Hilfe des Programm lesen. Für z.B. tail erhält man die durch den Aufruf

      Quellcode

      1. tail -h
      .

      Was hat es nun mit dieser PATH-Variable auf sich?
      Wenn man versucht, ein Programm auszuführen, muss Windows natürlich wissen, wo das Programm liegt. Sollte es sich nicht in dem Verzeichnis befinden, in dem ich euch gerade befindet, so werden der Reihe nach alle Pfade abgesucht, die in PATH stehen, und das erste genommen, was gefunden wird. Geändert wird diese Variable unter Vista und Nanami folgendermaßen:

      Rechtsklick auf Computer -> Eigenschaften -> Erweiterte Systemeinstellungen -> Umgebungsvariablen. (Unter XP und älterem Windowsversionen sollten die Umgebungsvariablen auf ähnliche Weise zu finden sein.)

      Hier findet ihr nun zwei Variablen mit dem Namen "Path" (in älteren Windowsversionen wurden diese Variablen "PATH" geschrieben, deswegen habe ich oben auch diese Schreibweise gewählt), einmal unter Benutzervariablen und einmal unter Systemvariablen. Die Benutzervariablen gelten nur für den gerade angemeldeten Benutzer; was ihr hier ändert, betrifft nur euren Account und sonst keinen. Die Systemvariablen betreffen alle Benutzer. Bearbeitet nun die Variable eurer Wahl (je nach dem, ob andere Benutzer auch die UN*X-Tools benutzen sollen oder nicht) und fügt mit einem Semikolon getrennt den Pfad zu dem Ordner hinzu, in dem ihr die UN*X-Tools gespeichert habt (d.h. den absoluten Pfad des Ordners, in dem die exe-Dateien liegen).

      Vorsicht! Wenn ihr hier vorhandene Pfade löscht oder Mist reinschreibt, könnte Windows nicht mehr richtig Funktionieren.

      Ich hoffe, es findet sich irgendwann jemand, dem dieses Tutorial geholfen hat.
    • Sehr schönes Tutorials doch gibt es diese Funktion nicht bereits?

      GML-Quellcode

      1. show_debug_message(My_Varivale) //Schreibt eine Message in ein File, welches man nur im Debug modus unter Tools>Show Messages erreichen kann


      Wollte dich jetzt nicht irgendwie entmutigen, finde das TUt auch supi, doch gibt es die funktion schon :S
    • 1.: Die Funktion habe ich übersehen.
      2.: In der Hilfe steht was davon dass der Text angezeigt wird und nicht, dass er in einer Datei festgehalten wird. Und wenn man mal viele Instanzen des selben debugausgabenerzeugenden Objekts hat, wird das verfolgen eines bestimmten Objekts dort immer noch schwierig. Auch sind damit nicht die Probleme versorgt, dass man mal über längeren Zeitraum protokolliert und danach was nachschauen muss (viel Spaß beim Scrollen) oder dass man diesen Log nachlesen will, wenn das Spiel plötzlich abstürzt.

      3.: Mag sein, dass sich diese Anwendung im Nachhinein als schlecht gewählt herausstellt, aber primärer Gedanke war es, die oben genannten UN*X-Tools (und vor allem die Windowskompilationen, die ohne Emulationsschicht auskommen) denen vorzustellen, die sie noch nicht kannten.
    • Ich würde das gerna an dieser Stelle nochmal etwas elaborieren, weil es vielleicht einigen immernoch nicht so ganz klar ist: Eine elementare Arbeitsweise sowohl in der Mathematik als in der Informatik (und in vielen Naturwissenschaften nebenbei auch) ist es, neue Probleme auf bereits bekannte und gelöste Probleme zurückzuführen. Um diese Arbeitsweise zu unterstreichen gibt es die sogenannte UN*X-Philosophie, die ein paar Regeln vorgibt, wie sich einige Menschen gute Software vorstellt. Sie besagt, dass gutes Programm nach Möglichkeit genau eine Aufgabe lösen soll, und so geschrieben sein soll, dass es mit jeder anderen Software zusammenarbeitet. Dazu legt sie fest, dass die einzige wirklich kompatible Schnittstelle im Prinzip Textdateien sind. Daraus folgt, dass es wahnsinnig viele Tools in jedem UN*X-System gibt, um Textdateien zu verarbeiten, was vielen hier eventuell gar nicht so bewusst ist. Das Tutorial sollte wohl darauf hinweisen, dass es durchaus lohnenswert ist, sich mit diesen Tools zu beschäftigen. Das Tutorial unterteilt sich also in zwei Abschnitte: Zuerst wird das Debuggen auf das verarbeiten von Textdateien vereinfacht, sodass die mächtigen UN*X-Tools angewendet werden können, dann wird gezeigt, was mit UN*X-Tools so gemacht werden kann. Ein Beispiel: Ihr interessiert euch für Statistische Daten, wie viele Instanzen so erzeugt werden. Dazu fügt ihr bei allen relevanten Objekten im Create-Event ein (wobei ihr NAME durch den entsprechenden Namen ersetzt):

      GML-Quellcode

      1. scr_printf("created NAME");

      Nun könnt ihr den Log nach Beendigung des Spiels wie folgt analyiseren:

      Quellcode

      1. grep created debug.log | sed 's/\[.*\]\W*//' | sort | uniq -c | sort -bn

      Sieht kompliziert aus, ich erklär mal die einzelnen involvierten Programme:
      • grep wurde bereits erklärt, es filtert alle Zeilen heraus, die das Wort "created" enthalten
      • sed wird hier benutzt, um die Timestamps zu entfernen. Sed ist im Prinzip eine eigene Programmiersprache, das erste S steht dabei für ersetzen und folgt grob der folgenden Syntax: s/PATTERN/ERSATZ/. Der Ersatz ist hier leer, wir wollen ja nur etwas entfernen. Das Pattern ist ein Regulärer Ausdruck, ich verzichte hier auf die Details, die Funktion des Regulären Ausdrucks zu erklären, nur soviel: Er erkennt pro Zeile das erste Vorkommen von rechteckigen Klammern und liefert die Klammern, den Inhalt sowie darauf folgenden Whitespace.
      • sort sortiert logischerweise die Zeilen, hier um Blöcke gleicher Zeilen zu bilden
      • uniq -c Zählt aufeinanderfolgende gleichen Zeilen und ersetzt sie durch ein einziges Vorkommen, dabei wird die Anzahl der Zeilen vorangestellt
      • sort -bn sortiert ebenfalls, ignoriert aber diesmal führende Leerzeichen (dies ist nötig, weil uniq -c automatisch rechtsbündige Zahlen generiert) und sortiert nicht nach ASCII-Werten, sondern liest Zahlen an Anfang von Zeilen korrekt ein.

      Es wird also eine Sortierte Liste von allen Instanzen sortiert nach Anzahl der erzeugten Instanzen ausgegeben. Und alles, was dafür benötigt wurde, ist eine einzige Zeile Code. So kompakt wie mit UN*X-Tools kann man kaum programmieren.