Simple java code measuring

Question

I am trying to simply measure my code execution time.

public class PerfMeasureUtil {

    private static final Logger LOG = Logger.getLogger(PerfMeasureUtil.class.getName());
    private long startTime;
    private long duration;
    private static final EnvironmentProperties env = new EnvironmentProperties();

    /**
     * start counting the time
     *
     * @return self
     */
    public PerfMeasureUtil start() {
        if (env.isDev()) {// || env.isTest()) {
            LOG.log(Level.INFO, "====================================== measurement starts");
            this.startTime = System.currentTimeMillis();
        }
        return this;
    }

    /**
     * stops counting the time and returns the result
     *
     * @param methodName
     * @return
     */
    public long stop(String methodName) {
        if (env.isDev()) {// || env.isTest()) {
            this.duration = System.currentTimeMillis() - startTime;
            LOG.log(Level.INFO, "====================================== {0}", methodName);
            LOG.log(Level.INFO, "time spend: {0}ms", duration);
            LOG.log(Level.INFO, "======================================");
            return duration;
        }
        return -1;
    }
}

EnvironmentProperties has a boolean property based on the Maven build type. The measurement should be executed only on dev, or maybe testing environment, not in production. Now I call it like this everywhere, where it is needed:

    PerfMeasureUtil measureUtil = new PerfMeasureUtil().start();
    foo = readFooFromSomewhere();
    bar.applyFoo();
    printResult(bar);
    measureUtil.stop("FooBarApplication.aplyFooOnBar");

Is there something that could be made clearly better? I am not sure about the permanent if-check even on other built types when it is not needed.

And of course the pollution of code is pretty bad with it, but this way I have more control on the code amount measured. Maybe annotation could help?

Answer 1

Return Value

I don't think it's a good idea to return PerfMeasureUtil in start. What would it even be used for? The code would look like this, which doesn't make much sense:

PerfMeasureUtil meassure = new PerfMeasureUtil();
meassure = meassure.start();
int time = meassure.stop("someName");

I could imagine using it as sort of a factory method:

public static PerfMeasureUtil start() {
    PerfMeasureUtil meassure = new PerfMeasureUtil();
    if (env.isDev()) {// || env.isTest()) {
        LOG.log(Level.INFO, "====================================== measurement starts");
        meassure.setStartTime(System.currentTimeMillis());
    }
    return meassure;
}

And then use it like this:

PerfMeasureUtil meassure = PerfMeasureUtil.start();
int time = meassure.stop("someName");

But I would probably prefer to just not return anything.

Dev check

If you want to reduce the amount of environment checks, you could actually use the factory approach from above, and check on object creation if you are in development mode. If not, return a dummy object whose methods do nothing.

Misc

• be consistent with your use of this. Currently, you use it sometimes, but not always.
• duration doesn't really need to be a field.
• I would add a comment on stop to mention what methodName does (that it's only used for logging).

Answer 2

The code you've put together so far looks decent. I agree with tim's feedback, as well.

One thing you might want to consider is that using milliseconds does not give you a lot of precision. A lot of methods will complete very quickly, so your tool would only be capable of successfully instrumenting groups of method calls. It'd be worth looking into a means by which you could get time at a higher level of precision with a reasonable degree of accuracy. Whether or not this matters will depend on how long the things you're planning on measuring usually take.

If you're only measuring things on the order of seconds, this should be more than fine. If you were looking at methods that might complete in a millisecond or two, your start time is only accurate to +/- .5 milliseconds, and your end time is only accurate to +/- .5 milliseconds, so in total you could be getting run duration measurements that are off by about a millisecond. If you're measuring something that's about a 2 millisecond duration, that could give you an error of about 50%, whereas if you're measuring something that takes 2 seconds you're only looking at an error of about 0.05%. For most purposes, a 0.05% error is completely tolerable, whereas an error of 50% is not.