Beefy Boxes and Bandwidth Generously Provided by pair Networks
P is for Practical

Make java code faster

by fizbin (Chaplain)
on Aug 10, 2004 at 15:57 UTC ( #381641=CUFP: print w/replies, xml ) Need Help??

One module that has saved me a few times when a script just wasn't performing fast enough is Devel::SmallProf. I'm sure that there's a way to get good use out of profilers that don't drill down to a line-by-line analysis, but for "so that's where all the time goes" surprise moments, I've never found anything else that works as well on perl scripts as Devel::SmallProf. (for example, letting me know that I was throwing a huge amount of time into one mktime() call, and that by memoizing it could double my script's performance)

Anyway, sadly most of my job does not involve the camel. Instead, I often find myself trying to make java code go faster. Usually, this involves running java with the included profiler and looking at this output in various viewers, like ProphIt or HPjmeter. However, although these tools are often nice for demonstrating to management that there's not one single big timesink we can point to and say "that's it", I often find them a bit short on where in a given method all the time is being spent - these tools stop at the method level, and I miss my line-by-line information.

Well, the raw output of the java profiler includes this line-by-line information (assuming you compiled your code with debugging on), and the output is text. Enter perl.

The tool below lets you focus on which lines are actually eating up your cpu time; usage is pretty simple:

perl [-l limitingExpression] methodExpr profile1 [profile2 ...]
For example, if you know that it's code inside org.perlmonks.fizbin.Foo.doStrangeThings() that you want to look at closely, you can do:
perl org.perlmonks.fizbin.Foo.doStrangeThings todaysProfile.hprof.txt
Or even (if you don't care about other classes with that same method name, or want to see them too):
perl doStrangeThings todaysProfile.hprof.txt
Or if you want to look at everything inside a given class, use:
perl 'Foo\..*' yesterdaysProfile.hprof.txt
The expression is anchored so that you won't get any class named SuperFoo, but without the ugly \. you would select classes named FooBar. Maybe in a future version.

Another thing often is that there are certain usage patterns that are slow because they eventually cause some slow code to be invoked - for example, using a StringBuffer and consistently not allocating enough room. In this case, what you want to see is everything in your packages that eventually calls the slow code, so that you can try to avoid causing performance problems down the line.

perl -l StringBuffer.expandCapacity com.perlmonks.fizbin.* *.hprof.txt
The -l limiting expression also accepts something like in case the limit can't be expressed by a method name but can be expressed with a particular line.

When I use this script, I often pipe it through head, because I rarely care about more than the top few offenders. The top line always gives you the total number of samples in the entire profile, to keep you from losing perspective in your optimizing hunts. And now the script:

#!perl # This finds which specific lines are the hot points in a profile, # assuming that the code was compiled with debugging information. # # Parameters: method name, profile(s) to analyze # For example: # perl simpleConstant2 SlowProduct.31.hprof.txt # # You can give multiple profile arguments - # you can even say: # perl simpleConstant2 SlowProduct.*.hprof.txt # use strict; use vars qw[$state $limit $method $methodregexp $limitregexp $uselast]; # $state = "cpu", "trace", "other" $state = "other"; $method = shift; $limit = undef; if ($method eq "-l") { $limit = shift; $method = shift; } $uselast = 0; if ($method =~ s/^-//) {$uselast=1;} $methodregexp = qr/\t((?:.*\.)?(?:$method))\((.*:(?:\d+|Unknown line)) +\)/; if ($limit) { $limitregexp = qr/[\t.](?:$limit)\(/; $limitregexp = qr/\((?:$limit)\)/ if $limit =~ /:/; } else { $limitregexp = $methodregexp; } if (!$method or !@ARGV) { print <<EOD; Usage: [-l limit] method-name profile... Multiple profile names may be given The method-name argument is a regular expression of which method(s) you want to look at - for example, to look at all classes in a package called 'myproject', use 'myproject.*' The -l option limits output to those traces that call the named method. (For example, use "-l expandCapacity" to find those places in our code that append too much to a StringBuffer and cause it to re-allocate storage) EOD exit; } # be nice to people on windows: @ARGV = map { my @a = /[*?]/?glob($_):qw[]; @a?@a:$_; } @ARGV; # line -> total samples my %linetimes = (); # trace number -> description my %traces = (); my $sampletot = 0; my $trace = 0; my $limitmatched = 1; while (<>) { if ($state eq "other") { if (/^TRACE (\d+):/) { $trace = $1; $state = "trace"; $limitmatched = 0; } elsif (/^CPU SAMPLES BEGIN .total = (\d+)/) { $sampletot += $1; $state = "cpu"; } } elsif ($state eq "trace") { if (/^\t/) { if (($uselast or !$traces{$trace}) and /$methodregexp/) { my ($method,$line) = ($1,$2); $line = "Unknown" if $line =~ /Unknown/; $traces{$trace} = "$line in $method"; } if (/$limitregexp/) { $limitmatched = 1; } } else { if (!$limitmatched) { delete $traces{$trace}; } $state = "other"; redo; } } elsif ($state eq "cpu") { if (/CPU SAMPLES END/) { $state = "other"; next; } elsif (/^\s*\d+(.*)/) { my @data = split(/\s+/, $1); if ($traces{$data[4]}) { $linetimes{$traces{$data[4]}} += $data[3]; } } } } continue { if (eof) { $state = "other"; %traces = (); } } print "$sampletot\tTotal Samples\n"; foreach my $key (sort {$linetimes{$b} <=> $linetimes{$a}} keys(%lineti +mes)) { printf("%d\t%s\n", $linetimes{$key}, $key); }
I have a similar script for analyzing the heap dumps that the java profiler can produce, but I've not found that nearly as useful. (For our work, HPjmeter is adequate for determining allocation sites)
-- @/=map{[/./g]}qw/.h_nJ Xapou cets krht ele_ r_ra/; map{y/X_/\n /;print}map{pop@$_}@/for@/

Log In?

What's my password?
Create A New User
Node Status?
node history
Node Type: CUFP [id://381641]
Approved by Aristotle
and all is quiet...

How do I use this? | Other CB clients
Other Users?
Others examining the Monastery: (7)
As of 2017-04-25 09:29 GMT
Find Nodes?
    Voting Booth?
    I'm a fool:

    Results (449 votes). Check out past polls.