Java thread execution order when using Timer and TimerTask

Question

I'm using Timer as an process interrupt mechanism. The flow of logic is as follows:

T0: create new timer at T0 and schedule a new timer task to execute at T2 (1 second task delay, task is very simple - sets a flag variable)

T1: in the main calling thread, sleep for 5 seconds

T2: in the timer thread, task executes

T5: sleep finishes

T6: cancel timer and any scheduled tasks

The code works perfectly on my Windows and Ubuntu dev environment. But when I run the same code on my SLES 10 build server, logging indicates this execution order:

T0: timer and timer tasks are created to execute at T2

T1: main thread sleeps for 5 seconds

T5: main thread wakes up

T6: timer cancels

T7: task executes

Could anyone offer an explanation as to why this occurs? Thanks very much.

Answer 1

Hm. I'm surprised that you see that much difference (in seconds?), but I guess it is possible that you see different order of execution from machine to machine, jvm to jvm etc. Especially, when the JIT is compiling your code for the first time, I tend to see delay (compared to subsequent execution of same code) in the order of 100-300ms in my code for example, so maybe it's more dramatic in your code?

Not sure what you mean with "process interrupt mechanism". Do you mean that the timer task interrupts some thread?

Anyways, what I can suggest now is to use System.nanoTime() instead. (Although I don't think it will explain anything, Use of System.currentTimeMillis() is discouraged in serious measurements). Addition of -server to your JAVA_OPTS is generally advised so that you see the behavior when the code is optimized by JIT. It is also highly advisable to run your code multiple times and take statistics.

If I were you, I'll do these small things first, then debug using synchronizers like CyclicBarrier, CountdownLatch and see where exactly the delay is coming.

What are the "background noise" (degree of activity) in the SLES? Maybe the OS is very very busy or something?

What is the task's nature? Is it anything network/IO related?

Answer 2

It turned out it was a timestamp issue. Using new Date().getTime instead of System.currentTimeMillis yielded the expected order of execution timestamps.

Thanks for all the good ideas.

Answer 3

You should consider firing an event when the tasks are complete. That ensures execution order.