ViewVC Help
View File | Revision Log | Show Annotations | Download File
/cvs/docs/corodebug.pod
Revision: 1.4
Committed: Sun Jan 13 05:39:09 2008 UTC (16 years, 5 months ago) by root
Branch: MAIN
Changes since 1.3: +1 -3 lines
Log Message:
*** empty log message ***

File Contents

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