Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > comp.lang.java.programmer > #36946

Different way of printing makes code twice as fast

Show key headers only | View raw

I have a very strange problem with the code below. If I run it like it
is, I get:
    15:41:34: Warming up
    15:41:34: took 2.46E+00 seconds.
    15:41:37: took 2.47E+00 seconds.
    15:41:39: took 2.45E+00 seconds.
    15:41:42: Real work
    15:41:42: took 5.26E+00 seconds.
    15:41:47: took 5.22E+00 seconds.
    15:41:52: took 5.28E+00 seconds.
    15:41:58: took 5.25E+00 seconds.
    15:42:03: took 5.28E+00 seconds.

When I change the first:
    System.out.print(getCurrentTime() + ": ");
to:
    System.out.printf("%s: ", getCurrentTime());

I get:
    15:43:52: Warming up
    15:43:52: took 2.47E+00 seconds.
    15:43:54: took 2.49E+00 seconds.
    15:43:57: took 2.50E+00 seconds.
    15:43:59: Real work
    15:43:59: took 2.46E+00 seconds.
    15:44:02: took 2.49E+00 seconds.
    15:44:04: took 2.50E+00 seconds.
    15:44:07: took 2.50E+00 seconds.
    15:44:09: took 2.49E+00 seconds.

What could be happening here?


public class Problem {
    // ################ main
    public static void main(final String[] args) {
        final float DIVIDER          = 1_000_000_000;

        System.out.printf("%s: Warming up\n", getCurrentTime());
        for (int r = 0; r < 3; ++r) {
            long tDuration;
            long tStart;

            System.out.print(getCurrentTime() + ": ");
            // System.out.printf("%s: ", getCurrentTime());
            tStart = System.nanoTime();
            for (int ir = 0; ir < INNER_REPEATS; ++ir) {
                test();
            }
            tDuration = System.nanoTime() - tStart;
            System.out.printf("took %.2E seconds.\n", tDuration / DIVIDER);
        }
        System.out.printf("%s: Real work\n", getCurrentTime());
        for (int r = 0; r < 5; ++r) {
            long tDuration;
            long tStart;

            System.out.print(getCurrentTime() + ": ");
            // System.out.printf("%s: ", getCurrentTime());
            tStart = System.nanoTime();
            for (int ir = 0; ir < INNER_REPEATS; ++ir) {
                test();
            }
            tDuration       = System.nanoTime() - tStart;
            System.out.printf("took %.2E seconds.\n", tDuration / DIVIDER);
        }
    }


    // ################ constructors
    // Do not allow initiation
    private Problem() {
    }


    // ################ private
    private static String getCurrentTime() {
        return String.format("%tT", System.currentTimeMillis());
    }

    private static final int INNER_REPEATS  = 100_000_000;


    // ################ functions to test
    private static final Long test() {
        long sum = 0L;

        for (int i = 0; i < 80; ++i) {
            sum += i;
        }
        return sum;
    }

}

-- 
Cecil Westerhof
Senior Software Engineer
LinkedIn: http://www.linkedin.com/in/cecilwesterhof

Back to comp.lang.java.programmer | Previous | Next — Next in thread | Find similar | Unroll thread

Thread

Different way of printing makes code twice as fast Cecil Westerhof <Cecil@decebal.nl> - 2017-07-15 15:55 +0200
  Re: Different way of printing makes code twice as fast j4n bur53 <janburse@fastmail.fm> - 2017-07-16 02:35 +0200

csiph-web