c# observable interval skips ticks

Question

in my code I need to have a long running timer to start some routine every first second of every minute. I tried to use System.Timers.Timer, but it is not very useful because of timer drift. So I've implemented a timer from Reactive extensions which ticks every 200ms and put some logic on the beginning of the routine:

IObservable<Timestamped<long>> observable = Observable.Interval(TimeSpan.FromMilliseconds(200), Scheduler.NewThread).Timestamp();
IDisposable subscription = observable.Subscribe(x => calculator.Calculate(x.Timestamp));

Then in Calculate method:

public void Calculate(DateTimeOffset timeElapsed)
{
    if (timeElapsed.Second != 1)
    {
        Log.Trace("Skip calc: second != 1. {0}", timeElapsed);
        return;
    }
    if ((timeElapsed.LocalDateTime - lastRun).TotalSeconds < 59)
    {
        Log.Trace("Skip calc: interval < 60sec.");
        return;
    }
    lastRun = timeElapsed.LocalDateTime;

    var longRunningTask = new Task(() => CalcRoutine(timeElapsed), token);
    longRunningTask.Start(); 
    //etc..
}

The problem is, that sometimes without any understandable reasons this timer skips about 7 ticks. In this specific case 2 last ticks are missing in 7:57:00 and whole 7:57:01 second is missing:

2015-05-22 07:56:59.1550|Skip calc: second != 1. 22.5.2015 7:56:59 +02:00
2015-05-22 07:56:59.3578|Skip calc: second != 1. 22.5.2015 7:56:59 +02:00
2015-05-22 07:56:59.5606|Skip calc: second != 1. 22.5.2015 7:56:59 +02:00
2015-05-22 07:56:59.7634|Skip calc: second != 1. 22.5.2015 7:56:59 +02:00
2015-05-22 07:56:59.9662|Skip calc: second != 1. 22.5.2015 7:56:59 +02:00
2015-05-22 07:57:00.1534|Skip calc: second != 1. 22.5.2015 7:57:00 +02:00
2015-05-22 07:57:00.3562|Skip calc: second != 1. 22.5.2015 7:57:00 +02:00
2015-05-22 07:57:00.5590|Skip calc: second != 1. 22.5.2015 7:57:00 +02:00
2015-05-22 07:57:02.1502|Skip calc: second != 1. 22.5.2015 7:57:02 +02:00
2015-05-22 07:57:03.3671|Skip calc: second != 1. 22.5.2015 7:57:03 +02:00

This behavior is not regular. It happens at random time from one up to three times a day. CPU load in that moments is normal without spikes. Disks are OK too. I am unable to repeat it on my computer. Furthermore, there is another instance of same application, that has less job to do, and it works perfectly fine. Applications are restarted every day at midnight.

What may cause this problem?

UPD: Complete code

static void Main(string[] args)
{
    var calculatorReact = new Calculator();
    IObservable<Timestamped<long>> observable = Observable.Interval(TimeSpan.FromMilliseconds(200)).Timestamp();
    IDisposable subscription = observable.Subscribe(x => calculatorReact.Calculate(x.Timestamp));

    Console.ReadLine();
 }

 public class Calculator
 {
     DateTime lastRun = DateTime.Now.AddDays(-1);
     public void Calculate(DateTimeOffset timeElapsed)
     {
         //start calcuation on the 1st second of every minute
         if (timeElapsed.Second != 1)
         {
             Console.WriteLine("Skip calc: second != 1. {0}", timeElapsed);
             return;
         }

         if ((timeElapsed.LocalDateTime - lastRun).TotalSeconds < 59)
         {
             Console.WriteLine("Skip calc: interval < 60sec.");
             return;
         }
         lastRun = timeElapsed.LocalDateTime;

         var tokenSource = new CancellationTokenSource();
         CancellationToken token = tokenSource.Token;
         var longRunningTask = new Task(() => { 
                Console.WriteLine("Calulating..");
         }, token);
         longRunningTask.Start(); 

        }
    }

UPD2 The problem was in time synchronization on that server. For some internal reasons we had to use our custom software, that shifts the system clocks rapidly when it finds a difference. So it can easily shift time from 7:57:00 to 7:57:02.

Sorry for taking your time.

The signature for your `.Subscribe(...)` call doesn't match the signature for the `Calculate` method. Can you please provide [minimal, complete, and verifiable](http://stackoverflow.com/help/mcve) code please? — Enigmativity, May 22 '15 at 07:53
Sorry. It should be `IDisposable subscription = observable.Subscribe(x => calculator.Calculate(x.Timestamp));` — S K, May 22 '15 at 08:46
Your code is still not complete. I'm trying to run it in LINQPad, but there are too many missing items. Can you please post the code that will run and produce your results? — Enigmativity, May 22 '15 at 09:12
I've posted code. It works in general. But my question was about random timer failures. — S K, May 22 '15 at 10:34
Thanks for posting the code. Now it seems to me that you're telling the code to skip all timestamps where the seconds are `1`. So in your question when you say "whole 7:57:01 second is missing" it's because you are telling it to miss. — Enigmativity, May 23 '15 at 00:23
@Enigmativity It's absolutely opposite. I skip everything except 1st second. And as I said before, the error is not constant. It occurs two-three times a day. The rest `24h*60min -2 = 1438` minutes are calculated without any problem. — S K, May 25 '15 at 07:39
Hi @skorchakov ! Can you post your own answer to this question so it will be removed from the Unanswered section :) Thanks — supertopi, Sep 13 '15 at 09:29
Well. There is no working solution yet. I guess there is something with time synchronization on that PC. If you shift clocks by a few seconds forward, timer will not fire those events. But different behavior of two same applications doesn't make sense. — S K, Sep 17 '15 at 08:56

score 0 · Answer 1 · answered May 22 '15 at 13:10

0

Matching timer based values using exact match is inherently unreliable because of the unpredictable rounding errors. This is pretty much the same as working with floating point numbers. You should never do x == 1.0. What you should do instead is abs(x-1.0) < 0.00001. This way you can take out of the picture small rounding errors by introducing some tolerances.

In you case I think you can do the same: instead of working with seconds work with milliseconds, or, better yet directly with ticks, and instead of comapring to an exact value introduce some tolerances

answered May 22 '15 at 13:10

mfeingold

7,094
4
37
43

Thanks for your comment. But I already use 200 millisecond intervals. So I have about 5 timer ticks per second. – S K May 22 '15 at 14:12
The root of the problem is that you compare for the exact match, reducing the interval by itself would not solve it – mfeingold May 22 '15 at 22:44
DateTimeOffset.Second is Integer, not double. So comparing it with 1 should not be a problem. The point is, that I log every step of Calculate method (skip when second != 1, skip when interval since last calculation is small and calculation itself), but due to a unknown reason few counter steps are missing. There is nothing in the log between 7:57:00 and 7:57:02. – S K May 25 '15 at 07:31

c# observable interval skips ticks

1 Answers1