1

I'm working on a project for optimizing an existing algorithm. I profiled the code with JIP and VisualVM and got a main bottleneck.

Now I want to see what takes the most time IN the method. What is an easy way to do that? Are there profilers that give me that information or do I need to start timing every step in the method and write it to a file?

EDIT : This should be while the code is running on inputsets

EDIT 2 : The method I'm talking about is called 100million+ times with a total of +/-500 seconds runtime. So every optimisation in the code will have a significant improvement.

Lonefish
  • 647
  • 2
  • 11
  • 32
  • not really a direct answer to what you ask but you might want to split your method into smaller methods (if it is possible of course) and that would indirectly solve your problem and provide better maintenability and reuse. – benzonico Feb 28 '13 at 14:18
  • Again not a direct answer but try using caliper from google. more info here https://code.google.com/p/caliper/ – anthonyms Feb 28 '13 at 14:21
  • The code is already calling a few methods, so further splitting isn't really possible. I was looking into Caliper just before your comment, but as I understand it it's like Stopwatch? Or am I wrong? – Lonefish Feb 28 '13 at 14:28
  • Are you sure that the method itself is the cause of your bottleneck, or is the number of times that the method is called? For example, you could have a method that takes 0.001 seconds to run, which isn't bad if it's only called once, but is noticeable if called 10,000 times. – parsifal Feb 28 '13 at 14:50
  • Inside the method, you can do some deduction rather than just logging everything. For example, a loop is likely to consume time, while basic data manipulation isn't. IO calls should be accounted-for by the method-level profiling, so can safely be ignored if it didn't show as a hotspot in the first pass. And so on. – parsifal Feb 28 '13 at 14:52
  • Finally, I second @benzonico: if your method is so large that you don't immediately say "oh, that's where the problem must be," then it needs refactoring. – parsifal Feb 28 '13 at 14:52
  • The fact is that it has some log-writing in the code, those are called, depending on if-clauses, this is why I can't say what the problem is, because I can't possibly know how much the if-clause is valid or not. The method is indeed the bottleneck. Or at least the biggest at the moment. We are talking about 100million + method calls for +/-500 seconds runtime. So every optimisation in the code will have a significant improvement. – Lonefish Feb 28 '13 at 15:02
  • So each call takes 5 millionths of a second. Let's say you reduce that to 4us (which is probably optimistic with a method that executes so quickly), you're still looking at 400 seconds of execution time. If it were me, I'd be trying to figure out how to reduce those 100MM calls, perhaps by using a different higher-level algorithm. or by introducing some level of concurrency (does each call depend on the results of the previous?). – parsifal Feb 28 '13 at 15:17
  • If I can reduce it to 400 seconds instead of 500 it is a 20% gain. The method is 10% of the runtime, so it would be a 2% improvement, which would be a decent improvement for the application. Changing the algorithm is out of the question, it is far too complex to do that, my job is to optimize the code. – Lonefish Feb 28 '13 at 15:24
  • I wish you the best of luck. And while I know absolutely nothing about your motivations, if I were tasked with eking out a 2% gain from CPU-intensive code, I would turn to hardware. For around $1,000 you can buy the latest i7 processor and enough liquid cooling to get an easy 20% boost from overclocking. For that matter, if you're using anything less than the latest chips at the highest clock rate, IMO *anything* you do in software is a waste of money. – parsifal Feb 28 '13 at 15:44

3 Answers3

1

If you are looking for tools that analyze code while it is executing, you will want to investigate dynamic analysis tools. JTest (for Java) is mentioned in the article but I am afraid I have not worked with it.

You can alternatively use a static code analysis tool like soot with some varied levels of success. The tools will identify areas of your code that take the longest to execute.

Others include: SonarJ, PMD, Kalistick

The way that I have used the tools like soot is to bind it in my build management tool. So for maven, it would be configured like so:

  <plugin>
    <groupId>net.ju-n.maven.plugins</groupId>
    <artifactId>soot-maven-plugin</artifactId>
    <version>0.1.1</version>
    <executions>
      <execution>
        <goals>
          <goal><!-- put the goal name here --></goal>
        </goals>
      </execution>
    </executions>
    <configuration>
        <!-- put your configurations here -->
    </configuration>
  </plugin>

I would then configure this to run in a maven profile (preferably on a build server) and publish the results.

The goal to execute is: mvn soot:soot

Note that the static analysis is performed on the code without actually executing the code.

  • Sorry, might not have been clear in the opening post. There are various if clauses in the method, so I want to know in actual execution what code is most used and what takes the most time in the function.. – Lonefish Feb 28 '13 at 14:32
  • Te tools should highlight the branches that are taking much time. Try them out? –  Feb 28 '13 at 14:33
  • 1
    I will try them out, but from what I read I understand that they analyze the source code. Not while it's running.. – Lonefish Feb 28 '13 at 14:34
  • You're right about that, those are not performance analysis tools, although Sonar MIGHT inadvertently point out issue that are relevant to performance. – vector Feb 28 '13 at 14:51
  • Perhaps you can expand this answer with an example of *how* these tools can help with performance analysis. – parsifal Feb 28 '13 at 14:56
  • You show how to run soot (well, almost), but not how it will help with performance analysis. – parsifal Feb 28 '13 at 15:45
  • Indeed, got it running with eclipse, but no idea how to get any usefull output (well, can't get any output out of it for that matter..) – Lonefish Feb 28 '13 at 17:04
0

JUnitBenchmarks could help. What about a 'brute force' type of check with time-stamps

between relevant sections of the method?

vector
  • 7,334
  • 8
  • 52
  • 80
  • You mean to time each step in the method and write them to a log? – Lonefish Feb 28 '13 at 14:57
  • Exactly, and/or give Soot a chance, except documentation on that seems aged. What jdk are you using? – vector Feb 28 '13 at 14:59
  • 1.6, the Eclipse compiler. I am installing Soot and will try it, because I'd rather have an automated system than one I have to write myself, because the last one will have potentially more influence on the code than one written by experts :) – Lonefish Feb 28 '13 at 15:13
0

Don't do it by measuring time.

Do it by grabbing snapshots in the debugger. That will show you down to the finest level what it's doing. Whatever it's doing, if you catch it doing it on two or more snapshots - consider it a bug. If you can avoid it, you'll save a ton of time.

How much time? You'll find out when you fix it, but the fewer snapshots it took to see it twice, the more you'll save.

If you're afraid it won't find "the problem", don't worry, it will, and it's probably something you didn't expect. More on all that ...

Community
  • 1
  • 1
Mike Dunlavey
  • 40,059
  • 14
  • 91
  • 135