Getting time it takes a method to run

Question

I'm getting weird results trying to use the method I usually use to get the duration:

float start = System.nanoTime();
//Do stuff
float duration = System.nanoTime() - start;
float durationInSeconds = duration / 1000000000.0f;

So I tried that in this flashlight app I'm making to create a strobe:

public void onClick(DialogInterface dialog, int id) {

                isFlashOn = true;
                isStrobeActive = true;

                // Perform actual strobe
                strobeHandler.post(new Runnable() {
                    float currDuration = 0;
                    final float deltaTime = 1/60f;
                    final float deltaTimeInMil = deltaTime * 1000;

                    @Override
                    public void run() {
                        float strobePerSecond = 1 / currentStrobeValue;

                        if (!isStrobeLightOn) {
                            if (currDuration > strobePerSecond) {
                                params = camera.getParameters();
                                params.setFlashMode(Parameters.FLASH_MODE_TORCH);
                                camera.setParameters(params);
                                currDuration -= strobePerSecond;
                                isStrobeLightOn = true;
                            }
                        } else {
                            params = camera.getParameters();
                            params.setFlashMode(Parameters.FLASH_MODE_OFF);
                            camera.setParameters(params);
                            isStrobeLightOn = false;
                        }
                        currDuration += deltaTime;
                        strobeHandler.postDelayed(this, (long) deltaTimeInMil);
                    }
                });
            }

The logs, however, return either 0.0 or 3.052E-5. I'm not exactly sure what I'm doing wrong, but I thing I need some help to figure it out. As always thanks.

Edit: I'm assuming that the start and end times are so similar, when they are subtracted and rounded, they are 0.

you could insert a Thread.sleep(1000) call to artificially bloat the running time, just to check if your timing code works... After all it might be just a quick call, doesn't look to complicated to me... — xmoex, Jun 20 '14 at 23:25
You ought to read this post: http://stackoverflow.com/questions/504103/how-do-i-write-a-correct-micro-benchmark-in-java — Raedwald, Jun 20 '14 at 23:33

ssedano · Answer 1 · 2014-06-21T00:11:26.667

0

Take a look at the byte code. Maybe the compiler is just stripping away the call. If that's the case just create a public volatile field and assign it inside the method or as a return value.

It is call dead-code elimination. It is not the only optimisation that might be performed.

Dissasemble the class file and take a look just in case. You can do that with javap.

Take a look at [1] and [2] for micro benchmarking advice.

[1] http://www.oracle.com/technetwork/java/hotspotfaq-138619.html#benchmarking_simple

[2] http://shipilev.net/talks/devoxx-Nov2013-benchmarking.pdf

edited Jun 21 '14 at 00:11

answered Jun 20 '14 at 23:21

ssedano

8,322
9
60
98

Why on earth would a call with potential side effects be stripped away? The would be a JVM bug of epic proportions. – Alvin Thompson Jun 20 '14 at 23:34

score 0 · Answer 2 · answered Jun 20 '14 at 23:22

I'm guessing because float is not accurate enough if numbers get too big. Why not use long like you're supposed to?

long start = System.nanoTime();
//Do stuff
long duration = System.nanoTime() - start;
double durationInSeconds = duration / 1000000000.0d;

score 0 · Answer 3 · edited May 23 '17 at 12:20

Three parts to the answer.

You should never subtract floating point numbers that are very close in value. You will get severe loss of precision, to the point of being useless. In this case, subtract the integers and convert to double only for displaying the result.
From what I can see of the code, it looks instantaneous -- in the microsecond range or below -- and the time function does not provide that level of resolution. You cannot get useful results this way.
Benchmark timing is subtle, complicated and confusing (even when it's behaving correctly!). Please read the reference provided and plan carefully. What are you trying to measure? How can you do it? What will you do with the results.

Reference: How do I write a correct micro-benchmark in Java?

Getting time it takes a method to run

3 Answers3