4
\$\begingroup\$

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?

\$\endgroup\$
  • \$\begingroup\$ Please state only the code's purpose in the title. \$\endgroup\$ – Jamal Mar 27 '15 at 13:59
  • \$\begingroup\$ Annotations could help, if you are using something like AspectJ maybe. \$\endgroup\$ – bhathiya-perera Mar 27 '15 at 14:02
  • \$\begingroup\$ @Jamal do you mean that "java" should be excluded? by the way thanks for correcting text :) \$\endgroup\$ – Zavael Mar 27 '15 at 14:48
  • 1
    \$\begingroup\$ Refer to this post regarding titles. My mistake for not providing it sooner. \$\endgroup\$ – Jamal Mar 27 '15 at 15:06
3
\$\begingroup\$

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).
\$\endgroup\$
  • \$\begingroup\$ the returning of object is because I can have some inline measurment (run1...run2...run2.stop...run1.stop), so it is important to know on which instance I am calling the stop method. But the factory method is nice simplification... I was inspired by the builder pattern when returning object from start method and so I achieved a one-liner initialization + starting (with the option to restart if needed). The dummy object is great.. will try it. Your Misc are true, there are some artifacts from previous version (duration was stoptime first - therefore it was field :) ) \$\endgroup\$ – Zavael Mar 27 '15 at 14:45
3
\$\begingroup\$

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.

\$\endgroup\$
  • 1
    \$\begingroup\$ Yes that was something i thought about, but afterwards for simplicity and purpose (catch the longest methods ie above few seconds) I choose that milis will serve \$\endgroup\$ – Zavael Mar 27 '15 at 14:48
  • 1
    \$\begingroup\$ In that case, milliseconds will be more than good enough. I updated my answer to include information comparing measurements of things taking seconds versus measurements of things taking milliseconds and comparing the errors for informative purposes. \$\endgroup\$ – Dogs Mar 27 '15 at 15:07

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.