Pierre_C
Pierre_C

Reputation: 101

With what could we replace SystemClock.elapsedRealtime() to get a reliable time?

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

Answers (2)

Pierre_C
Pierre_C

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

Android Android
Android Android

Reputation: 724

The best way to fix it is using AlarmManager with BroadCastReceiver instead Timer.

Upvotes: 0

Related Questions