ViewVC Help
View File | Revision Log | Show Annotations | Download File
/cvs/cvsroot/docs/corodebug.pod
Revision: 1.2
Committed: Sun Jan 13 05:31:11 2008 UTC (18 years, 8 months ago) by root
Branch: MAIN
Changes since 1.1: +301 -3 lines
Log Message:
*** empty log message ***

File Contents

# User Rev Content
1 root 1.1 =head1 NAME
2    
3     Debuggen mit Coroutinen
4    
5     =head1 Einführung
6    
7     Im Laufe der Jahre habe ich eine ganz eigene Methode zum Debuggen
8     meiner Programme entwickelt. Diese Methode kombiniert einige Konzepte
9     (interkative Shell in jedem Programm, Coroutinen), die mehr als reines
10     Debugging ermöglichen.
11    
12     Diese Methode möchte ich hiermit vorstellen, vielleicht bringt sie
13     den einen oder andreen auf Gedanken oder stellt sich gar als nützlich
14     heraus...
15    
16     =head1 "Traditionelle" Debugging-Methoden
17    
18     Nun, es gibt den Perl-Debugger; über diesen wird tatsächlich viel
19     erzählt und geschrieben, und ich nehme an, er wird wirklich häufig
20     benutzt. Aber aus welchen Gründen auch immer, ich konnte mich mit ihm
21     (anders als mit gdb) nie wirklich anfreunden: die einzige Funktion, die
22     ich mit einiger Regelmäßigkeit benutze, ist die Trace-Funktion. Das kann
23     ich sogar als "Fest im Gehirn eingebautes Makro" sofort tippen: "perl -d
24     xxx, dann t, dann c", andere Debugger-Befehle kenne ich nicht.
25    
26     Diese Trace-Funktion hat aber viele Nachteile: sie macht das Programm sehr
27     langsam, sie funktioniert nur, während man im Debugger ist, und häufig
28     hängt mein Programm aus nicht nachvollziehbaren Gründen, und die Ausgabe
29     ist zu umfangreich. Die Hauptnachteile sind aber, daß man den Debugger
30     nicht ein- oder ausschalten kann und daß er interaktiv arbeitet.
31    
32     Die Mehrheit meiner Programme sind langlebige Hintergrundprogramme. Diese
33     sind immerhin so gut getestet, daß sie in Produktion selten Probleme
34     entwickeln, aber manchmal kommt das natürlich vor. Das erklärt
35     wahrscheinlich, weshalb ich den Perl-Debugger nicht benutze: man kann den
36     Perl-Debugger (meines Wissens) nicht an bestehende Prozesse attachen, man
37     kann die Programme nicht dauerhaft unter dem Debugger starten und man hat
38     im Allgemeinen auch keinen interkativen Zugang.
39    
40     Startet man das Programm neu (z.B. nach Einbau einiger warn-statements
41     oder um es unter dem Debugger laufen zu lassen) tritt das Problem häufig
42     nicht mehr auf.
43    
44     Hinzu kommt, daß viele meiner Programme stark Ereignisgesteuert
45     arbeiten: Hält man das Programm an, gibt es unerwünschte Timeouts;
46     erstellt man einen Trace, springt dieser wild zwischen Programmteilen hin-
47     und her, die nichts miteinander zu tun haben.
48    
49     Als einzige Möglichkeit (die auch häufig implementiert wird), bleibt
50     häufig nur, extrem viel mitzuloggen, so daß man im Fehlerfall zumindest
51     auf eine Art Trace zurückgreifen kann. Natürlich sind die schweren
52     Fehler selten dort, wo man gerade viel mitloggt.
53    
54     =head1 Die Entwicklung eines anderen Ansatzes
55    
56     =head2 Die Anfänge: ein Webserver
57    
58     Um das Jahr 2000 herum schrieb ich einen Web-Server, der vollkommen
59     Event-gesteuert war (buchstäblich: er benutzte das Event-Modul dazu).
60    
61     Weil es so einfach war, bekam er bald eine interaktive Shell verpasst:
62    
63     sub shell {
64     my $fh = shift;
65    
66     while (defined (print $fh "cmd> "), $_ = <$fh>) {
67     s/\015?\012$//;
68    
69     # bearbeite Kommandos
70     }
71     }
72    
73     my $port = new Coro::Socket
74     LocalPort => $CMDSHELL_PORT,
75     ReuseAddr => 1,
76     Listen => 1,
77     or die "unable to bind cmdshell port: $!";
78    
79     push @listen_sockets, $port;
80    
81     async {
82     while () {
83     async \&shell, scalar $port->accept;
84     }
85     };
86    
87     Der Code benutzt Coroutinen, sollte aber einfach verständlich
88     sein: C<Coro::Socket> ist das Pendant zu C<IO::Socket>, bei dem Aufrufe
89     wie C<accept> die anderen coroutinen nicht blockieren; die Funktion
90     C<async> startet eine neue ("asynchrone") Coroutine für jedes neue
91     Verbindung, und die C<shell>-Funktion schließlich liest in einer Schleife
92     Befehle von der Socket und führt sie aus.
93    
94     Ursprünglich dazu gedacht, eine Liste von aktiven Verbindungen zu
95     erhalten bzw. bisweilen IP-Adressen zu blockieren, hatte ich irgendwann
96     eine offensichtliche aber doch nicht so offensichtliche idee:
97    
98     } elsif ($cmd eq "print") {
99     my @res = eval $_;
100     print $fh "eval: $@\n" if $@;
101     print $fh "RES = ", (join " : ", @res), "\n";
102    
103     Mit dem "print"-Kommando (eigentlich wäre "eval" ein besserer Name)
104     lassen sich erstaunlich viele Dinge erledigen:
105    
106     Erlaube 200 gleichzeitige Verbindungen mehr:
107    
108     print $conn::connections->adjust (200)
109    
110     Setze die Downloadrate auf 1MB/s:
111    
112     print $conn::tbf_top->{rate} = 1e6
113    
114     Erlaube 20 gleichzeitige Downloads mehr:
115    
116     print $conn::queue_file->{slots} += 20
117    
118     Das erste Beispiel benutzt die korrekte "API" zum anpassen einer
119     Semaphore, dei beiden letzteren Beispiele sind eigentlich "böse
120     Hacks" weil der Code diese Möglichkeit der Anpassung nicht explizit
121     unterstützt, sie funktionieren aber trotzdem.
122    
123     Auf diese Weise läßt sich bisweilen auch debuggen: wenn z.B. eine
124     Verbindung hängt, kann man versuchen, sie zu finden und dann versuchen,
125     herauszufinden, woran es liegt, indem man sich verschiedene globale
126     Variablen anschaut oder kleine "Suchprogramme" mit C<print do "dateiname">
127     ausführt.
128    
129     Das kann eine extreme Hilfe sein, ist aber immer noch recht umständlich.
130    
131     =head2 Perl ist besser als jede Shell: Deliantra
132    
133     Der Deliantra-Server (ein MORPG) ist ebenfalls vollkommen
134     Ereignisgesteuert und besitzt ebenfalls eine Shell, die (fast) ohne
135     Coroutinen auskommt:
136    
137     sub tcp_serve($) {
138     my ($fh) = @_;
139    
140     binmode $fh, ":raw:perlio:utf8";
141     print $fh "\n> ";
142    
143     my $iow; $iow = EV::io $fh, EV::READ, sub {
144     if (defined (my $cmd = <$fh>)) {
145     $cmd =~ s/\s+$//;
146    
147     if ($cmd =~ /^\s*exit\b/i) {
148     print $fh "will not exit() server.\n";
149    
150     # andere befehle
151     }
152     };
153     }
154    
155     our $LISTENER;
156    
157     # now a shell listening on a tcp-port - let the firewall decide access rights
158     if ($cf::CFG{perl_shell}) {
159     if (my $listen = new IO::Socket::INET LocalAddr => $cf::CFG{perl_shell}, Listen => 1, ReuseAddr => 1, Blocking => 0) {
160     $LISTENER = EV::io $listen, EV::READ, sub { tcp_serve $listen->accept };
161     }
162     }
163    
164     Deliantra benutzt EV als Event-Bibliothek, ansonsteb habe ich aus meinen
165     früheren Versuchen gelernt und implementiere keine Kommandos mehr direkt,
166     sondern erlaube direkt die Eingabe von Perl-Ausdrücken:
167    
168     ...
169     } else {
170     my $sub = sub {
171     package cf;
172     select $fh;
173    
174     # compile first, then execute, as Coro does not support switching in eval string
175     my $cb = eval "sub { $cmd \n}";
176    
177     my $t1 = Time::HiRes::time;
178     my @res = $@ ? () : eval { $cb->() };
179     my $t2 = Time::HiRes::time;
180    
181     print "\n",
182     "command: '$cmd'\n",
183     "execution time: ", $t2 - $t1, "\n";
184     warn "evaluation error: $@" if $@;
185     print "evaluation error: $@\n" if $@;
186     print "result:\n", cf::dumpval @res > 1 ? \@res : $res[0] if @res;
187     print "\n> ";
188    
189     select STDOUT;
190     };
191    
192     if ($cmd =~ s/\s*&$//) {
193     cf::async {
194     $Coro::current->desc ($cmd);
195     $sub->()
196     };
197     } else {
198     $sub->();
199     }
200    
201     Die Befehlsausführung ist weitaus komplexer: Zuerst wird die eingegebene
202     Zeile kompilziert und dann evaluiert. Danach wird das Ergebnis, etwaige
203     Laufzeitfehler und die Ausführungszeit ausgegeben.
204    
205     Da man als Administrator manchmal Befehle im "Hauptprogramm" (die
206     Coroutine, die die Event-Schleife ausführt) ausführen muss, der Server
207     aber all 120ms ein update generieren muss, muss man lang dauernde Befehle
208     in den "Hintergrund" (eine weitere Coroutine) schieben, was mit einem
209     angehängten "&" geschieht.
210    
211     Eine Beispielsession sieht so aus:
212    
213     # dmshell
214     Welcome!
215    
216     ext::help::reload &
217     ext::books::reload &
218     ext::map_tags::reload &
219     ext::map_world::reload &
220     print JSON::XS->new->pretty->encode({cf::mallinfo})
221    
222     > ext::map_world::reload &
223    
224     >
225     command: 'ext::map_world::reload'
226     execution time: 0.0744819641113281
227    
228     > ext::map_tags::reload &
229    
230     >
231     command: 'ext::map_tags::reload'
232     execution time: 1.14403510093689
233    
234     > $cf::PLAYER-{schmorp}
235    
236     command: '$cf::PLAYER-{schmorp}'
237     execution time: 5.00679016113281e-06
238     evaluation error: Bareword "schmorp" not allowed while "strict subs" in use at (eval 180) line 1, <GEN63> line 6.
239    
240     > $cf::PLAYER{schmorp}
241    
242     command: '$cf::PLAYER{schmorp}'
243     execution time: 1.09672546386719e-05
244     result:
245     bless( {
246     log_told => {},
247     last_save => "32009728.5217925",
248     rent => {
249     last_online_check => "1200189659",
250     last_offline_check => "1200189659",
251     balance => "-0.737118053715676",
252     apartment => {
253     "/brest/apartments/brest_town_house" => undef,
254     "/scorn/apartment/apartments" => undef
255     }
256     },
257     hintmode => 0,
258     npc_dialog_active => {}
259     }, 'cf::player::wrap' )
260    
261     >
262     > "schmorp"->cf::player::find->ob->stats->hp
263    
264     command: '"schmorp"->cf::player::find->ob->stats->hp'
265     execution time: 4.79221343994141e-05
266     result:
267     520
268    
269     und so weiter... Das ist natürlich eine große Hilfe beim Administrieren
270     oder Debuggen, weil man sich die aktuellen Daten die im server geladen
271     sind direkt ansehen kann.
272    
273     Sehr angenehm ist es auch, direkt im Spielbetrieb Bugs zu fixen, indem man
274     einzelne Routinen direkt überschreibt:
275    
276     # cat /tmp/bugfix
277     package cf;
278     sub _can_merge {
279     # neue merge-logik, vielleicht mit printf-style-debugging
280     }
281     1
282    
283     # dmshell
284     > do "/tmp/bugfix"
285    
286     So kann man im laufenden Betrieb schon sehr angenehm am Server arbeiten,
287     aber man muss sich jedesmal eine Shell ausdenken, sie implementieren, und
288     kann dennoch nur herumstochern.
289    
290     Doch mit Coroutinen kann mehr wesentlich mehr...
291    
292    
293     =head1 Coroutinen
294    
295     Mit Perl hat man prinzipiell zwei Methoden der
296     "parallelverarbeitung": Coroutinen (teilen sich einen gemeinsamen
297     Adressraum, laufen aber nicht wirklich parallel) und Prozesse (haben
298     getrennte Adressräume, laufen aber parallel (mit entsprechender
299     Hardware)). Threads (gemeinsamer Adressraum und echte Parallelität)
300     werden von Perl nicht angeboten.
301    
302 root 1.2 Gegenüber Prozessen hat man den Vorteil extrem einfacher Kommunikation
303     zwischen den einzelnen Instanzen, beispielsweise implementiert der schon
304     genannte Webserver einen Schutz gegen segmentierte Downloads, indem er die
305     gerade heruntergeladenen URLs pro Klient in einem globale Hash speichert:
306 root 1.1
307     if ($DOWNLOADS{$url}{$clientid} >= 4) {
308     # abort, zu viele Verbindungen
309     return;
310     }
311    
312     ++$DOWNLOADS{$url}{$clientid};
313    
314 root 1.2 Mit mehreren Prozessen ist dies natürlich nicht so einfach.
315    
316     Ein weitere Vorteil von Coroutinen ist das stark verinfachte Locking: es
317     gibt praktisch keine Race-conditions, denn solange man nicht absichtlich
318     Rechenzeit abgibt.
319    
320     Aber wie hilft das beim Debuggen?
321    
322     In einem ereignisgesteuerten Programm hat man meistens wenige Watcher
323     (z.B. einen pro TCP-Verbindung). Der aktuelle Zustand einer Verbindung
324     steht in irgendwelchen Variablen serialisiert. Das kann entweder eine
325     Zustandsmaschine sein (entweder Ad-Hoc oder z.B. mit POE) oder auch
326     per Continuation-Style durch den auf den Watcher gebundenen Callback,
327     mit einigen lexikalischen Variablen, in die man garnicht so einfach
328     reinschauen kann.
329    
330     Die ausgeführten Programmzeilen sind relativ uninteressant, das Programm
331     verbringt wohl die meiste Zeit in der Hauptschleife (z.B. C<EV::loop> oder
332     C<< Gtk->main >>), und Backtraces helfen garnicht ("steckt das Programm in
333     C<lese_von_socket> weil es noch auf den Header wartet oder ist es schon
334     beim Lesen des Request-Bodies?").
335    
336     Bei einem "herkömmlichen" - nicht ereigenisgesteuerten - Programm ist
337     es viel einfacher: "Programm steckt in Zeile 231, da liest er gerade den
338     Header ein".
339    
340     Und genau das kriegt man mit Coroutinen. Natürlich braucht man Hilfe vom
341     Laufzeitsystem, und diese Hilfe kommt von...
342    
343 root 1.1 =head1 Coro::Debug
344    
345 root 1.2 Seit Version 4.0 gibt es in der Coro-Distribution das
346     C<Coro::Debug>-Modul.
347    
348     Dieses implementiert nicht nur eine interaktive Shell (bzw. auch
349     Einzelteile, mit denen man das selbst tun kann), sondern auch eine
350     Übersicht über die Coroutinen, Backtraces und Aufruftraces.
351    
352     =head2 Benutzung
353    
354     Die einfachste Methode, um an eine Shell zu kommen, ist es, einen "UNIX
355     Socket Server" zu starten:
356    
357     use Coro::Debug;
358    
359     $CORO_DEBUGGER = new_unix_server Coro::Debug "/tmp/debug";
360    
361     Und schon kann man sich mit F</tmp/debug> verbinden... Oder auch
362     nicht: Die bisherigen Beispiele benutzen TCP-Sockets, da konnte man
363     C<telnet> benutzen, aber wie macht man das mit UNIX Sockets, und
364     warum?
365    
366     An dieser Stelle möchte ich herzlichst ein feines Werkzeug namens
367     C<socat> empfehlen, mit dme man sehr einfach Verbindungen zwischen zwei
368     Punkten schaffen kann, z.B. zwischen der Readline-Bibliothek und einer
369     UNIX Socket:
370    
371     socat readline unix:/tmp/debug
372    
373     Und man hat, im Gegensatz zum Perl-Debugger, auch noch echtes Readline
374     :-> C<socat> kann übrigens auch anders, z.B. C<netcat> ersetzen: C<socat
375     readline tcp:127.0.0.1:80>. Oder einen UDP-Server implementieren: C<socat
376     system:mcookie udp-listen:676>. Sehr hilfreich!
377    
378     Der Grund eine UNIX Socket zu benutzen ist der Sicherheitsaspekt: Um einen
379     TCP-Port zu schützen (die Shell macht ja keinerlei sicherheitsabfrage)
380     braucht man schon einen Firewall, um eine UNIX Socket zu schützen
381     muss man sie nur in ein Verzeichnis legen auf das nur legitime
382     Benutzer/Programme Zugriff besitzen (F</tmp/debug> ist also ein schlechtes
383     Beispiel). Auf diese Weise kann man diese Shell relativ unbedenklich
384     immer aktiv lassen (z.B. in der Produktionsumgebung):
385    
386     system "rm -rf /tmp/myprog";
387     mkdir "/tmp/myprog", 0700 or die "/tmp/myprog: $!";
388     $CORO_DEBUGGER = new_unix_server Coro::Debug "/tmp/myprog/debug";
389    
390     Auf diese Weise haben nur diejenigen Zugriff auf den Prozess, die sowieso
391     Zugriff haben.
392    
393     =head2 "Prozessliste"
394    
395     Mit dem C<ps>-Kommando erhält man eine Übersicht aller laufenden
396     Coroutinen, hier als Beispiel in eine laufenden Deliantra-Server:
397    
398     > ps
399     PID SS RSS USES Description Where
400     10289200 US 865k 830k [main::] [/deliantra/ext/dm-support.ext:47]
401     10289392 -- 2508 66 [coro manager] [/opt/perl/lib/perl5/Coro.pm:177]
402     10289712 -- 2508 2094 [unblock_sub scheduler] [/opt/perl/lib/perl5/Coro.pm:589]
403     13776976 -- 2548 13 [EV idle process] [/opt/perl/lib/perl5/Coro/EV.pm:65]
404     18176656 -- 2964 53k timeslot manager [/deliantra/cf.pm:397]
405     23103792 -- 19k 42k player scheduler [/deliantra/ext/login.ext:510]
406     46912554817888 -- 2980 1 follow handler [/deliantra/ext/follow.ext:50]
407     19457280 -- 138k 432k map scheduler [/deliantra/ext/map-scheduler.ext:65]
408     18681088 -- 3228 6312 music scheduler [/deliantra/ext/player-env.ext:77]
409     26391616 -- 2980 40k worldmap updater [/deliantra/ext/item-worldmap.ext:114]
410     140130800 -- 16k 3746 [async_pool idle] [/opt/perl/lib/perl5/Coro.pm:258]
411     286210960 -- 16k 22k [async_pool idle] [/opt/perl/lib/perl5/Coro.pm:258]
412     196084816 -- 10k 1251 [async_pool idle] [/opt/perl/lib/perl5/Coro.pm:258]
413     439518192 -- 3268 2 addme init [/deliantra/ext/login.ext:21]
414    
415     Die C<PID> ist nichts anderes als die Addresse des Perl-Coroutinenobjektes
416     (C<$obj+0>). Die C<SS>-Spalte (State/Stack) gibt an, ob eine Coroutine
417     gerade läuft (rB<U>nning, B<R>eady oder weder noch), bzw. ob sie einen
418     eigenen C-Stack hat (B<S>) oder nicht (B<->), oder gerade getraced wird
419     (C<T>), mehr dazu später. C<RSS> ist der Speicherverbrauch der Coroutine
420     in Bytes. C<Uses> gibt an, wie oft die Coroutine Rechenzeit zugeteilt bzw.
421     wieder abgegeben hat.
422    
423     Die C<Description>-Spalte gibt lediglich den Inhalt des C<desc>-Members
424     der Coroutinenstruktur wieder, den man einfach setzen kann:
425    
426     $Coro::current->{desc} = "login phase 1";
427     ... tue etwas
428     $Coro::current->{desc} = "login phase 2";
429     ...
430    
431     Die meisten Coroutinen setzen einfach einen Namen, manche ändern den
432     Namen je nach Ort, so daß man sofort sehen kann, in welchen "Zustand" die
433     Coroutine ist.
434    
435     Der Server benutzt eine Menge Coroutinen (die meisten sind sehr
436     kurzlebig): Spieler regelmäßig speichern erledigt z.B. der C<player
437     scheduler>, der hier gerade in Zeile C<510> von C<login.ext> steckt:
438    
439     Coro::EV::timer_once $SCHEDULE_INTERVAL;
440    
441     Das macht Sinn, da er nur alle paar Sekunden aktiv wird und den Rest der
442     Zeit schläft.
443    
444     Ein anderes Beispiel ist C<addme init>, was ein Teil des Login-Prozesses
445     darstellt. Zeile C<21> ist in einer Funktion C<query>, die den Benutzer
446     etwas frägt (naheligenderweise Name oder Passwort). Um mehr zu erfahren,
447     braucht man einen Backtrace:
448    
449     =head2 Backtraces
450    
451     Backtraces erhält man mit dem C<bt>-Kommando und der "PID" als Argument:
452    
453     > bt 439518192
454     coroutine is at /deliantra/ext/login.ext line 21
455     ext::login::query('cf::client::wrap=HASH(0x3d7dfb0)',
456     0, 'What is your name?\x{a}:')
457     called at /deliantra/ext/login.ext line 208
458     ext::login::__ANON__ called at -e line 0
459     Coro::_run_coro called at -e line 0
460    
461     Nicht nur sieht man sofort, was den Benutzer gefragt wird (weil C<query>
462     den Fragetext als Parameter übergeben bekommt), sondern man sieht auch,
463     wo im Login-Prozess man sich gerade befindet, nämlich in Zeile C<208>
464     (was innerhalb des C<on_addme>-Callbacks von Deliantra ist).
465    
466     Noch mehr Informationen erhält man mit einem Aufruftrace:
467    
468     =head2 Aufruftraces/Ablaufverfolgung
469    
470     Zuerst sollte man den "Logging Level" in seiner Shell auf 5 oder höher schrauben:
471    
472     > loglevel 5
473    
474     Dann kann man Aufruftraces mit C<tr> und C<ut> starten und stoppen:
475    
476     > tr 439518192
477     2008-01-13Z04:03:28.1954 (5) [439518192] tracing enabled
478     (timestanmps usf. im Folgenden gekürzt)
479     .8374 (5) [pid] enter Coro::State::_cctx_init with (277569264)
480     .8375 (5) [pid] leave Coro::State::_cctx_init returning ()
481     .8375 (5) [pid] leave ext::login::query returning (schmorp)
482     .8376 (5) [pid] enter ext::login::check_playing with (cf::client::wrap=HASH(0x3d7dfb0),name)
483     .8376 (5) [pid] enter cf::player::find_active with (schmorp)
484     .8376 (5) [pid] leave cf::player::find_active returning ()
485     .8378 (5) [pid] enter cf::client::send_drawinfo with
486     (cf::client::wrap=HASH(0x3d7dfb0),Welcome name, please enter your password...,5)
487     .8378 (5) [pid] leave cf::client::send_drawinfo returning ()
488     .8379 (5) [pid] enter ext::login::query with (
489     cf::client::wrap=HASH(0x3d7dfb0),4,What is your password?\x{0a}:)
490     .8380 (5) [pid] enter cf::client::query with (
491     cf::client::wrap=HASH(0x3d7dfb0),4,What is your password?\x{0a}:,CODE(0x6fca040))
492     .8380 (5) [pid] leave cf::client::query returning ()
493    
494     Bei diesem Tracing wird bei jedem Funktionsaufruf bzw. bei jeder Rückkehr
495     aus einer Funktion eine Zeile ausgegeben die Funktionsnamen, Argumente
496     bzw. Resultatsliste ausgibt.
497    
498     Im Beispiel wurde die Ablaufverfolgung aktiviert, während der
499     Spiel-Klient noch in der Namensabfrage steckte (der Aufruf von
500     C<_cctx_init> ist ein Implementationsdetail von Coro, der das Starten
501     eines neuen Interpreters anzeigt, mehr dazu später). Konsequenterweise
502     sieht man daher nur die Rückkehr aus dem C<query>-Aufruf, mit dem Namen
503     als Resultat (C<schmorp>).
504    
505     Danach schaut der Server nach, ob der User gerade spielt
506     (C<check_playing), was wiederum C<find_active>) aufruft). Weil er nicht
507     spielt kann man mit dem Login fortfahren und nach dem Passwort Fragen,
508     usf.
509    
510     Es ist gut möglich, daß der Server während der Ausführung einer
511     Coroutine viele andere Dinge tut (wenn der Login-Callback den Spieler von
512     der Platte lädt, läuft der Server erstmal weiter, denn der Zugriff kann
513     durchaus mal eine Sekunde oder länger dauern, wenn z.B. gerade viel I/O
514     stattfindet). Da die Ablaufvergolgung nur für eine (die interessante)
515     Coroutine aktiviert ist, bekommt man auch nur für diese die Meldungen,
516     was ungemein hilfreich ist.
517    
518     C<Coro> selbst untertsützt auch Zeilenweise Ablaufverfolgung, es gibt
519     jedoch noch kein Kommando um dieses zu aktivieren (ich habs noch nie
520     gebraucht). Wenn man sich das C<Coro::Debug>-Modul ansieht, sieht man
521     such, daß man seine eigenen Trace-Callbacks definieren kann und damit
522     recht viele Tricks möglich sind.
523    
524     =head3 "printf-debugging"
525    
526     Die Ablaufverfolgung benutzt die C<Coro::Debug::log $loglevel,
527     $msg>-Funktion zum Ausgeben der Meldungen, mit der man auch eigene Meldungen ausgeben kann,
528     wahlweise auch nur wenn Tradcing aktiviert ist:
529    
530     Coro::Debug::log 6, "some log message"
531     if $Coro::current->is_traced;
532    
533     (Vielleicht sollte die nächste Version von Coro::Debug einen
534     coroutinenabhängigen Loglevel anbieten...)
535    
536     =head3 Automatische Aktivierung
537    
538     Die Ablaufverfolgung kann man auch progrrammatisch aktivieren, z.B. wenn die Coroutine kurzlebig ist oder
539     man unbedignt den Anfang mitkriegen möchte:
540    
541     Coro::Debug::trace;
542     # ab hier wird getraced
543    
544     Coro::Debug::untrace;
545     # ab hier nicht mehr, boa!
546    
547     =head3 Problemchen
548    
549     Ablaufverfolgung geht nicht mit allen Coroutinen:
550    
551     PID SS RSS USES Description Where
552     10289200 US 865k 926k [main::] [/deliantra/ext/dm-support.ext:47]
553    
554     > coro tr 10289200
555     2008-01-13Z04:33:58.7787 (5) [123282976] unable to enable tracing:
556     cannot enable tracing on coroutine with custom stack
557     at /opt/perl/lib/perl5/Coro/Debug.pm line 205, <GEN88> line 2.
558    
559     Der Grund liegt in der Implementation: Sowohl der Perl-Debugger als auch
560     Coro müssen eine andere Implementation des Interpreters verwenden, der
561     langsamer läuft, aber den Ablauf verfolgen kann. Wie also kann man diese
562     mit Coro an- oder abschalten?
563    
564     Coro arbeitet, indem jede Coroutine quasi ihren eigenen (abgespeckten)
565     Interpreter verpasst bekommt. Damit der Speicherverbrauch gering und
566     vor allem die Geschwindigkeit hoch sind, teilt Coro verschiedenen
567     Coroutinen ihren eigenen Interpreter zu, sofern dies möglich ist. Dies
568     ist genau dann möglich, wenn sich die Coroutine in der äußersten
569     Interpreterschleife befindet (d.h. keine rekursiven Aufrufe gemacht
570     wurden. Ein rekursiver Aufruf findet statt, wenn man eine C/XS-Funktion
571     aufruft und diese wiederum Perl, was z.B. bei fast allen Callback-Systemen
572     vorkommt). Außerdem hat das Hautprogramm immer seinen eigenen
573     Interpreter.
574    
575     Genau dies sieht man im rechten Teil der C<SS>-Spalte: Tracing kann
576     nur dann aktiviert werden, wenn dort ein C<-> steht, und auch nur dann
577     deaktiviert werden, wenn die Coroutine während des Tracens keine
578     rekursiven Mätzchen macht.
579    
580     In der Praxis ist das kein Problem: man kann ja einfach alles in eine
581     Coroutine verlegen und das Hauptprogramm schlafenlegen, oder das Tracing
582     aktivieren (z.b. programmatisch), bevor man z.B. in die Event-Schleife
583     springt: Das verlangsamt die Ausführung zwar, aber nicht sehr (einige
584     Prozent).
585    
586     =head2 Code-Injection
587    
588     Manchmal kann es recht hilfreich sein, einer Coroutine etwas Code
589     unterzujubeln. Auf diese Weise kann man z.B. Backtraces erhalten:
590    
591     > eval 277575488 Carp::cluck "holladrio"
592    
593     Oder man kann auf lokale Variablen zugreifen (z.B. mit dem
594     C<PadWalker>-Modul).
595    
596     Das ganze geht auch programmatisch:
597    
598     $coro->eval ("string");
599     $coro->call (sub { ... });
600    
601    
602     =head1 Ausblick
603    
604     C<Coro::Debug> ist recht neu und die sich ergebenden Möglichkeiten noch
605     nicht wirklich ausgelotet. Ich denke, daß es aber jetzt schon sehr
606     hilfreiche Mittel zum Debugging zur Verfügung stellt.
607    
608     Ich hoffe auch, ich konnte ein paar Anregungen zum Thema "jedes
609     Perl-Programm braucht eine interaktive Shell" zu liefern: Es ist
610     wirklich hilfreich, und mit Perl (mit oder ohne Coro) sehr einfach zu
611     implementieren.
612    
613 root 1.1 =head1 Autor
614    
615     Marc Lehmann <schmorp@schmorp.de>.