0

I'm seeing some strange behaviour in Java:
Commenting a println makes the function execute slower.
Uncommenting the println makes the function execute faster.

I would expect this to be reversed, as println should cost time.

The trigger is the System.out.println(""); in the sequentialProcessData function.
With the line commented I get 2.5 secs.
With the line uncommented I get 1.9 secs.

The behaviour is independent of using nanotime() or currentTimeMillis() to measure time.

Also, I could not reproduce the behaviour when triggering the println with a flag.

Tested with Eclipse, jdk1.7.0_51 (JavaSE), Windows 7 (8 cores in case that matters).

Thanks

EDIT
This behaviour only occurs for me when I compile the code in Eclipse. (running in Eclipse and in the shell both have this strange behaviour)
If I compile in the shell (javac Main.java), then the behaviour is normal, i.e. the println version is slower (by about 1 secs).

So something strange with the Eclipse compiler?

Code:

import java.util.Random;

public class Main {

  public static void main(String[] args) {

    // Generate Data Matrix with random numbers
    int ROWS = 10000;
    int COLS = 40;
    double[][] data = generateData(ROWS,COLS);

    //Variables
    long start_main;
    long end_main;

    // Time consuming function
    start_main = System.nanoTime();

    sequencialProcessData(data);

    end_main = System.nanoTime();
    System.out.println("main duration: " + (end_main - start_main)*Math.pow(10, -9) + " secs");

  }

  static double[][] sequencialProcessData(double[][] data) {

    double[][] result = new double[data.length][data[0].length];

    for(int col = 0; col < data.length; ++col) {
      for(int row = 0; row < data[col].length; ++row) {
        for(int i = 0; i <= row; ++i) {
          result[col][row] += data[col][i]; 
        }
      }
    }

    // TRIGGER : COMMENT and UNCOMMENT THIS to see a difference in performance
//    System.out.println("");

    return result;
  }

  static double[][] generateData(int ROWS,int COLS) {

    double[][] data = new double[COLS][ROWS];

    Random random = new Random();
    for(int col = 0; col < COLS; ++col) {
      for(int row = 0; row < ROWS; ++row) {
        data[col][row] = random.nextDouble();
      }
    }

    return data;
  }

}
Caffeinated
  • 11,982
  • 40
  • 122
  • 216
imran
  • 247
  • 2
  • 11
  • Have you run the example enough number of times with and without the `println` ? – Svetlin Zarev Feb 25 '14 at 15:13
  • 1
    Something else was going on, if you test it enough you'll probably find it was just measurement error. I ran it 10 times each way (from a command shell using bash), no significant variation. – T.J. Crowder Feb 25 '14 at 15:18
  • I tried your code on my machine, but I am unable to reproduce the problem you have. I get for both versions similar times; very slightly more for the println version. Please make sure you don't have any application running that influences your measurement. Also everything lower than milliseconds can be considered garbage unless you run it several 100 times and check the average time. – Mike de Dood Feb 25 '14 at 15:24
  • I ran it about 30 times each way (manually), EVERYTIME getting the stated results: between 1.9 and 2 secs with println and between 2.5 and 2.6 secs without println – imran Feb 25 '14 at 15:34
  • I ran from inside Eclipse...maybe I should try from shell (DOS)...will report with that – imran Feb 25 '14 at 15:35
  • The strange behaviour only comes when I compile the java code in Eclipse (that is, when I make a change and run in Eclipse, it automatically compiles a new .class), which then has the strange behaviour both in the shell and in eclipse. If I compile in the shell (javac Main.java) then the behaviour is fine, i.e. the version with println is slower (by about one second). – imran Feb 25 '14 at 15:57
  • Are you quite sure that you're using the exact same version of Java inside Eclipse as you're using on the command line? Do you have the Java compliance checking in Eclipse set to the same version as the compiler? – EdwinW Feb 25 '14 at 16:17
  • @EdwinW - yes, as far as I can see, I am using jdk1.7.0_51 on shell (javac -version and java - version) and same JRE version in Eclipse. Also the compliance level in Eclipse is 1.7. So I used javac -target 1.7 -source 1.7 Main.java in shell, with same results....but now I am thinking there might be so many options in Eclipse with make this behaviour...I am actually happy its not happening in shell – imran Feb 26 '14 at 08:17
  • Hmm Yeah I'm struggling to reproduce your results as well. Using jdk1.8.0_45 in Eclipse, I get ~1.8 with println and ~1.79sec without. – Dylan Watson Aug 24 '16 at 04:08

0 Answers0