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

Slide 1

Slide 1 text

Devel::YCallTrace – noch ein anderes Werkzeug zur Analyse von Perl Programmen Elena Bolshakova [email protected]

Slide 2

Slide 2 text

Wer bin ich Russland, Moskau, Yandex

Slide 3

Slide 3 text

Problemstellung Mein Programm funktioniert nicht richtig. Warum?

Slide 4

Slide 4 text

Lösung: Debugger perl -d my_script.pl

Slide 5

Slide 5 text

Einzelschritt-Verarbeitung ● nimmt viel Zeit ● langweilig ● unter mod_perl – ?

Slide 6

Slide 6 text

Automatischer Debugger ● man führt die Programm aus ● nötige Logdateien werden automatisch speichern ● dann kann man die Logdateien lesen und prüfen

Slide 7

Slide 7 text

“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 ...

Slide 8

Slide 8 text

Beispiele

Slide 9

Slide 9 text

Devel::RemoteTrace “Attachable call trace of perl scripts” Verlangsamung: sehr bedeutend + use Devel::RemoteTrace; > netcat u l 9999 > kill USR2

Slide 10

Slide 10 text

Devel::RemoteTrace – Bericht [18952] ./sudokusolver.pl:264: my %index; [18952] ./sudokusolver.pl:265: my %digit; [18952] ./sudokusolver.pl:266: for my $j (@$s){ [18952] ./sudokusolver.pl:267: my $ind = $g>[$j]; [18952] ./sudokusolver.pl:268: next SUBSET if $board>{$ind}>{content}; [18952] ./sudokusolver.pl:264: my %index; [18952] ./sudokusolver.pl:265: my %digit; [18952] ./sudokusolver.pl:266: for my $j (@$s){ [18952] ./sudokusolver.pl:267: my $ind = $g>[$j]; [18952] ./sudokusolver.pl:268: next SUBSET if $board>{$ind}>{content}; [18952] ./sudokusolver.pl:269: $index{$ind} = 1; [18952] ./sudokusolver.pl:270: for my $d (keys %{$board>{$ind} >{hypothesis}}) { [18952] ./sudokusolver.pl:270: for my $d (keys %{$board>{$ind} >{hypothesis}}) { [18952] ./sudokusolver.pl:271: next if $board>{$ind}>{hypothesis} >{$d} == 0; [18952] ./sudokusolver.pl:272: $digit{$d} = 1; [18952] ./sudokusolver.pl:271: next if $board>{$ind}>{hypothesis} >{$d} == 0;

Slide 11

Slide 11 text

Devel::TraceSubs Verlangsamung: ~20x vervolgt Aufrufen der Subroutinen warnings: defined(%hash) is deprecated Modification of noncreatable array value attempted

Slide 12

Slide 12 text

Devel::TraceSubs - Initialisierung +use Devel::TraceSubs; + my $dbg = Devel::TraceSubs>new( + verbose => 0, + pre => '>', + post => '<', + level => '~', + params => 1, + wrap => [''], + ); + $dbg>trace('main::');

Slide 13

Slide 13 text

Devel::TraceSubs - Bericht at sample_scripts/fib.pl line 32 at sample_scripts/fib.pl line 42 at sample_scripts/fib.pl line 42 at sample_scripts/fib.pl line 42 at sample_scripts/fib.pl line 42 at sample_scripts/fib.pl line 42 at sample_scripts/fib.pl line 42 at sample_scripts/fib.pl line 42 at sample_scripts/fib.pl line 42

Slide 14

Slide 14 text

Devel::TraceSubs – Bericht 2 at ./sudoku-solver.pl line 27 at ./sudoku-solver.pl line 27 at ./sudoku-solver.pl line 33 at ./sudoku-solver.pl line 126 at ./sudoku-solver.pl line 126 at ./sudoku-solver.pl line 127 at ./sudoku-solver.pl line 127

Slide 15

Slide 15 text

Devel::CallTrace Verlangsmanung: ~1.5x vervolgt Aufrufen der Subroutinen gebraucht der Debugger .deb > perl d:CallTrace script.pl

Slide 16

Slide 16 text

Devel::CallTrace – Bericht ... main::explain_state (./sudokusolver.pl:300307) main::explain_hypothesis (./sudokusolver.pl:310317) main::rule_0 (./sudokusolver.pl:186202) main::explain (./sudokusolver.pl:291297) main::explain_state (./sudokusolver.pl:300307) main::explain_hypothesis (./sudokusolver.pl:310317) main::rule_0 (./sudokusolver.pl:186202) main::rule_1 (./sudokusolver.pl:205226) main::explain (./sudokusolver.pl:291297) main::explain (./sudokusolver.pl:291297) main::explain (./sudokusolver.pl:291297) main::explain_state (./sudokusolver.pl:300307) main::explain_hypothesis (./sudokusolver.pl:310317) main::rule_0 (./sudokusolver.pl:186202) ...

Slide 17

Slide 17 text

Devel::CallStack Verlangsamung: 2-10x Gesamtbericht über den Stapelspeicher > perl d:CallStack script.pl > less callstack.out

Slide 18

Slide 18 text

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 ...

Slide 19

Slide 19 text

Devel::Trace Verlangsamung: ~20x druckt jede Zeile Code (wie sh -x) > perl d:Trace script.pl

Slide 20

Slide 20 text

Devel::Trace – Bericht ... >> ./sudokusolver.pl:56: for my $i ( 1 .. 9 ){ >> ./sudokusolver.pl:57: for my $j (1 .. 9){ >> ./sudokusolver.pl:58: my $c = shift @arr; >> ./sudokusolver.pl:59: if ($c eq '.'){ >> ./sudokusolver.pl:66: $board>{"$i$j"} = { >> ./sudokusolver.pl:58: my $c = shift @arr; >> ./sudokusolver.pl:59: if ($c eq '.'){ >> ./sudokusolver.pl:66: $board>{"$i$j"} = { >> ./sudokusolver.pl:58: my $c = shift @arr; >> ./sudokusolver.pl:59: if ($c eq '.'){ >> ./sudokusolver.pl:63: hypothesis => { map { $_ => 1 } 1 .. 9 }, >> ./sudokusolver.pl:60: $board>{"$i$j"} = { >> ./sudokusolver.pl:60: $board>{"$i$j"} = { >> ./sudokusolver.pl:60: $board>{"$i$j"} = { ...

Slide 21

Slide 21 text

Devel::TraceVars Verlangsamung: sehr bedeutend druckt jede Zeile Code (mit Variablen) riesige Logdatei > perl d:TraceVars script.pl

Slide 22

Slide 22 text

Devel::TraceVars – Bericht ... >> ./sudokusolver.pl 58: my $c = shift @arr; >> ./sudokusolver.pl 59: if (8 eq '.'){ >> ./sudokusolver.pl 66: HASH(0x13746d0)>{"14"} = { >> ./sudokusolver.pl 58: my $c = shift @arr; >> ./sudokusolver.pl 59: if (. eq '.'){ >> ./sudokusolver.pl 63: hypothesis => { map { $_ => 1 } 1 .. 9 }, >> ./sudokusolver.pl 60: HASH(0x13746d0)>{"15"} = { >> ./sudokusolver.pl 60: HASH(0x13746d0)>{"15"} = { >> ./sudokusolver.pl 60: HASH(0x13746d0)>{"15"} = { >> ./sudokusolver.pl 60: HASH(0x13746d0)>{"15"} = { >> ./sudokusolver.pl 60: HASH(0x13746d0)>{"15"} = { >> ./sudokusolver.pl 60: HASH(0x13746d0)>{"15"} = { >> ./sudokusolver.pl 60: HASH(0x13746d0)>{"15"} = { >> ./sudokusolver.pl 58: my $c = shift @arr; ...

Slide 23

Slide 23 text

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 – ...

Slide 24

Slide 24 text

Devel::YCallTrace

Slide 25

Slide 25 text

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

Slide 26

Slide 26 text

Live Demo

Slide 27

Slide 27 text

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($N1) + fib($N2); } }

Slide 28

Slide 28 text

> ./fib.pl 8 21 > ./yct_view.pl Please contact me at: http://lena santhinkpad:39539/ > firefox http://lenasan thinkpad:39539/

Slide 29

Slide 29 text

No content

Slide 30

Slide 30 text

No content

Slide 31

Slide 31 text

No content

Slide 32

Slide 32 text

No content

Slide 33

Slide 33 text

No content

Slide 34

Slide 34 text

No content

Slide 35

Slide 35 text

No content

Slide 36

Slide 36 text

Devel::YCallTrace: Nutzung

Slide 37

Slide 37 text

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

Slide 38

Slide 38 text

Objektorientirte Schnitstelle require Devel::YCallTrace; my $yct = new Devel::YCallTrace; Die Logdatei wird gespeichert wenn der Objekt zerstört wird

Slide 39

Slide 39 text

Als ein Debugger perl d:YCallTraceDbg=namespaces,App::A ck /usr/bin/ackgrep my Die Logdatei wird im END block gespeichert

Slide 40

Slide 40 text

Irgendwie im Quelltext einer Webdienst if( !production() && cookie('yct_debug') ){ Devel::YCallTrace::init(...); Apache2::RequestUtil>request>pool >cleanup_register( sub { Devel::YCallTrace::finish(); } ); }