docs/corodebug.pod

=head1 NAME

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 andreen 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 aber 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 interkativen Zugang.

Startet man das Programm neu (z.B. nach Einbau einiger warn-statements
oder um es unter dem Debugger laufen zu lassen) tritt das Problem häufig
nicht mehr auf.

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 implementiert wird), bleibt
häufig 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$//;

         # 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 jedes 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 ($cmd eq "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, dei 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";
           
            # 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, ansonsteb habe ich aus meinen
früheren Versuchen gelernt und implementiere keine Kommandos mehr direkt,
sondern erlaube direkt die Eingabe von Perl-Ausdrücken:

            ...
         } 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 kompilziert und dann evaluiert. 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 globale Hash speichert:

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

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

=head1 Coro::Debug

=head1 Autor

Marc Lehmann <schmorp@schmorp.de>.
Revision:	1.1
Committed:	Sun Jan 13 03:12:05 2008 UTC (16 years, 5 months ago) by root
Branch:	MAIN
Log Message:	* empty log message *
#	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			Gegenüber Prozessen hat man den Vorteil extrem einfacher Kommunikation zwischen den einzelnen Instanzen, beispielsweise
303			implementiert der schon genannte Webserver einen Schutz gegen segmentierte Downloads, indem er die gerade heruntergeladenen URLs
304			pro Klient in einem globale Hash speichert:
305
306			if ($DOWNLOADS{$url}{$clientid} >= 4) {
307			# abort, zu viele Verbindungen
308			return;
309			}
310
311			++$DOWNLOADS{$url}{$clientid};
312
313			=head1 Coro::Debug
314
315			=head1 Autor
316
317			Marc Lehmann <schmorp@schmorp.de>.