docs/corodebug.pod

=head1 Debuggen mit Coroutinen

=head1 Einführung

Im Laufe der Jahre habe ich eine ganz eigene Methode zum Debuggen
meiner Programme entwickelt. Diese Methode kombiniert einige Konzepte
(interkative Shell in jedem Programm, Coroutinen), die mehr als reines
Debugging ermöglichen.

Diese Methode möchte ich hiermit vorstellen, vielleicht bringt sie
den einen oder anderen auf Gedanken oder stellt sich gar als nützlich
heraus...

=head1 "Traditionelle" Debugging-Methoden

Nun, es gibt den Perl-Debugger; über diesen wird tatsächlich viel
erzählt und geschrieben, und ich nehme an, er wird wirklich häufig
benutzt. Aber aus welchen Gründen auch immer, ich konnte mich mit ihm
(anders als mit gdb) nie wirklich anfreunden: die einzige Funktion, die
ich mit einiger Regelmäßigkeit benutze, ist die Trace-Funktion. Das kann
ich sogar als "Fest im Gehirn eingebautes Makro" sofort tippen: "perl -d
xxx, dann t, dann c", andere Debugger-Befehle kenne ich nicht.

Diese Trace-Funktion hat viele Nachteile: sie macht das Programm sehr
langsam, sie funktioniert nur, während man im Debugger ist, und häufig
hängt mein Programm aus nicht nachvollziehbaren Gründen, und die Ausgabe
ist zu umfangreich. Die Hauptnachteile sind aber, daß man den Debugger
nicht ein- oder ausschalten kann und daß er interaktiv arbeitet.

Die Mehrheit meiner Programme sind langlebige Hintergrundprogramme. Diese
sind immerhin so gut getestet, daß sie in Produktion selten Probleme
entwickeln, aber manchmal kommt das natürlich vor. Das erklärt
wahrscheinlich, weshalb ich den Perl-Debugger nicht benutze: man kann den
Perl-Debugger (meines Wissens) nicht an bestehende Prozesse attachen, man
kann die Programme nicht dauerhaft unter dem Debugger starten und man hat
im Allgemeinen auch keinen interaktiven Zugang.

Startet man das Programm neu (z.B. nach Einbau einiger C<warn>-statements
oder um es unter dem Debugger laufen zu lassen) tritt das Problem
natürlich nicht mehr auf, oder man müsste zu lange warten bis der
entscheidende "Trigger" kommt.

Hinzu kommt, daß viele meiner Programme stark ereignisgesteuert
arbeiten: Hält man das Programm an, gibt es unerwünschte Timeouts;
erstellt man einen Trace, springt dieser wild zwischen Programmteilen hin
und her, die nichts miteinander zu tun haben.

Als einzige Möglichkeit (die auch häufig angewendet wird), bleibt meist
nur, extrem viel mitzuloggen, so daß man im Fehlerfall zumindest auf eine
Art Trace zurückgreifen kann. Natürlich sind die schweren Fehler selten
dort, wo man gerade viel mitloggt.

=head1 Die Entwicklung eines anderen Ansatzes

=head2 Die Anfänge: ein Webserver

Um das Jahr 2000 herum schrieb ich einen Web-Server, der vollkommen
Event-gesteuert war (buchstäblich: er benutzte das Event-Modul dazu).

Weil es so einfach war, bekam er bald eine interaktive Shell verpasst:

   sub shell {
      my $fh = shift;

      while (defined (print $fh "cmd> "), $_ = <$fh>) {
         s/\015?\012$//;

         if (/^info/) {
            # bearbeite Kommandos
            ...
      }
   }

   my $port = new Coro::Socket
        LocalPort => $CMDSHELL_PORT,
        ReuseAddr => 1,
        Listen => 1,
   or die "unable to bind cmdshell port: $!";

   push @listen_sockets, $port;

   async {
      while () {
         async \&shell, scalar $port->accept;
      }
   };

Der Code benutzt Coroutinen, sollte aber einfach verständlich
sein: C<Coro::Socket> ist das Pendant zu C<IO::Socket>, bei dem Aufrufe
wie C<accept> die anderen Coroutinen nicht blockieren; die Funktion
C<async> startet eine neue ("asynchrone") Coroutine für jede neue
Verbindung, und die C<shell>-Funktion schließlich liest in einer Schleife
Befehle von der Socket und führt sie aus.

Ursprünglich dazu gedacht, eine Liste von aktiven Verbindungen zu
erhalten bzw. bisweilen IP-Adressen zu blockieren, hatte ich irgendwann
eine offensichtliche aber doch nicht so offensichtliche idee (*:

         } elsif (s/^print//) {
            my @res = eval $_;
            print $fh "eval: $@\n" if $@;
            print $fh "RES = ", (join " : ", @res), "\n";

Mit dem "print"-Kommando (eigentlich wäre "eval" ein besserer Name)
lassen sich erstaunlich viele Dinge erledigen:

Erlaube 200 gleichzeitige Verbindungen mehr:

   print $conn::connections->adjust (200)

Setze die Downloadrate auf 1MB/s:

   print $conn::tbf_top->{rate} = 1e6

Erlaube 20 gleichzeitige Downloads mehr:

   print $conn::queue_file->{slots} += 20

Das erste Beispiel benutzt die korrekte "API" zum Anpassen einer
Semaphore, die beiden letzteren Beispiele sind eigentlich "böse
Hacks" weil der Code diese Möglichkeit der Anpassung nicht explizit
unterstützt, sie funktionieren aber trotzdem.

Auf diese Weise läßt sich bisweilen auch Debuggen: wenn z.B. eine
Verbindung hängt, kann man versuchen, sie zu finden und dann versuchen,
herauszufinden, woran es liegt, indem man sich verschiedene globale
Variablen anschaut oder kleine "Suchprogramme" mit C<print do "dateiname">
ausführt.

Das kann eine extreme Hilfe sein, ist aber immer noch recht umständlich.

=head2 Perl ist besser als jede Shell: Deliantra

Der Deliantra-Server (ein MORPG) ist ebenfalls vollkommen
ereignisgesteuert und besitzt ebenfalls eine Shell, die (fast) ohne
Coroutinen auskommt:

   sub tcp_serve($) {
      my ($fh) = @_;

      binmode $fh, ":raw:perlio:utf8";
      print $fh "\n> ";

      my $iow; $iow = EV::io $fh, EV::READ, sub {
         if (defined (my $cmd = <$fh>)) {
            $cmd =~ s/\s+$//;

            if ($cmd =~ /^\s*exit\b/i) {
               print $fh "will not exit() server.\n";
            } elsif (...
               # andere befehle
               ...
              
         }
      };
   }

   our $LISTENER;

   # now a shell listening on a tcp-port - let the firewall decide access rights
   if ($cf::CFG{perl_shell}) {
      if (my $listen = new IO::Socket::INET LocalAddr => $cf::CFG{perl_shell}, Listen => 1, ReuseAddr => 1, Blocking => 0) {
         $LISTENER = EV::io $listen, EV::READ, sub { tcp_serve $listen->accept };
      }
   }

Deliantra benutzt EV als Event-Bibliothek, ansonsten habe ich aus meinen
früheren Versuchen gelernt und implementiere keine Kommandos mehr direkt,
sondern erlaube direkt die Eingabe von Perl-Ausdrücken (und stelle
stattdessen einfach ein paar Funktionen im Namensraum zur Verfügung):

            ...
         } else {
            my $sub = sub {
               package cf;
               select $fh;

               # compile first, then execute, as Coro does not support switching in eval string
               my $cb = eval "sub { $cmd \n}";

               my $t1 = Time::HiRes::time;
               my @res = $@ ? () : eval { $cb->() };
               my $t2 = Time::HiRes::time;

               print "\n",
                     "command: '$cmd'\n",
                     "execution time: ", $t2 - $t1, "\n";
               warn "evaluation error: $@" if $@;
               print "evaluation error: $@\n" if $@;
               print "result:\n", cf::dumpval @res > 1 ? \@res : $res[0] if @res;
               print "\n> ";

               select STDOUT;
            };

            if ($cmd =~ s/\s*&$//) {
               cf::async {
                  $Coro::current->desc ($cmd);
                  $sub->()
               };
            } else {
               $sub->();
            }

Die Befehlsausführung ist weitaus komplexer: Zuerst wird die eingegebene
Zeile kompiliert und dann C<eval>uiert. Danach wird das Ergebnis, etwaige
Laufzeitfehler und die Ausführungszeit ausgegeben.

Da man als Administrator manchmal Befehle im "Hauptprogramm" (die
Coroutine, die die Event-Schleife ausführt) ausführen muss, der Server
aber all 120ms ein update generieren muss, muss man lang dauernde Befehle
in den "Hintergrund" (eine weitere Coroutine) schieben, was mit einem
angehängten "&" geschieht.

Eine Beispielsession sieht so aus:

   # dmshell
   Welcome!

   ext::help::reload &
   ext::books::reload &
   ext::map_tags::reload &
   ext::map_world::reload &
   print JSON::XS->new->pretty->encode({cf::mallinfo})

   > ext::map_world::reload &

   > 
   command: 'ext::map_world::reload'
   execution time: 0.0744819641113281

   > ext::map_tags::reload &

   > 
   command: 'ext::map_tags::reload'
   execution time: 1.14403510093689

   > $cf::PLAYER-{schmorp}

   command: '$cf::PLAYER-{schmorp}'
   execution time: 5.00679016113281e-06
   evaluation error: Bareword "schmorp" not allowed while "strict subs" in use at (eval 180) line 1, <GEN63> line 6.

   > $cf::PLAYER{schmorp}

   command: '$cf::PLAYER{schmorp}'
   execution time: 1.09672546386719e-05
   result:
   bless( {
       log_told => {},
       last_save => "32009728.5217925",
       rent => {
           last_online_check => "1200189659",
           last_offline_check => "1200189659",
           balance => "-0.737118053715676",
           apartment => {
              "/brest/apartments/brest_town_house" => undef,
              "/scorn/apartment/apartments" => undef
            }
         },
       hintmode => 0,
       npc_dialog_active => {}
     }, 'cf::player::wrap' )

   > 
   > "schmorp"->cf::player::find->ob->stats->hp

   command: '"schmorp"->cf::player::find->ob->stats->hp'
   execution time: 4.79221343994141e-05
   result:
   520

und so weiter... Das ist natürlich eine große Hilfe beim Administrieren
oder Debuggen, weil man sich die aktuellen Daten, die im Server geladen
sind, direkt ansehen kann.

Sehr angenehm ist es auch, direkt im Spielbetrieb Bugs zu fixen, indem man
einzelne Routinen direkt überschreibt:

   # cat /tmp/bugfix
   package cf;
   sub _can_merge {
      # neue merge-logik, vielleicht mit printf-style-debugging
   }
   1

   # dmshell
   > do "/tmp/bugfix"

So kann man im laufenden Betrieb schon sehr angenehm am Server arbeiten,
aber man muss sich jedesmal eine Shell ausdenken, sie implementieren, und
kann dennoch nur herumstochern.

Doch mit Coroutinen kann mehr wesentlich mehr...


=head1 Coroutinen

Mit Perl hat man prinzipiell zwei Methoden der
"Parallelverarbeitung": Coroutinen (teilen sich einen gemeinsamen
Adressraum, laufen aber nicht wirklich parallel) und Prozesse (haben
getrennte Adressräume, laufen aber parallel (mit entsprechender
Hardware)). Threads (gemeinsamer Adressraum und echte Parallelität)
werden von Perl nicht angeboten.

Gegenüber Prozessen hat man den Vorteil extrem einfacher Kommunikation
zwischen den einzelnen Instanzen. Beispielsweise implementiert der schon
genannte Webserver einen Schutz gegen segmentierte Downloads, indem er die
gerade heruntergeladenen URLs pro Klient in einem globalen Hash speichert:

   if ($DOWNLOADS{$url}{$clientid} >= 4) {
      # abort, zu viele Verbindungen
      return;
   }

   ++$DOWNLOADS{$url}{$clientid};

Mit mehreren Prozessen ist dies natürlich nicht so einfach.

Ein weiterer Vorteil von Coroutinen ist das stark vereinfachte Locking: es
gibt praktisch keine Race-Conditions, denn solange man nicht absichtlich
Rechenzeit abgibt, wird man auch nicht unterbrochen.

Aber wie hilft das beim Debuggen?

In einem ereignisgesteuerten Programm hat man meistens wenige Watcher
(z.B. einen pro TCP-Verbindung). Der aktuelle Zustand einer Verbindung
steht in irgendwelchen Variablen serialisiert.  Das kann entweder eine
Zustandsmaschine sein (entweder Ad-Hoc oder z.B. mit POE) oder auch
per Continuation-Style durch den auf den Watcher gebundenen Callback,
mit einigen lexikalischen Variablen, in die man garnicht so einfach
reinschauen kann.

Die ausgeführten Programmzeilen sind relativ uninteressant, das Programm
verbringt wohl die meiste Zeit in der Hauptschleife (z.B. C<EV::loop> oder
C<< Gtk->main >>), und Backtraces helfen garnicht ("steckt das Programm in
C<lese_von_socket> weil es noch auf den Header wartet oder ist es schon
beim Lesen des Request-Bodies? In welcher Variable steht der aktuelle
Zustand nochmal?").

Bei einem "herkömmlichen" - nicht ereignisgesteuertem - Programm ist
es viel einfacher: "Programm steckt in Zeile 231, da liest er gerade den
Header ein".

Und genau diese einfache Relation "Ort entspricht Zustand" erhält man mit
Coroutinen. Natürlich braucht man Unterstützung vom Laufzeitsystem, und diese
Hilfe kommt von...

=head1 Coro::Debug

Seit Version 4.0 gibt es in der Coro-Distribution das
C<Coro::Debug>-Modul.

Dieses implementiert nicht nur eine interaktive Shell (bzw. auch
Einzelteile, mit denen man das selbst tun kann), sondern auch eine
Übersicht über die Coroutinen, Backtraces und Aufruftraces.

=head2 Benutzung

Die einfachste Methode, um an eine Shell zu kommen, ist es, einen "UNIX
Socket Server" zu starten:

   use Coro::Debug;

   $CORO_DEBUGGER = new_unix_server Coro::Debug "/tmp/debug";

Und schon kann man sich mit F</tmp/debug> verbinden... Oder auch
nicht: Die bisherigen Beispiele benutzten TCP-Sockets, da konnte man
C<telnet> benutzen, aber wie macht man das mit UNIX Sockets, und
warum?

An dieser Stelle möchte ich herzlichst ein feines Werkzeug namens
C<socat> empfehlen, mit dem man sehr einfach Verbindungen zwischen zwei
Punkten schaffen kann, z.B. zwischen der Readline-Bibliothek und einer
UNIX Socket:

   socat readline unix:/tmp/debug

Und man hat - im Gegensatz zum Perl-Debugger - auch noch echtes Readline
:-> C<socat> kann übrigens auch anders, z.B. C<netcat> ersetzen: C<socat
readline tcp:127.0.0.1:80>. Oder einen UDP-Server implementieren: C<socat
system:mcookie udp-listen:676>. Oder einen einfachen Proxy, oder... es ist
sehr hilfreich!

Der Grund, eine UNIX Socket zu benutzena, ist der Sicherheitsaspekt: Um einen
TCP-Port zu schützen (die Shell macht ja keinerlei Authentifizierung)
braucht man schon einen Firewall, um eine UNIX Socket zu schützen
muss man sie nur in ein Verzeichnis legen auf das nur legitime
Benutzer/Programme Zugriff besitzen (F</tmp/debug> ist also ein schlechtes
Beispiel). Auf diese Weise kann man diese Shell relativ unbedenklich
immer aktiviert lassen (auch z.B. in der Produktionsumgebung):

   system "rm -rf /tmp/myprog";
   mkdir "/tmp/myprog", 0700 or die "/tmp/myprog: $!";
   $CORO_DEBUGGER = new_unix_server Coro::Debug "/tmp/myprog/debug";

Auf diese Weise haben nur diejenigen Zugriff auf den Prozess, die sowieso
Zugriff haben.

Und nun zu einigen der eingebaute Befehle (es gibt auch das
C<help>-Kommando, und alles, was nicht ein bekanntes Kommando ist, wird
als Perl-Ausdruck interpretiert):


=head2 "Prozessliste"

Mit dem C<ps>-Kommando erhält man eine Übersicht aller laufenden
Coroutinen, hier als Beispiel in einem laufenden Deliantra-Server:

   > ps
              PID SS  RSS USES Description             Where
         10289200 US 865k 830k [main::]                [/deliantra/ext/dm-support.ext:47]
         10289392 -- 2508   66 [coro manager]          [/opt/perl/lib/perl5/Coro.pm:177]
         10289712 -- 2508 2094 [unblock_sub scheduler] [/opt/perl/lib/perl5/Coro.pm:589]
         13776976 -- 2548   13 [EV idle process]       [/opt/perl/lib/perl5/Coro/EV.pm:65]
         18176656 -- 2964  53k timeslot manager        [/deliantra/cf.pm:397]
         23103792 --  19k  42k player scheduler        [/deliantra/ext/login.ext:510]
   46912554817888 -- 2980    1 follow handler          [/deliantra/ext/follow.ext:50]
         19457280 -- 138k 432k map scheduler           [/deliantra/ext/map-scheduler.ext:65]
         18681088 -- 3228 6312 music scheduler         [/deliantra/ext/player-env.ext:77]
         26391616 -- 2980  40k worldmap updater        [/deliantra/ext/item-worldmap.ext:114]
        140130800 --  16k 3746 [async_pool idle]       [/opt/perl/lib/perl5/Coro.pm:258]
        286210960 --  16k  22k [async_pool idle]       [/opt/perl/lib/perl5/Coro.pm:258]
        196084816 --  10k 1251 [async_pool idle]       [/opt/perl/lib/perl5/Coro.pm:258]
        439518192 -- 3268    2 addme init              [/deliantra/ext/login.ext:21]

Die C<PID> ist nichts anderes als die Addresse des Perl-Coroutinenobjektes
(C<$obj+0>). Die C<SS>-Spalte (State/Stack) gibt an, ob eine Coroutine
gerade läuft (rB<U>nning, B<R>eady oder weder noch), bzw. ob sie einen
eigenen C-Stack hat (B<S>) oder nicht (B<->), oder gerade getraced wird
(C<T>), mehr dazu später. C<RSS> ist der Speicherverbrauch der Coroutine
in Bytes. C<Uses> gibt an, wie oft die Coroutine Rechenzeit zugeteilt
bekommen bzw. wieder abgegeben hat.

Die C<Description>-Spalte gibt lediglich den Inhalt des C<desc>-Members
der Coroutinenstruktur wieder, den man einfach setzen kann:

   $Coro::current->{desc} = "login phase 1";
   ... tue etwas
   $Coro::current->{desc} = "login phase 2";
   ...

Die meisten Coroutinen setzen einfach einen Namen, manche ändern den
Namen je nach Ort, so daß man sofort sehen kann, in welchen "Zustand" die
Coroutine ist.

Und C<Where> schließlich gibt an, wo im Programm sich die Coroutine
gerade befindet (dabei nimmt sich C<Coro> selbst aus, sonst würde dort
fast immer nur C<Coro::Semaphore>, C<Coro::Signal> usw. auftauchen).

Der Server benutzt eine Menge Coroutinen (die meisten sind sehr
kurzlebig): Spieler regelmäßig speichern erledigt z.B. der C<player
scheduler>, der hier gerade in Zeile C<510> von C<login.ext> steckt:

   Coro::EV::timer_once $SCHEDULE_INTERVAL;

Das macht Sinn, da er nur alle paar Sekunden aktiv wird und den Rest der
Zeit schläft (in C<timer_once>).

Ein anderes Beispiel ist C<addme init>, was einen Teil des Login-Prozesses
darstellt. Zeile C<21> ist in einer Funktion C<query>, die den Benutzer
etwas fragt (naheligenderweise Name oder Passwort). Um mehr zu erfahren,
braucht man einen Backtrace:

=head2 Backtraces

Backtraces erhält man mit dem C<bt>-Kommando und der "PID" als Argument:

   > bt 439518192
   coroutine is at /deliantra/ext/login.ext line 21
           ext::login::query('cf::client::wrap=HASH(0x3d7dfb0)',
                             0, 'What is your name?\x{a}:')
              called at /deliantra/ext/login.ext line 208
           ext::login::__ANON__ called at -e line 0
           Coro::_run_coro called at -e line 0

Nicht nur sieht man sofort, was den Benutzer gefragt wird (weil C<query>
den Fragetext als Parameter übergeben bekommt), sondern man sieht auch,
wo im Login-Prozess man sich gerade befindet, nämlich in Zeile C<208>
(was innerhalb des C<on_addme>-Callbacks von Deliantra ist).

Noch mehr Informationen erhält man mit einem Aufruftrace:

=head2 Aufruftraces/Ablaufverfolgung

Zuerst sollte man den "Logging Level" in seiner Shell auf 5 oder höher schrauben:

   > loglevel 5

Dann kann man Aufruftraces mit C<tr> und C<ut> starten und stoppen:

   > tr 439518192
   2008-01-13Z04:03:28.1954 (5) [439518192] tracing enabled
   (timestanmps usf. im Folgenden gekürzt)
   .8374 (5) [pid] enter Coro::State::_cctx_init with (277569264)
   .8375 (5) [pid] leave Coro::State::_cctx_init returning ()
   .8375 (5) [pid] leave ext::login::query returning (schmorp)
   .8376 (5) [pid] enter ext::login::check_playing with (cf::client::wrap=HASH(0x3d7dfb0),name)
   .8376 (5) [pid] enter cf::player::find_active with (schmorp)
   .8376 (5) [pid] leave cf::player::find_active returning ()
   .8378 (5) [pid] enter cf::client::send_drawinfo with
                   (cf::client::wrap=HASH(0x3d7dfb0),Welcome name, please enter your password...,5)
   .8378 (5) [pid] leave cf::client::send_drawinfo returning ()
   .8379 (5) [pid] enter ext::login::query with (
                   cf::client::wrap=HASH(0x3d7dfb0),4,What is your password?\x{0a}:)
   .8380 (5) [pid] enter cf::client::query with (
                   cf::client::wrap=HASH(0x3d7dfb0),4,What is your password?\x{0a}:,CODE(0x6fca040))
   .8380 (5) [pid] leave cf::client::query returning ()

Bei diesem Tracing wird bei jedem Funktionsaufruf bzw. bei jeder Rückkehr
aus einer Funktion eine Zeile ausgegeben die Funktionsnamen, Argumente
bzw. Resultatsliste ausgibt.

Im Beispiel wurde die Ablaufverfolgung aktiviert, während der
Spiel-Klient noch in der Namensabfrage steckte (der Aufruf von
C<_cctx_init> ist ein Implementationsdetail von Coro, der das Starten
eines neuen Interpreters anzeigt, mehr dazu später). Konsequenterweise
sieht man daher nur die Rückkehr aus dem C<query>-Aufruf, mit dem Namen
als Resultat (C<schmorp>).

Danach schaut der Server nach, ob der User gerade spielt
(C<check_playing>), was wiederum C<find_active>) aufruft). Weil er nicht
spielt kann man mit dem Login fortfahren und nach dem Passwort fragen,
usf.

Es ist gut möglich, daß der Server während der Ausführung einer
Coroutine viele andere Dinge tut (wenn der Login-Callback den Spieler von
der Platte lädt, läuft der Server erstmal weiter, denn der Zugriff kann
durchaus mal eine Sekunde oder länger dauern, wenn z.B. gerade viel I/O
stattfindet). Da die Ablaufverfolgung nur für eine (die interessante)
Coroutine aktiviert ist, bekommt man auch nur für diese die Meldungen,
was ungemein hilfreich ist.

C<Coro> selbst unterstützt auch eine zeilenweise Ablaufverfolgung
ähnlich wie im Perl-Debugger, es gibt jedoch noch kein Kommando um dieses
zu aktivieren (ich hab's schlicht noch nie vermisst). Wenn man sich das
C<Coro::Debug>-Modul ansieht, sieht man such, daß man seine eigenen
Trace-Callbacks definieren kann und damit recht viele Tricks möglich
sind.

=head3 "printf-debugging"

Die Ablaufverfolgung benutzt die C<Coro::Debug::log $loglevel,
$msg>-Funktion zum ausgeben der Meldungen, mit der man auch eigene Meldungen ausgeben kann,
wahlweise auch nur wenn Tracing aktiviert ist:

   Coro::Debug::log 6, "some log message"
      if $Coro::current->is_traced;

(Vielleicht sollte die nächste Version von Coro::Debug einen
coroutinen/shellabhängigen Loglevel anbieten...)

=head3 Automatische Aktivierung

Die Ablaufverfolgung kann man auch progrrammatisch aktivieren, z.B. wenn
die Coroutine kurzlebig ist oder man unbedingt den Anfang mitkriegen
möchte:

   Coro::Debug::trace;
   # ab hier wird getraced

   Coro::Debug::untrace;
   # ab hier nicht mehr, boa!

=head3 Problemchen

Ablaufverfolgung geht nicht mit allen Coroutinen:

        PID SS  RSS USES Description  Where
   10289200 US 865k 926k [main::]     [/deliantra/ext/dm-support.ext:47]

   > coro tr 10289200
   2008-01-13Z04:33:58.7787 (5) [123282976] unable to enable tracing:
      cannot enable tracing on coroutine with custom stack
      at /opt/perl/lib/perl5/Coro/Debug.pm line 205, <GEN88> line 2.

Der Grund liegt in der Implementation: Sowohl der Perl-Debugger als auch
Coro müssen eine andere Implementation des Interpreters verwenden, der
langsamer läuft, aber den Ablauf verfolgen kann. Wie also kann man diese
mit Coro an- oder abschalten?

Coro arbeitet, indem jede Coroutine quasi ihren eigenen (abgespeckten)
Interpreter verpasst bekommt. Damit der Speicherverbrauch gering und
vor allem die Geschwindigkeit hoch sind, teilt Coro verschiedenen
Coroutinen nach Möglichkeit den gleichen Interpreter zu. Dies ist
genau dann möglich, wenn sich die Coroutine in der äußersten
Interpreterschleife befindet (d.h. keine rekursiven Aufrufe gemacht
wurden. Ein rekursiver Aufruf findet statt, wenn man eine C/XS-Funktion
aufruft und diese wiederum Perl, was z.B. bei fast allen Callback-Systemen
vorkommt). Außerdem hat das Hautprogramm immer seinen eigenen
Interpreter.

Genau dies sieht man im rechten Teil der C<SS>-Spalte: Tracing kann
nur dann aktiviert werden, wenn dort ein C<-> steht, und auch nur dann
deaktiviert werden, wenn die Coroutine während des Tracens keine
rekursiven Mätzchen macht.

In der Praxis ist das kein Problem: man kann ja einfach alles in eine
Coroutine verlegen und das Hauptprogramm schlafenlegen, oder das Tracing
aktivieren (z.b. programmatisch), bevor man beispielsweise in die
Event-Schleife springt: Das verlangsamt die Ausführung zwar, aber nicht
sehr (einige Prozent).

=head2 Code-Injection

Manchmal kann es recht hilfreich sein, einer Coroutine etwas Code
unterzujubeln. Auf diese Weise kann man z.B. Backtraces erhalten:

   > eval 277575488 Carp::cluck "holladrio"

Oder man kann auf lokale Variablen zugreifen (z.B. mit dem
C<PadWalker>-Modul).

Das Ganze geht auch programmatisch:

   $coro->eval ("string");
   $coro->call (sub { ... });
 
Und es funktioniert sogar, wenn die Coroutine sich in einem XS-Aufruf
befinden sollte.


=head1 Ausblick

C<Coro::Debug> ist recht neu und die sich ergebenden Möglichkeiten noch
nicht wirklich ausgelotet. Ich denke, daß es aber jetzt schon sehr
hilfreiche Mittel zum Debugging zur Verfügung stellt.

Ich hoffe auch, ich konnte ein paar Anregungen zum Thema "jedes
Perl-Programm braucht eine interaktive Shell" zu liefern: Es ist
wirklich hilfreich, und mit Perl (mit oder ohne Coro) sehr einfach zu
implementieren.

=head1 Autor

Marc Lehmann <schmorp@schmorp.de>.

=head1 Anhang: dumpval

Wen's interessiert, ich verwende die folgende "dumpval"-Funktion schon
seit vielen Jahren, und sie gibt recht lesbare Debug-Dumps:

   # dumpval $ref

   sub dumpval {
      eval {
         local $SIG{__DIE__};
         my $d;
         $d = new Data::Dumper([$_[0]], ["*var"]);
         $d->Terse(1);
         $d->Indent(2);
         $d->Quotekeys(0);
         $d->Useqq(1);
         #$d->Bless(...);
         $d->Seen($_[1]) if @_ > 1;
         $d = $d->Dump();
         $d =~ s/([\x00-\x07\x09\x0b\x0c\x0e-\x1f])/sprintf "\\x%02x", ord($1)/ge;
         $d
      } || "[unable to dump $_[0]: '$@']";
   }

Früher habe ich mal Dumpvalue benutzt, ist auch nicht schlecht (das
PApp::Catch_STDOUT ist ein Hack, den man in neueren Perls durch PerlIO
ersetzen kann):

   sub dumpval {
      eval {
         local $SIG{__DIE__};
         my $d;
         local *STDOUT;
         local *PApp::output;
         tie *STDOUT, PApp::Catch_STDOUT;

         require Dumpvalue;
         $d = new Dumpvalue globPrint => 1, compactDump => 0, veryCompact => 0;
         $d->dumpValue($_[0]);
         $d = $PApp::output;
         $d =~ s/([\x00-\x07\x09\x0b\x0c\x0e-\x1f])/sprintf "\\x%02x", ord($1)/ge;
         $d;
      } || "[unable to dump $_[0]: '$@']";
   }

Revision:	1.9
Committed:	Mon Jan 21 11:12:49 2008 UTC (18 years, 8 months ago) by root
Branch:	MAIN
CVS Tags:	HEAD
Changes since 1.8:	+1 -1 lines
Log Message:	* empty log message *