This may be a silly question for some pro java coders but I am going mad right now, so I am still asking. Please guide me in right direction someone.
How do I analyze which method/partOfMethod is consuming more time in my java program?
(I am using Eclipse and Junit)
Use jvisualvm. It is bundled in with the JDK nowadays, but a standalone version exists as well, which is more up to date. Typically, when you start it you can pick which running java process to connect to (this may well be our running unit test). You can specify which qualified class name filters you need to track. Normally, some class instrumentation will ensue, and you will be able to track the processing time allocated to each method (cumulative time as well).
You need to get a Java profiler. Some of them integrate well in Eclipse.
Other than that, you're left with using a custom profiler class (if you don't have a lot of profiling to do and if you already suspect some bottlenecks).
Here is a simple class to do that:
/**
* Small helper class to profile the code, take timing, ...
*
* To use this, simply call the start method with an identifier. When you want to measure the time, call the stop method
* with the same identifier. To output statistics, simply call the toString method or the toCsv method to create a CSV
* file with the profiler information.
*
* @author Vincent Prat @ MarvinLabs
*/
public class Profiler {
private static final int THEORETICAL_MAX_NAME_LENGTH = 50;
private static Profiler singletonInstance = null;
private Map<String, Profile> profiles; // Fast access to profiles by name
private List<Profile> profilesStack; // Profiles as created chronologically
/**
* Get access to the singleton instance (create it if necessary)
*/
public static Profiler getInstance() {
if (singletonInstance == null) {
singletonInstance = new Profiler();
}
return singletonInstance;
}
/**
* Protected constructor for singleton
*/
protected Profiler() {
profiles = new HashMap<String, Profiler.Profile>();
profilesStack = new ArrayList<Profile>();
}
/**
* Start a profile. If the profile does not exist, it will be created. If it exists, a new round of measure is
* taken.
*
* @param name
* The name of the profile. If possible, less than Profiler.THEORETICAL_MAX_NAME_LENGTH characters
*
* @see Profiler.THEORETICAL_MAX_NAME_LENGTH
*/
public void start(String name) {
Profile p = profiles.get(name);
if (p == null) {
p = new Profile(name);
profiles.put(name, p);
profilesStack.add(p);
}
p.start();
}
/**
* Stop a profile and compute some statistics about it.
*
* @param name
* The name of the profile as declared in the corresponding start method
*/
public void stop(String name) {
Profile p = profiles.get(name);
if (p == null) {
throw new RuntimeException("The profile " + name + " has not been created by a call to the start() method!");
}
p.stop();
}
/**
* Clear all the current measures. Not to be called within any start/stop pair.
*/
public void reset() {
profiles.clear();
}
/**
* Build a string containing all the information about the measures we have taken so far.
*/
@Override
public String toString() {
final StringBuffer sb = new StringBuffer();
for (Profile p : profilesStack) {
sb.append(p.toString());
sb.append("\n");
}
return sb.toString();
}
/**
* Output the measures to an output string
*/
public void toCsvFile(OutputStream os) throws IOException {
Profile.writeCsvHeader(os);
for (Profile p : profilesStack) {
p.writeCsvLine(os);
}
}
/**
* Profile information. It stores statistics per named profile.
*
* @author Vincent Prat @ MarvinLabs
*/
private static class Profile {
private static final String CSV_HEADERS = "Name, Call Count, Total Time (ms), Average Time (ms), Min Time (ms), Max Time (ms), Delta Time (ms), Delta Ratio (%)\n";
private static final String FORMAT_STRING = "%-" + THEORETICAL_MAX_NAME_LENGTH + "."
+ THEORETICAL_MAX_NAME_LENGTH
+ "s: %3d calls, total %5d ms, avg %5d ms, min %5d ms, max %5d ms, delta %5d ms (%d%%)";
private static final String CSV_FORMAT_STRING = "%s,%d,%d,%d,%d,%d,%d,%d\n";
private String name;
private long startTime;
private long callCount;
private long totalTime;
private long minTime;
private long maxTime;
public Profile(String name) {
this.name = name;
this.callCount = 0;
this.totalTime = 0;
this.startTime = 0;
this.minTime = Long.MAX_VALUE;
this.maxTime = Long.MIN_VALUE;
}
public void start() {
startTime = System.currentTimeMillis();
}
public void stop() {
final long elapsed = (System.currentTimeMillis() - startTime);
if (elapsed < minTime) minTime = elapsed;
if (elapsed > maxTime) maxTime = elapsed;
totalTime += elapsed;
callCount++;
}
private String getFormattedStats(String format) {
final long avgTime = callCount == 0 ? 0 : (long) totalTime / callCount;
final long delta = maxTime - minTime;
final double deltaRatio = avgTime == 0 ? 0 : 100.0 * ((double) 0.5 * delta / (double) avgTime);
return String
.format(format, name, callCount, totalTime, avgTime, minTime, maxTime, delta, (int) deltaRatio);
}
@Override
public String toString() {
return getFormattedStats(FORMAT_STRING);
}
public static void writeCsvHeader(OutputStream os) throws IOException {
os.write(CSV_HEADERS.getBytes());
}
public void writeCsvLine(OutputStream os) throws IOException {
os.write(getFormattedStats(CSV_FORMAT_STRING).getBytes());
}
}
}
And sample usage:
Profiler.getInstance().start("marker1");
// Do something...
Profiler.getInstance().start("marker2");
// Something else...
Profiler.getInstance().stop("marker2");
// And some more...
Profiler.getInstance().stop("marker1");
// Output the profiling result
System.out.println(Profiler.getInstance().toString());
Call me old fashioned, but this is the simplest approach in my opinion:
long a, b, c, d;
a = System.currentTimeMillis();
// some code 1
b = System.currentTimeMillis();
// some code 2
c = System.currentTimeMillis();
// some code 3
d = System.currentTimeMillis();
System.out.println("Some code 1 took "+(b-a)+"mil to execute. ("+((b-a)/1000)+" seconds)");
System.out.println("Some code 2 took "+(c-b)+"mil to execute. ("+((c-b)/1000)+" seconds)");
System.out.println("Some code 3 took "+(d-c)+"mil to execute. ("+((d-c)/1000)+" seconds)");
Hope this helps :)
You could take a look at Yourkit (commercial software), which can monitor memory, CPU and many more. It has special view that show how much time was spent in methods (for example you can see that 40% of the execution time was spent in method xyz()).
The process of measuring which part of a programming takes how much runtime is called "profiling".
There are many profiling plugins for eclipse. One is described here.
there are some online tools like IdeOne which gives you the time taken for the block of code to execute. Give it a try!
