String initialization and performance

Question

This is a performance related question:

In the repeatPrint1() method, I initialized some String attributes to null before using them in a loop. In the repeatPrint2() method, I initialized some String attributes directly inside the loop.

When I tested, the result was amazing - repeatPrint2() was performing better than repeatPrint1() up to almost 2500 records, but after that repeatPrint1() started performing better than repeatPrint2().

Can anyone explain why this happened? In a code review, what can we take as the correct way?

Code Snippet:

public static void main(String[] args) throws Exception {    
    long startTime1 = System.nanoTime();    
    repeatPrint1();
    long estimatedTime1 = System.nanoTime() - startTime1;
    long startTime2 = System.nanoTime();
    repeatPrint2();
    long estimatedTime2 = System.nanoTime() - startTime2;
    System.out.println("estimatedTime1: " + estimatedTime1);
    System.out.println("estimatedTime2: " + estimatedTime2);
}


private static void repeatPrint1() {
    String name1 = null;
    String name2 = null;
    String name3 = null;
    String name4 = null;
    String name5 = null;

    for(int x = 10; x < 2500; x = x + 1) {        
        name1 = "My Name is AAAA" + x;
        name2 = "My Name is BBBB" + x;
        name3 = "My Name is CCCC" + x;
        name4 = "My Name is DDDD" + x;
        name5 = "My Name is EEEE" + x;

        System.out.print("name1 : " + name1);
        System.out.print("name2 : " + name2);
        System.out.print("name3 : " + name3);
        System.out.print("name4 : " + name4);
        System.out.print("name5 : " + name5);

        System.out.println("value of x : " + x);         
    }     
}


private static void repeatPrint2() {     
    for(int x = 10; x < 2500; x = x + 1) {        
        String Sname1 = "My Name is AAAA" + x;
        String Sname2 = "My Name is BBBB" + x;
        String Sname3 = "My Name is CCCC" + x;
        String Sname4 = "My Name is DDDD" + x;
        String Sname5 = "My Name is EEEE" + x;

        System.out.print("Sname1 : " + Sname1 );
        System.out.print("Sname2 : " + Sname2 );
        System.out.print("Sname3 : " + Sname3 );
        System.out.print("Sname4 : " + Sname4 );
        System.out.print("Sname5 : " + Sname5 );

        System.out.println("value of x : " + x );        
    }     
}

Answer 1

The two approaches that you have given are basically identical. Your timings are being thrown off primarily because the JVM has not warmed up; hotspot does not kick in until a method or loop has been repeated over 10,000 times. After that many repetitions you can often also have GC kicking in adhoc, as well as OS processes in the mix too.

To address some of these problems in a benchmark, warm up each method over 10k times and repeat several times. For OS noise, be sure to shutdown as many other apps and processes as you can and make sure that the machine is running idle. The OS can of course be tuned too, but lets leave that as off topic for now. Below is some example code that will give you an idea, I have also added two more ways to optimise the loop; just for fun ;)

I include the timings that I got towards the bottom. The things to note are

1. the two approaches that you included start off varying, but normalise to being about the same pretty quickly
2. the cost of your code is being dwarfed by calls to System.out; in otherwords the io itself. to demonstrate that I have given two other alternatives, one that makes more calls to System.out and another that makes less.

estimatedTime1: 17.27938 ms

estimatedTime2: 17.45852 ms

estimatedTime3: 100.61994 ms

estimatedTime4: 9.553329999999999 ms

public class Foo {
    public static void main( String[] args ) throws Exception {
        time1();
        time2();
        time3();
        time4();

        time1();
        time2();
        time3();
        time4();

        time1();
        time2();
        time3();
        time4();
    }

    private static final int REPEAT = 100;

    private static void time1() {
        long startTime1 = System.nanoTime();
        for ( int i=0; i<REPEAT; i++ ) {
            repeatPrint1();
        }
        long estimatedTime1 = System.nanoTime() - startTime1;

        double dur = estimatedTime1/1000000.0/REPEAT;
        System.out.println( "estimatedTime1: " + dur );
    }

    private static void time2() {
        long startTime1 = System.nanoTime();
        for ( int i=0; i<REPEAT; i++ ) {
            repeatPrint2();
        }
        long estimatedTime1 = System.nanoTime() - startTime1;

        double dur = estimatedTime1/1000000.0/REPEAT;
        System.out.println( "estimatedTime2: " + dur );
    }

    private static void time3() {
        long startTime1 = System.nanoTime();
        for ( int i=0; i<REPEAT; i++ ) {
            repeatPrint3();
        }
        long estimatedTime1 = System.nanoTime() - startTime1;

        double dur = estimatedTime1/1000000.0/REPEAT;
        System.out.println( "estimatedTime3: " + dur );
    }

    private static void time4() {
        long startTime1 = System.nanoTime();
        for ( int i=0; i<REPEAT; i++ ) {
            repeatPrint4();
        }
        long estimatedTime1 = System.nanoTime() - startTime1;

        double dur = estimatedTime1/1000000.0/REPEAT;
        System.out.println( "estimatedTime4: " + dur );
    }



    private static void repeatPrint1() {

        String name1 = null;
        String name2 = null;
        String name3 = null;
        String name4 = null;
        String name5 = null;
        for ( int x = 10; x < 2500; x = x + 1 ) {

            name1 = "My Name is AAAA" + x;
            name2 = "My Name is BBBB" + x;
            name3 = "My Name is CCCC" + x;
            name4 = "My Name is DDDD" + x;
            name5 = "My Name is EEEE" + x;

            System.out.print( "name1 : " + name1 );
            System.out.print( "name2 : " + name2 );
            System.out.print( "name3 : " + name3 );
            System.out.print( "name4 : " + name4 );
            System.out.print( "name5 : " + name5 );

            System.out.println( "value of x : " + x );

        }

    }


    private static void repeatPrint2() {

        for ( int x = 10; x < 2500; x = x + 1 ) {

            String Sname1 = "My Name is AAAA" + x;
            String Sname2 = "My Name is BBBB" + x;
            String Sname3 = "My Name is CCCC" + x;
            String Sname4 = "My Name is DDDD" + x;
            String Sname5 = "My Name is EEEE" + x;

            System.out.print( "Sname1 : " + Sname1 );
            System.out.print( "Sname2 : " + Sname2 );
            System.out.print( "Sname3 : " + Sname3 );
            System.out.print( "Sname4 : " + Sname4 );
            System.out.print( "Sname5 : " + Sname5 );

            System.out.println( "value of x : " + x );

        }
    }



    private static void repeatPrint3() {
        for ( int x = 10; x < 2500; x = x + 1 ) {
            pr1( 1, x, "AAAA" );
            pr1( 2, x, "BBBB" );
            pr1( 3, x, "CCCC" );
            pr1( 4, x, "DDDD" );
            pr1( 5, x, "EEEE" );
            xr1( x );
        }
    }
    private static void pr1( int i, int x, String r ) {
        System.out.print( "Sname" );
        System.out.print( '0'+i );
        System.out.print( " : " );
        System.out.print( "My Name is " );
        System.out.print( r );
        System.out.println( Integer.toString(x) );
    }
    private static void xr1( int x ) {
        System.out.print( "value of x : " );
        System.out.println( Integer.toString(x) );
    }

    private static void repeatPrint4() {
        StringBuilder buf = new StringBuilder( 400 );

        for ( int x = 10; x < 2500; x = x + 1 ) {
            pr2( buf, 1, x, "AAAA" );
            pr2( buf, 2, x, "BBBB" );
            pr2( buf, 3, x, "CCCC" );
            pr2( buf, 4, x, "DDDD" );
            pr2( buf, 5, x, "EEEE" );
            xr2( buf, x );

            System.out.print( buf.toString() );

            buf.setLength( 0 );
        }
    }

    private static void pr2( StringBuilder buf, int i, int x, String r ) {
        buf.append( "Sname" );
        buf.append( '0' + i );
        buf.append( " : " );
        buf.append( "My Name is " );
        buf.append( r );
        buf.append( Integer.toString( x ) );
        buf.append( "\n" );
    }
    private static void xr2( StringBuilder buf, int x ) {
        buf.append( "value of x : " );
        buf.append( Integer.toString( x ) );
        buf.append( "\n" );
    }

}

Answer 2

The main reason is that performance is a random variable, so, if you have reliable data to elaborate on, you may first want to produce a reasonable number of data points, so that you can perform a statistical analysis.

Answer 3

Read the byte code using javap and compare the two method transformation.

From the code you posted, I think it will be pretty much the same: the compiler should move the local variable (as in repeatPrint2) to the top of method.

What you encountered is probably the JIT compiler kick in and optimizing your code on the fly.

And I would personally prefer declaring variable in the scope it's used rather than in the outer scope (eg: like repeatPrint2): this is better for readability and for refactoring.

Answer 4

Have a look at this question, which describes how to setup a good microbenchmark.

Two important points are:

• Have a warmup phase where you call your methods for some ten thousand times.
  This way the JIT will cache the method.
• There will be a difference if you call repeatPrint1() before repeatPrint2() and vice versa

The results you are getting with your code will differ at any run. Spend some time to setup a good benchmark to have valueable results.