Save 37% off PRO during our Black Friday Sale! »

Devel::YCallTrace -- noch ein anderes Werkzeug zur Analyse von Perl Programmen

Devel::YCallTrace -- noch ein anderes Werkzeug zur Analyse von Perl Programmen

8f83769f20aae31b1666e52ee2bab413?s=128

Elena Bolshakova

March 14, 2013
Tweet

Transcript

  1. Devel::YCallTrace – noch ein anderes Werkzeug zur Analyse von Perl

    Programmen Elena Bolshakova helena@cpan.org
  2. Wer bin ich Russland, Moskau, Yandex

  3. Problemstellung Mein Programm funktioniert nicht richtig. Warum?

  4. Lösung: Debugger perl -d my_script.pl

  5. Einzelschritt-Verarbeitung • nimmt viel Zeit • langweilig • unter mod_perl

    – ?
  6. Automatischer Debugger • man führt die Programm aus • nötige

    Logdateien werden automatisch speichern • dann kann man die Logdateien lesen und prüfen
  7. “Automatishe Debuggers” auf CPAN Devel::CallChecker Devel::CallParser Devel::CallStack Devel::CallTrace Devel::Calltree Devel::DTrace

    Devel::DumpTrace Devel::DumpTrace::PPI Devel::Optrace Devel::PrettyTrace Devel::RemoteTrace Devel::SimpleTrace Devel::Spy Devel::STrace Devel::Trace Devel::TraceCalls Devel::Trace::Cwd Devel::Trace::Fork Devel::Trace::Method Devel::TraceMethods Devel::Trace::More Devel::TraceSubs Devel::TraceUse Devel::TraceVars Devel::TrackObjects Runops::Recorder Runops::Trace ...
  8. Beispiele

  9. Devel::RemoteTrace “Attachable call trace of perl scripts” Verlangsamung: sehr bedeutend

    + use Devel::RemoteTrace; > netcat ­u ­l 9999 > kill ­USR2 <pid>
  10. Devel::RemoteTrace – Bericht [18952] ./sudoku­solver.pl:264: my %index; [18952] ./sudoku­solver.pl:265: my

    %digit; [18952] ./sudoku­solver.pl:266: for my $j (@$s){ [18952] ./sudoku­solver.pl:267: my $ind = $g­>[$j]; [18952] ./sudoku­solver.pl:268: next SUBSET if $board­>{$ind}­>{content}; [18952] ./sudoku­solver.pl:264: my %index; [18952] ./sudoku­solver.pl:265: my %digit; [18952] ./sudoku­solver.pl:266: for my $j (@$s){ [18952] ./sudoku­solver.pl:267: my $ind = $g­>[$j]; [18952] ./sudoku­solver.pl:268: next SUBSET if $board­>{$ind}­>{content}; [18952] ./sudoku­solver.pl:269: $index{$ind} = 1; [18952] ./sudoku­solver.pl:270: for my $d (keys %{$board­>{$ind}­ >{hypothesis}}) { [18952] ./sudoku­solver.pl:270: for my $d (keys %{$board­>{$ind}­ >{hypothesis}}) { [18952] ./sudoku­solver.pl:271: next if $board­>{$ind}­>{hypothesis}­ >{$d} == 0; [18952] ./sudoku­solver.pl:272: $digit{$d} = 1; [18952] ./sudoku­solver.pl:271: next if $board­>{$ind}­>{hypothesis}­ >{$d} == 0;
  11. Devel::TraceSubs Verlangsamung: ~20x vervolgt Aufrufen der Subroutinen warnings: defined(%hash) is

    deprecated Modification of non­creatable array value attempted
  12. Devel::TraceSubs - Initialisierung +use Devel::TraceSubs; + my $dbg = Devel::TraceSubs­>new(

    + verbose => 0, + pre => '>', + post => '<', + level => '~', + params => 1, + wrap => ['<!­­', '­­>'], + ); + $dbg­>trace('main::');
  13. Devel::TraceSubs - Bericht <!--~~> main::fib( ''4'' )--> at sample_scripts/fib.pl line

    32 <!--~~~> main::fib( '3' )--> at sample_scripts/fib.pl line 42 <!--~~~~> main::fib( '2' )--> at sample_scripts/fib.pl line 42 <!--~~~~< main::fib => 1--> at sample_scripts/fib.pl line 42 <!--~~~~> main::fib( '1' )--> at sample_scripts/fib.pl line 42 <!--~~~~< main::fib => 1--> at sample_scripts/fib.pl line 42 <!--~~~< main::fib => 2--> at sample_scripts/fib.pl line 42 <!--~~~> main::fib( '2' )--> at sample_scripts/fib.pl line 42 <!--~~~< main::fib => 1--> at sample_scripts/fib.pl line 42
  14. Devel::TraceSubs – Bericht 2 <!--~~> main::read_board--> at ./sudoku-solver.pl line 27

    <!--~~< main::read_board--> at ./sudoku-solver.pl line 27 <!--~~> main::print_board( '{'33' => {'content' => '','type' => 'solution','hypothesis' => {'6' => 1,'3' => 1,'7' => at ./sudoku-solver.pl line 33 <!--~~< main::print_board => <void>--> at ./sudoku-solver.pl line 33 <!--~~> main::solve( '{'33' => {'content' => '','type' => 'solution','hypothesis' => {'6' => 1,'3' => 1,'7' => 1,'9' at ./sudoku-solver.pl line 34 <!--~~~> main::generate_groups--> at ./sudoku-solver.pl line 126 <!--~~~< main::generate_groups--> at ./sudoku-solver.pl line 126 <!--~~~> main::generate_subsets--> at ./sudoku-solver.pl line 127 <!--~~~< main::generate_subsets--> at ./sudoku-solver.pl line 127 <!--~~~> main::explain_hypothesis( '{'33' => {'content' => '','type' => 'solution','hypothesis' => {'6' => 1,'3' => 1 at ./sudoku-solver.pl line 131 ...
  15. Devel::CallTrace Verlangsmanung: ~1.5x vervolgt Aufrufen der Subroutinen gebraucht der Debugger

    .deb > perl ­d:CallTrace script.pl
  16. Devel::CallTrace – Bericht ... main::explain_state (./sudoku­solver.pl:300­307) main::explain_hypothesis (./sudoku­solver.pl:310­317) main::rule_0 (./sudoku­solver.pl:186­202)

    main::explain (./sudoku­solver.pl:291­297) main::explain_state (./sudoku­solver.pl:300­307) main::explain_hypothesis (./sudoku­solver.pl:310­317) main::rule_0 (./sudoku­solver.pl:186­202) main::rule_1 (./sudoku­solver.pl:205­226) main::explain (./sudoku­solver.pl:291­297) main::explain (./sudoku­solver.pl:291­297) main::explain (./sudoku­solver.pl:291­297) main::explain_state (./sudoku­solver.pl:300­307) main::explain_hypothesis (./sudoku­solver.pl:310­317) main::rule_0 (./sudoku­solver.pl:186­202) ...
  17. Devel::CallStack Verlangsamung: 2-10x Gesamtbericht über den Stapelspeicher > perl ­d:CallStack

    script.pl > less callstack.out
  18. Devel::CallStack – Bericht main::run 1 1 main::run,Data::Dumper::Dumper 2 1 main::run,Data::Dumper::Dumper,Data::Dumper::Dump

    3 1 main::run,Data::Dumper::Dumper,Data::Dumper::Dump,Data::Dumper::Dumpxs 4 1 main::run,Data::Dumper::Dumper,Data::Dumper::Dump,Data::Dumper::new 4 1 main::run,main::explain_hypothesis 2 1 main::run,main::explain_hypothesis,main::print_hypothesis 3 1 main::run,main::print_board 2 2 main::run,main::read_board 2 1 main::run,main::solve 2 1 main::run,main::solve,main::explain_hypothesis 3 141 main::run,main::solve,main::explain_hypothesis,main::print_hypothesis 4 141 main::run,main::solve,main::explain_state 3 140 main::run,main::solve,main::explain_state,main::print_board 4 140 main::run,main::solve,main::generate_groups 3 1 main::run,main::solve,main::generate_subsets 3 1 main::run,main::solve,main::rule_0 3 1339 ...
  19. Devel::Trace Verlangsamung: ~20x druckt jede Zeile Code (wie sh -x)

    > perl ­d:Trace script.pl
  20. Devel::Trace – Bericht ... >> ./sudoku­solver.pl:56: for my $i (

    1 .. 9 ){ >> ./sudoku­solver.pl:57: for my $j (1 .. 9){ >> ./sudoku­solver.pl:58: my $c = shift @arr; >> ./sudoku­solver.pl:59: if ($c eq '.'){ >> ./sudoku­solver.pl:66: $board­>{"$i$j"} = { >> ./sudoku­solver.pl:58: my $c = shift @arr; >> ./sudoku­solver.pl:59: if ($c eq '.'){ >> ./sudoku­solver.pl:66: $board­>{"$i$j"} = { >> ./sudoku­solver.pl:58: my $c = shift @arr; >> ./sudoku­solver.pl:59: if ($c eq '.'){ >> ./sudoku­solver.pl:63: hypothesis => { map { $_ => 1 } 1 .. 9 }, >> ./sudoku­solver.pl:60: $board­>{"$i$j"} = { >> ./sudoku­solver.pl:60: $board­>{"$i$j"} = { >> ./sudoku­solver.pl:60: $board­>{"$i$j"} = { ...
  21. Devel::TraceVars Verlangsamung: sehr bedeutend druckt jede Zeile Code (mit Variablen)

    riesige Logdatei > perl ­d:TraceVars script.pl
  22. Devel::TraceVars – Bericht ... >> ./sudoku­solver.pl 58: my $c =

    shift @arr; >> ./sudoku­solver.pl 59: if (8 eq '.'){ >> ./sudoku­solver.pl 66: HASH(0x13746d0)­>{"14"} = { >> ./sudoku­solver.pl 58: my $c = shift @arr; >> ./sudoku­solver.pl 59: if (. eq '.'){ >> ./sudoku­solver.pl 63: hypothesis => { map { $_ => 1 } 1 .. 9 }, >> ./sudoku­solver.pl 60: HASH(0x13746d0)­>{"15"} = { >> ./sudoku­solver.pl 60: HASH(0x13746d0)­>{"15"} = { >> ./sudoku­solver.pl 60: HASH(0x13746d0)­>{"15"} = { >> ./sudoku­solver.pl 60: HASH(0x13746d0)­>{"15"} = { >> ./sudoku­solver.pl 60: HASH(0x13746d0)­>{"15"} = { >> ./sudoku­solver.pl 60: HASH(0x13746d0)­>{"15"} = { >> ./sudoku­solver.pl 60: HASH(0x13746d0)­>{"15"} = { >> ./sudoku­solver.pl 58: my $c = shift @arr; ...
  23. Ist alles schon gut? Leider nicht • riesige Logdateien –

    schwierig zu lesen und grep'en – passt nicht für die große Programme • doch gibt es einige Informationen nicht – Werte der Variablen – ob die Subroutine ihre Parametern modifiziert hat – ...
  24. Devel::YCallTrace

  25. Devel::YCallTrace vervolgt Aufrufen der Funktionen Verlangsamung bis 50-100x prozedurale, objektorientirte

    und debugger Schnittstelle mod_perl kompatibel perl >= 5.8 kompatibel erfordet Aspect, Template::Toolkit, HTTP::Daemon gebraucht SQLite oder andere DB
  26. Live Demo

  27. Plan B for live demo # Fibonacci numbers, recursively require

    Devel::YCallTrace; Devel::YCallTrace::init(); print fib($N); sub fib{ my ($N) = @_; if ($N <= 2 ){ return 1; } else { return fib($N­1) + fib($N­2); } }
  28. > ./fib.pl 8 21 > ./yct_view.pl Please contact me at:

    http://lena­ san­thinkpad:39539/ > firefox http://lena­san­ thinkpad:39539/
  29. None
  30. None
  31. None
  32. None
  33. None
  34. None
  35. None
  36. Devel::YCallTrace: Nutzung

  37. Prozedurale Schnittstelle require Devel::YCallTrace; Devel::YCallTrace::init(); Die Logdatei wird im END-block

    gespeichert
  38. Objektorientirte Schnitstelle require Devel::YCallTrace; my $yct = new Devel::YCallTrace; Die

    Logdatei wird gespeichert wenn der Objekt zerstört wird
  39. Als ein Debugger perl ­d:YCallTraceDbg=namespaces,App::A ck /usr/bin/ack­grep my Die Logdatei

    wird im END block gespeichert
  40. Irgendwie im Quelltext einer Webdienst if( !production() && cookie('yct_debug') ){

    Devel::YCallTrace::init(...); Apache2::RequestUtil­>request­>pool ­>cleanup_register( sub { Devel::YCallTrace::finish(); } ); }
  41. https://github.com/liruoko/y_call_trace.git

  42. Danke! Elena Bolshakova helena@cpan.org