Reputation: 101
I have an android service in charge to update a clock and to execute specific task (as playing song) at different time.
I tried to use things like Timer.scheduleAtFixedRate(new MyTask(), 0, 1000L) but I got more than 4 minutes of delay in 1h.
Now I decided to:
1) record the start time using System.currentTimeMillis() in var long expectedtNextSystemMilli
2) add 1 second (1000 ms) to this var to get the next date/time to execute again the task
3) inside the runnable task compute delay between the "real system time" and the expected one from the var, to chedule the next execution of the task.
After several test, I noticed that there was also a probleme of delay and read in the documentation that the usage of System.currentTimeMillis() is discouraged to mesure elapsed time and we must use SystemClock.elapsedRealtime(). Also I did it and here below is the code of MyTask
private class MyTask extends TimerTask {
@Override
public void run() {
Log.i(TAG, "Timer doing work.");
try {
// compute the exact next expected system time when MyTask must be executed
expectedtNextSystemMilli += 1000L;
long delay = expectedtNextSystemMilli - SystemClock.elapsedRealtime() ;
// countdown update
counter = counter - 1;
// !!! sometimes android system is slow and more than 1s is spend before this method is called
// also we have to test and loop to catch up the delay
while ( delay < 0){
Log.e("TimerTick", "ERROR time spent by system in milli = " + delay + "> 1s ");
expectedtNextSystemMilli += 1000L;
delay = expectedtNextSystemMilli - SystemClock.elapsedRealtime() ;
counter = counter - 1;
}
// test if countdown is finished
if ( counter <=0 ){
mTimer.cancel();
onFinish();
}else{
// send message to listeners
onTick(counter);
// update the delay with the new system time (in case the call to onTick has been long)
delay = expectedtNextSystemMilli - SystemClock.elapsedRealtime() ;
// schedule the next execution of this task
mTimer.schedule(new MyTask(), delay);
Log.d("TimerTick", "new delay in milli is " + delay+", elapsedRealtime = "+ SystemClock.elapsedRealtime() );
}
} catch (Throwable t) { //you should always ultimately catch all exceptions in timer tasks.
Log.e("TimerTick", "Timer Tick Failed. Raison: "+ t.getMessage());
}
}
}
Tracing this code I was surprised to notice a jump of 28s returned by SystemClock.elapsedRealtime() as you may see
07-13 22:15:00.041: V/TimerManagerService(19377): onTick delay = 361 end , trace = 539
07-13 22:15:00.041: D/TimerTick(19377): new delay in milli is 999, elapsedRealtime = 84800078
07-13 22:15:01.041: I/TimerManagerService(19377): Timer doing work.
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -28585> 1s
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -27585> 1s
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -26586> 1s
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -25586> 1s
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -23587> 1s
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -22587> 1s
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -21588> 1s
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -20588> 1s
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -19589> 1s
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -18589> 1s
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -17589> 1s
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -16590> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -15590> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -14591> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -13591> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -12591> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -11592> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -10592> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -9592> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -8593> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -7594> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -6594> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -5595> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -4596> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -3596> 1s 07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -24586> 1s 07-13 22:15:01.051: E/TimerTick(19377): ERROR time spent by system in milli = -2597> 1s 07-13 22:15:01.051: E/TimerTick(19377): ERROR time spent by system in milli = -1598> 1s 07-13 22:15:01.051: E/TimerTick(19377): ERROR time spent by system in milli = -598> 1s 07-13 22:15:01.051: V/TimerManagerService(19377): onTick delay = 331 end , trace = 540
07-13 22:15:01.051: D/TimerTick(19377): new delay in milli is 400, elapsedRealtime = 84830677
07-13 22:15:01.450: I/TimerManagerService(19377): Timer doing work.
1) log at: 07-13 22:15:00.041: D/TimerTick(19377): new delay in milli is 999, elapsedRealtime = 84800078
is in run() just after the schedule schedule => mTimer.schedule(new MyTask(), delay);
2) schedule call the same run() but seems to spend more than 28s to do it
07-13 22:15:01.041: E/TimerTick(19377): ERROR time spent by system in milli = -28585 (ms)> 1s
notwithstanding that eclipse report only one second => 22:15:00.041 between the two calls 22:15:01.041
Also I guess what must do I use to get an accurate elasped time on android?
Upvotes: 4
Views: 2281
Reputation: 101
After deep investigation :) it appears tthat there is no real "good" solution, but several "best" solutions depending the goals.
In my case I needed to display linked count down (second precision) and to execute tasks as playing song at the end of each ones.
What happened when I used SystemClock.elapsedRealtime() is that after 1 hour there was frequently several minutes of delay.
Exemple:
start count down of 1 hour at 6:00:0.0 (looking the date on the smartphone)
end of count down at 7:04:11.0 instead of 7:00:00.0
Also I have to use Calendar .getTimeInMillis() which return the "official" date/time done by android OS.
I guess this date/time is resynchronized frequently using different techniques and so more accurate in my case.
Hope this may help ...
Upvotes: 2
Reputation: 724
The best way to fix it is using AlarmManager with BroadCastReceiver instead Timer.
Upvotes: 0