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 *
#	Content
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>.