ViewVC Help
View File | Revision Log | Show Annotations | Download File
/cvs/AnyEvent/lib/AnyEvent/Debug.pm
(Generate patch)

Comparing AnyEvent/lib/AnyEvent/Debug.pm (file contents):
Revision 1.18 by root, Tue Aug 16 14:47:26 2011 UTC vs.
Revision 1.19 by root, Tue Aug 16 16:37:04 2011 UTC

… …
31 31
32use AnyEvent (); BEGIN { AnyEvent::common_sense } 32use AnyEvent (); BEGIN { AnyEvent::common_sense }
33use AnyEvent::Util (); 33use AnyEvent::Util ();
34use AnyEvent::Socket (); 34use AnyEvent::Socket ();
35use AnyEvent::Log (); 35use AnyEvent::Log ();
36
37# cache often-used strings, purely to save memory, at the expense of speed
38our %STRCACHE;
36 39
37=item $shell = AnyEvent;::Debug::shell $host, $service 40=item $shell = AnyEvent;::Debug::shell $host, $service
38 41
39This function binds on the given host and service port and returns a 42This function binds on the given host and service port and returns a
40shell object, which determines the lifetime of the shell. Any number 43shell object, which determines the lifetime of the shell. Any number
… …
197A level of C<0> disables wrapping, i.e. AnyEvent works normally, and in 200A level of C<0> disables wrapping, i.e. AnyEvent works normally, and in
198its most efficient mode. 201its most efficient mode.
199 202
200A level of C<1> enables wrapping, which replaces all watchers by 203A level of C<1> enables wrapping, which replaces all watchers by
201AnyEvent::Debug::Wrapped objects, stores the location where a watcher was 204AnyEvent::Debug::Wrapped objects, stores the location where a watcher was
202created and wraps the callback so invocations of it can be traced. 205created and wraps the callback to log all invocations at "trace" loglevel
206(see L<AnyEvent::Log>).
203 207
204A level of C<2> does everything that level C<1> does, but also stores a 208A level of C<2> does everything that level C<1> does, but also stores a
205full backtrace of the location the watcher was created. 209full backtrace of the location the watcher was created, which slows down
210watcher creation considerably.
206 211
207Every wrapped watcher will be linked into C<%AnyEvent::Debug::Wrapped>, 212Every wrapped watcher will be linked into C<%AnyEvent::Debug::Wrapped>,
208with its address as key. The C<wl> command in the debug shell cna be used 213with its address as key. The C<wl> command in the debug shell cna be used
209to list watchers. 214to list watchers.
210 215
… …
338The reason it creates an object is to save time, as formatting can be 343The reason it creates an object is to save time, as formatting can be
339done at a later time. Still, creating a backtrace is a relatively slow 344done at a later time. Still, creating a backtrace is a relatively slow
340operation. 345operation.
341 346
342=cut 347=cut
343
344our %PATHCACHE; # purely to save memory
345 348
346sub backtrace(;$) { 349sub backtrace(;$) {
347 my $w = shift; 350 my $w = shift;
348 351
349 my (@bt, @c); 352 my (@bt, @c);
… …
370 0 .. (@DB::args < $Carp::MaxArgNums ? @DB::args : $Carp::MaxArgNums) - 1) 373 0 .. (@DB::args < $Carp::MaxArgNums ? @DB::args : $Carp::MaxArgNums) - 1)
371 . ")" 374 . ")"
372 if $c[4]; 375 if $c[4];
373 } 376 }
374 377
375 push @bt, [\($PATHCACHE{$c[1]} ||= $c[1]), $c[2], $sub]; 378 push @bt, [\($STRCACHE{$c[1]} ||= $c[1]), $c[2], $sub];
376 } 379 }
377 380
378 @DB::args = (); 381 @DB::args = ();
379 382
380 bless \@bt, "AnyEvent::Debug::Backtrace" 383 bless \@bt, "AnyEvent::Debug::Backtrace"
381} 384}
385
386=back
387
388=cut
382 389
383package AnyEvent::Debug::Wrap; 390package AnyEvent::Debug::Wrap;
384 391
385use AnyEvent (); BEGIN { AnyEvent::common_sense } 392use AnyEvent (); BEGIN { AnyEvent::common_sense }
386use Scalar::Util (); 393use Scalar::Util ();
… …
409 ++$w->{called}; 416 ++$w->{called};
410 417
411 return &$cb 418 return &$cb
412 unless $TRACE_LEVEL; 419 unless $TRACE_LEVEL;
413 420
414 local $TRACE_CUR = "$w"; 421 local $TRACE_CUR = $w;
415 AE::log trace => "enter $TRACE_CUR"; 422 AE::log 9 => "enter $TRACE_CUR"
423 if $AnyEvent::VERBOSE >= 9;
416 eval { 424 eval {
417 local $SIG{__DIE__} = sub { die $_[0] . AnyEvent::Debug::backtrace }; 425 local $SIG{__DIE__} = sub { die $_[0] . AnyEvent::Debug::backtrace };
418 &$cb; 426 &$cb;
419 }; 427 };
420 if ($@) { 428 if ($@) {
421 push @{ $w->{error} }, [AE::now, $@] 429 push @{ $w->{error} }, [AE::now, $@]
422 if @{ $w->{error} } < 10; 430 if @{ $w->{error} } < 10;
423 AE::log error => "$TRACE_CUR $@"; 431 AE::log error => "$TRACE_CUR $@";
424 } 432 }
425 AE::log trace => "leave $TRACE_CUR"; 433 AE::log 9 => "leave $TRACE_CUR"
434 if $AnyEvent::VERBOSE >= 9;
426 }; 435 };
427 436
428 $self = bless { 437 $self = bless {
429 type => $name, 438 type => $name,
430 w => $self->$super (%arg), 439 w => $self->$super (%arg),
431 file => $file, 440 rfile => \($STRCACHE{$file} ||= $file),
432 line => $line, 441 line => $line,
433 sub => $sub, 442 sub => $sub,
434 cur => $TRACE_CUR, 443 cur => $TRACE_CUR,
435 now => AE::now, 444 now => AE::now,
436 arg => \%arg, 445 arg => \%arg,
… …
444 if $WRAP_LEVEL >= 2; 453 if $WRAP_LEVEL >= 2;
445 454
446 Scalar::Util::weaken ($w = $self); 455 Scalar::Util::weaken ($w = $self);
447 Scalar::Util::weaken ($AnyEvent::Debug::Wrapped{Scalar::Util::refaddr $self} = $self); 456 Scalar::Util::weaken ($AnyEvent::Debug::Wrapped{Scalar::Util::refaddr $self} = $self);
448 457
449 AE::log trace => "creat $w"; 458 AE::log trace => "creat $w"
459 if $AnyEvent::VERBOSE >= 9;
450 460
451 $self 461 $self
452 }; 462 };
453 } 463 }
454} 464}
455 465
456package AnyEvent::Debug::Wrapped; 466package AnyEvent::Debug::Wrapped;
467
468=head1 THE AnyEvent::Debug::Wrapped CLASS
469
470All watchers created while the wrap level is non-zero will be wrapped
471inside an AnyEvent::Debug::Wrapped object. The address of the
472wrapped watcher will become its ID - every watcher will be stored in
473C<$AnyEvent::Debug::Wrapped{$id}>.
474
475These wrapper objects, as of now, can be stringified, and you can call the
476C<< ->verbose >> method to get a multiline string describing the watcher
477in great detail, but otherwise has no other public methods.
478
479For debugging, of course, it can be helpful to look into these objects,
480which is why this is documented here, but this might change at any time in
481future versions.
482
483Each object is a relatively standard hash with the following members:
484
485 type => name of the method used ot create the watcher (e.g. C<io>, C<timer>).
486 w => the actual watcher
487 rfile => reference to the filename of the file the watcher was created in
488 line => line number where it was created
489 sub => function name (or a special string) which created the watcher
490 cur => if created inside another watcher callback, this is the string rep of the other watcher
491 now => the timestamp (AE::now) when the watcher was created
492 arg => the arguments used to create the watcher (sans C<cb>)
493 cb => the original callback used to create the watcher
494 called => the number of times the callback was called
495
496=cut
457 497
458use AnyEvent (); BEGIN { AnyEvent::common_sense } 498use AnyEvent (); BEGIN { AnyEvent::common_sense }
459 499
460use overload 500use overload
461 '""' => sub { 501 '""' => sub {
462 $_[0]{str} ||= do { 502 $_[0]{str} ||= do {
463 my ($pkg, $line) = @{ $_[0]{caller} }; 503 my ($pkg, $line) = @{ $_[0]{caller} };
464 504
465 my $mod = AnyEvent::Debug::path2mod $_[0]{file}; 505 my $mod = AnyEvent::Debug::path2mod ${ $_[0]{rfile} };
466 my $sub = $_[0]{sub}; 506 my $sub = $_[0]{sub};
467 507
468 if (defined $sub) { 508 if (defined $sub) {
469 $sub =~ s/^\Q$mod\E:://; 509 $sub =~ s/^\Q$mod\E:://;
470 $sub = "($sub)"; 510 $sub = "($sub)";
… …
481 my ($self) = @_; 521 my ($self) = @_;
482 522
483 my $res = "type: $self->{type} watcher\n" 523 my $res = "type: $self->{type} watcher\n"
484 . "args: " . (join " ", %{ $self->{arg} }) . "\n" # TODO: decode fh? 524 . "args: " . (join " ", %{ $self->{arg} }) . "\n" # TODO: decode fh?
485 . "created: " . (AnyEvent::Log::ft $self->{now}) . " ($self->{now})\n" 525 . "created: " . (AnyEvent::Log::ft $self->{now}) . " ($self->{now})\n"
486 . "file: $self->{file}\n" 526 . "file: ${ $self->{rfile} }\n"
487 . "line: $self->{line}\n" 527 . "line: $self->{line}\n"
488 . "subname: $self->{sub}\n" 528 . "subname: $self->{sub}\n"
489 . "context: $self->{cur}\n" 529 . "context: $self->{cur}\n"
490 . "cb: $self->{cb} (" . (AnyEvent::Debug::cb2str $self->{cb}) . ")\n" 530 . "cb: $self->{cb} (" . (AnyEvent::Debug::cb2str $self->{cb}) . ")\n"
491 . "invoked: $self->{called} times\n"; 531 . "invoked: $self->{called} times\n";
… …
503 543
504 $res 544 $res
505} 545}
506 546
507sub DESTROY { 547sub DESTROY {
508 AE::log trace => "dstry $_[0]"; 548 AE::log trace => "dstry $_[0]"
549 if $AnyEvent::VERBOSE >= 9;
509 550
510 delete $AnyEvent::Debug::Wrapped{Scalar::Util::refaddr $_[0]}; 551 delete $AnyEvent::Debug::Wrapped{Scalar::Util::refaddr $_[0]};
511} 552}
512 553
513package AnyEvent::Debug::Backtrace; 554package AnyEvent::Debug::Backtrace;
… …
539 fallback => 1, 580 fallback => 1,
540; 581;
541 582
5421; 5831;
543 584
544=back
545
546=head1 AUTHOR 585=head1 AUTHOR
547 586
548 Marc Lehmann <schmorp@schmorp.de> 587 Marc Lehmann <schmorp@schmorp.de>
549 http://home.schmorp.de/ 588 http://home.schmorp.de/
550 589

Diff Legend

– Removed lines
+ Added lines
< Changed lines
> Changed lines