Skip to content
Browse files

Support new style timer messages that are in arrays, not hashes

  • Loading branch information...
1 parent 3b92c93 commit f26a76f4f0d0d656eeed336d3057ececbd3fb65d @hoytech committed Apr 7, 2013
Showing with 44 additions and 28 deletions.
  1. +23 −14 lib/Log/Defer/Viz.pm
  2. +6 −4 t/runs.t
  3. +3 −3 t/tp.log
  4. +12 −7 t/viz.t
View
37 lib/Log/Defer/Viz.pm
@@ -15,8 +15,20 @@ sub render_timers {
my $width = $arg{width} || 80;
my $timers = $arg{timers} || croak "need timers";
- my @timer_names = sort { $timers->{$a}->[0] <=> $timers->{$b}->[0] } keys %$timers;
- my @timer_names_by_end_time = sort { $timers->{$a}->[1] <=> $timers->{$b}->[1] } keys %$timers;
+ ## Support old style timers where they were stored in a hash:
+
+ if (ref $timers eq 'HASH') {
+ my $temp_timers = [];
+
+ foreach my $timer_name (keys %$timers) {
+ push @$temp_timers, [ $timer_name, @{ $timers->{$timer_name} }, ];
+ }
+
+ $timers = $temp_timers;
+ }
+
+ my @sorted_timers = sort { $a->[1] <=> $b->[1] } @$timers;
+ my @sorted_timers_by_end_time = sort { $a->[2] <=> $b->[2] } @$timers;
my $output = '';
@@ -26,25 +38,22 @@ sub render_timers {
my $max_time = 0;
my $max_namelen = 11;
- foreach my $timer_name (@timer_names) {
- my $timer = $timers->{$timer_name};
-
- $max_time = $timer->[1] if $timer->[1] > $max_time;
- $max_namelen = length($timer_name)+1 if length($timer_name)+1 > $max_namelen;
+ foreach my $timer (@sorted_timers) {
+ $max_time = $timer->[2] if $timer->[2] > $max_time;
+ $max_namelen = length($timer->[0])+1 if length($timer->[0])+1 > $max_namelen;
}
## Bar graph plots
my $scaling = ($width - $max_namelen - 8) / $max_time;
- foreach my $timer_name (@timer_names) {
- my $timer = $timers->{$timer_name};
- $output .= sprintf("%${max_namelen}s ", $timer_name);
+ foreach my $timer (@sorted_timers) {
+ $output .= sprintf("%${max_namelen}s ", $timer->[0]);
- $output .= ' ' x int($timer->[0] * $scaling);
+ $output .= ' ' x int($timer->[1] * $scaling);
- my $bar_width = int(($timer->[1] - $timer->[0]) * $scaling) - 1;
+ my $bar_width = int(($timer->[2] - $timer->[1]) * $scaling) - 1;
if ($bar_width > 0) {
$output .= '|';
@@ -67,10 +76,10 @@ sub render_timers {
$output .= 'times in ms ';
$output .= ' ' x ($max_namelen - 11);
- $output .= _time_bars($max_time, $scaling, [ map { $timers->{$_}->[0] } @timer_names ], $seen);
+ $output .= _time_bars($max_time, $scaling, [ map { $_->[1] } @sorted_timers ], $seen);
$output .= ' ' x ($max_namelen + 1);
- $output .= _time_bars($max_time, $scaling, [ map { $timers->{$_}->[1] } @timer_names_by_end_time ], $seen);
+ $output .= _time_bars($max_time, $scaling, [ map { $_->[2] } @sorted_timers_by_end_time ], $seen);
return $output;
}
View
10 t/runs.t
@@ -28,16 +28,18 @@ my $z = decode_json q{
"data" : {
"junkdata" : "some data"
},
- "timers" : {
- "junktimer" : [
+ "timers" : [
+ [
+ "junktimer",
0.000224,
0.100655
],
- "junktimer2" : [
+ [
+ "junktimer2",
0.000281,
0.202386
]
- }
+ ]
}
};
View
6 t/tp.log
@@ -1,3 +1,3 @@
-{"data":{"junkdata":"some data"},"logs":[[0.000158,30,"This is an info message (log level=30)"],[0.003226,20,"This is a warning!"],[0.061928,40,"Debug: blah blah blah"],[0.201223,10,"Error! \n\n Here is some more data:",{"whatever":987}]],"timers":{"junktimer":[0.000224,0.100655],"junktimer2":[0.000281,0.202386]},"end":0.202386,"start":1340353046.93565}
-{"logs":[[0.000158,30,"I HAVE NO DATA"],[0.003226,20,"This is a warning!"],[0.061928,40,"Debug: blah blah blah"],[0.201223,10,"Error! \n\n Here is some more data:",{"whatever":987}]],"timers":{"junktimer":[0.000224,0.100655],"junktimer2":[0.000281,0.202386]},"end":0.202386,"start":1340353046.93565}
-{"data":{"junkdata":"some data"},"logs":[[0.000158,30,"This is an info message (log level=30)"],[0.003226,20,"This is a warning!"],[0.061928,40,"Debug: blah blah blah"],[0.201223,10,"Error! \n\n Here is some more data:",{"whatever":987}]],"timers":{"junktimer":[0.000224,0.100655],"junktimer2":[0.000281,0.202386]},"end":0.202386,"start":1360953046.93565}
+{"data":{"junkdata":"some data"},"logs":[[0.000158,30,"This is an info message (log level=30)"],[0.003226,20,"This is a warning!"],[0.061928,40,"Debug: blah blah blah"],[0.201223,10,"Error! \n\n Here is some more data:",{"whatever":987}]],"timers":[["junktimer",0.000224,0.100655],["junktimer2",0.000281,0.202386]],"end":0.202386,"start":1340353046.93565}
+{"logs":[[0.000158,30,"I HAVE NO DATA"],[0.003226,20,"This is a warning!"],[0.061928,40,"Debug: blah blah blah"],[0.201223,10,"Error! \n\n Here is some more data:",{"whatever":987}]],"timers":[["junktimer",0.000224,0.100655],["junktimer2",0.000281,0.202386]],"end":0.202386,"start":1340353046.93565}
+{"data":{"junkdata":"some data"},"logs":[[0.000158,30,"This is an info message (log level=30)"],[0.003226,20,"This is a warning!"],[0.061928,40,"Debug: blah blah blah"],[0.201223,10,"Error! \n\n Here is some more data:",{"whatever":987}]],"timers":[["junktimer",0.000224,0.100655],["junktimer2",0.000281,0.202386]],"end":0.202386,"start":1360953046.93565}
View
19 t/viz.t
@@ -7,29 +7,34 @@ use Test::More tests => 1;
use Log::Defer::Viz;
-print "\n\n" . Log::Defer::Viz::render_timers(timers => {
- "download file" => [
+print "\n\n" . Log::Defer::Viz::render_timers(timers => [
+ [ "download file",
0.000224,
0.100655
],
- "sent reply" => [
+ [ "download file",
+ 0.017314,
+ 0.060655
+ ],
+ [ "sent reply",
0.100663,
0.100740
],
- "DB lookup" => [
+ [ "DB lookup",
0.032724,
0.080655
],
- "cache lookup" => [
+ [ "cache lookup",
0.000281,
0.032386
],
- "update cache" => [
+ [ "update cache",
0.032380,
0.119233
],
- });
+ ]);
+## Exercise old format where timers was a hash:
print "\n\n" . Log::Defer::Viz::render_timers(timers => {
'blah' => [
0.123413,

0 comments on commit f26a76f

Please sign in to comment.
Something went wrong with that request. Please try again.