Why does a dummy Thread (only sleeping in short intervals) improve performance of another Thread?

Viewed 601

We are using the ScheduledExecutorService.scheduleAtFixedRate to perform an I/O Task every 100 ms. (The actual I/O Operation is performed by a third party library and we don't know exactly what is happening inside.)

Sometimes keeping up with the 100 ms intervals has some issues and we fall back to 500 ms. Since it is I/O, we weren't surprised, but we observed a strange behavior:

If a specific Thread runs, we are matching the 100 ms. If this thread is not running, we are falling back to 500 ms.

That specific Threads' run-method looks like this:

while(active){
  try {
    Thread.sleep(delay);
  } catch (InterruptedException e) {
    Thread.currentThread().interrupt();
    break;
  }
//some more stuff
}

Basically, when we use a short delay like 5 ms we get a better performance within the library. When we use longer delays like 1000 ms, performance is significantly worse.

It also seems to be platform-specific since we were not able to reproduce the problem (Java 8, Windows 10).

All that we know is that it's definitely the short sleep()-call causing the improvement since we could fix the issue by running a dummy thread just sleeping in short intervals.

Any explanation would be helpful to understand what is happening :-)

--- edit

Even more interesting: if we are adding not one but two new Threads only for short sleep intervals, it adds a little bit of performance. Not as significant as the first thread, but still like 20%.

--- edit 2

The System where we can observe the behavior: Intel Atom E3845 Windows 10

The System where we can't reproduce it: Intel i7-5820K Windows 10

We can't look up the source code but the library seems to run single-threaded (no new threads created) and creates a Socket connection.

1 Answers

It might be a multi-threading visibility problem (hard to say without knowing the involved source/library).

The example is based on code from thread how-to-demonstrate-java-multithreading-visibility-problems.

Executing the following code will lead in infinite execution of thread t.

public class Test extends Thread {

    boolean keepRunning = true;

    public static void main(String[] args) throws InterruptedException {
        Test t = new Test();
        t.start();
        Thread.sleep(1000);
        t.keepRunning = false;
        System.out.println(System.currentTimeMillis() + ": keepRunning is false");
    }

    public void run() {
        int i = 0;
        while (keepRunning) {
            i++;
        }
        System.out.println("iterations: " + i);
    }
}

Reason is that thread t keeps its own local state of keepRunning and never get the updated state.

If you amend the run method to

public void run() {
    int i = 0;
    while (keepRunning) {
        i++;
        System.out.println(i);
    }
    System.out.println("iterations: " + i);
}

it finish for example with

...
111955
111956
iterations: 111956
1582797899956: keepRunning is false

Q: How does this additional println statement change the behavior? A: System.out is a PrintStream and the println method is implemented as

public void println(boolean x) {
    synchronized (this) {
        print(x);
        newLine();
    }
}

The synchronized block lead to synchronization between the thread-local state and main memory.

Similar effect happen when you use a Thread.sleep(delay) instead.

public void run() {
    int i = 0;
    while (keepRunning) {
        i++;
        try {
            Thread.sleep(5);
        } catch(InterruptedException e) {
            System.out.println("interrupted");
            Thread.currentThread().interrupt();
        }
    }
    System.out.println("iterations: " + i);
}

example output

1582798987660: keepRunning is false
iterations: 197

You might try to replace the Thread.sleep(delay) by a System.out.println() statement to see if this would have a similar effect. Then it's most probably related to the above example.

edit To enforce that thread t gets the updated state the variable keepRunning can be declared as volatile.

public class Test extends Thread {

volatile boolean keepRunning = true;

public static void main(String[] args) throws InterruptedException {
    Test t = new Test();
    t.start();
    Thread.sleep(1000);
    t.keepRunning = false;
    System.out.println(System.currentTimeMillis() + ": keepRunning is false");
}

public void run() {
    int i = 0;
    while (keepRunning) {
        i++;
    }
    System.out.println("iterations: " + i);
}

}

example output

iterations: 1726941412
1582799612746: keepRunning is false
Related