views:

307

answers:

3

I just wrote a whole blurb on how I reached this point, but figured it's easier to post the code and leave it at that :)

As far as I can tell, the performance of test3() should be the same as test1() - the only difference is where the exception is caught (inside the calling method for test1(), inside the called method for test3())

Why does test3() regularly take time somewhere between test1() and test2() to complete?

import java.io.UnsupportedEncodingException;
import java.net.URLEncoder;

public class Test {

    public static void main(String[] args) {
        warmup(); 
        test1(2500000); // Exception caught inside the loop
        test2(2500000); // Exception caught outside the loop
        test3(2500000); // Exception caught "inside" the loop, but in the URLEncoder.encode() method
    }

    private static void warmup() {
        // Let URLEncoder do whatever startup it needs before we hit it
        String encoding = System.getProperty("file.encoding");
        try {
            URLEncoder.encode("ignore", encoding);
        } catch (UnsupportedEncodingException e) {
            // TODO Auto-generated catch block
            e.printStackTrace();
        }
    }

    private static void test1(int count) {
        String encoding = System.getProperty("file.encoding");
        long start = System.currentTimeMillis();
        for (int i = 0; i < count; i++) {
            try {
                URLEncoder.encode("test 1 " + i, encoding);
            } catch (UnsupportedEncodingException e) {
                // TODO Auto-generated catch block
                e.printStackTrace();
            }
        }
        long end = System.currentTimeMillis();
        System.out.println("Performed " + count + " encodings trying to catch each in " + (end - start) + "ms");
    }

    private static void test2(int count) {
        String encoding = System.getProperty("file.encoding");
        long start = System.currentTimeMillis();
        try {
            for (int i = 0; i < count; i++) {
                URLEncoder.encode("test 2" + i, encoding);
            }
        } catch (UnsupportedEncodingException e) {
            // TODO Auto-generated catch block
            e.printStackTrace();
        }
        long end = System.currentTimeMillis();
        System.out.println("Performed " + count + " encodings trying to catch all in " + (end - start) + "ms");
    }

    private static void test3(int count) {
        long start = System.currentTimeMillis();
        for (int i = 0; i < count; i++) {
            URLEncoder.encode("test 3 " + i);
        }
        long end = System.currentTimeMillis();
        System.out.println("Performed " + count + " encodings with a deprecated method in " + (end - start) + "ms");
    }

}

Running it gives me (JDK 1.6.0_13 on Windows XP) the output:

Performed 2500000 encodings trying to catch each in 4906ms
Performed 2500000 encodings trying to catch all in 2454ms
Performed 2500000 encodings with a deprecated method in 2953ms

So, responses are pretty close (we're talking something that's so trivial it's irrelevant), btu I'm curious!

Later...

People have suggested that there's JVM optimization getting in the way - I agree. So, I've broken each test down into it's own class/main method and each individually. The results from this:

1 - Performed 2500000 encodings trying to catch each in 5016ms
1 - Performed 5000000 encodings trying to catch each in 7547ms
1 - Performed 5000000 encodings trying to catch each in 7515ms
1 - Performed 5000000 encodings trying to catch each in 7531ms

2 - Performed 2500000 encodings trying to catch all in 4719ms
2 - Performed 5000000 encodings trying to catch all in 7250ms
2 - Performed 5000000 encodings trying to catch all in 7203ms
2 - Performed 5000000 encodings trying to catch all in 7250ms

3 - Performed 2500000 encodings with a deprecated method in 5297ms
3 - Performed 5000000 encodings with a deprecated method in 8015ms
3 - Performed 5000000 encodings with a deprecated method in 8063ms
3 - Performed 5000000 encodings with a deprecated method in 8219ms

Interesting observations:

  • The gap between catching each call versus catching everything outside of the loop is reduced in it's own JVM (I assume optimization is not going the whole hog in the all-tests-in-one case due to the other iterations that have been performed)
  • The gap between the try/catch on my side versus the try/catch inside URLEncoder.encode() is now much smaller (half a second over 5000000 iterations) but still consistantly there...
+1  A: 

Running it in the order you posted:

Performed 2500000 encodings trying to catch each in 34208ms
Performed 2500000 encodings trying to catch all in 31708ms
Performed 2500000 encodings with a deprecated method in 30738ms

Reversing the order:

Performed 2500000 encodings with a deprecated method in 32598ms
Performed 2500000 encodings trying to catch all in 31239ms
Performed 2500000 encodings trying to catch each in 31208ms

Therefore I don't actually think you're seeing what you think you're seeing (certainly, test1 is not 66% slower than test3, which is what your benchmarks suggest)

Catchwa
Hmm... I've broken out each test into it's own main class, so there can't be any optimization between tests getting in the way, I see:1 - Performed 2500000 encodings trying to catch each in 5016ms1 - Performed 5000000 encodings trying to catch each in 7547ms2 - Performed 2500000 encodings trying to catch all in 4719ms2 - Performed 5000000 encodings trying to catch all in 7250ms3 - Performed 2500000 encodings with a deprecated method in 5297ms3 - Performed 5000000 encodings with a deprecated method in 8015msThe deprecated test is still slightly slower. Again, only minutely! :/
Martin
Blah - being a comment screwed up the formatting... See the original text for an update
Martin
A: 

Yeah you have your explanation, I think:

3 is slightly slower than 1 due to the extra method call involved.

2 is faster than either since it does not 'set up' and 'tear down' exception-catching-related bytecode in each loop. You can crack open the byte code to see the difference with javap -- see http://www.theserverside.com/tt/articles/article.tss?l=GuideJavaBytecode

Whether you use 2 or 1 depends on which behavior you want, since they are not equivalent. I would choose 1 over 3 since you are then not using a deprecated method, which is more important than tiny speed increases -- but as it happens 1 is faster anyhow.

Sean Owen
A: 

Please correct me, but the test2 for-loop executes only 1 step, because of the throwing exception and test1 caught the exception inside the loop and is executed 2500000 times.

When you catch the exception outside the loop, the loop will not start again. Print out "int i" to be sure how many steps the loop made.

The third one is the slowest, because the method delegates the call to the deprecated method.

Markus Lausberg
The exception is never actually thrown - the encoding is valid for all of them - it's more of a question of "what's the JVM doing in case it is thrown" (printing out something on each loop verifies this)
Martin
thanks Martin, i though the exception would thrown.
Markus Lausberg