System.Threading.Timer fires callback erratically

Question

I wrote a class named DoubleAnimator that changes a double value from a start value to an end value over a period.

This class is based on a System.Threading.Timer to change and report the value.

I noticed that, mainly for first uses, the timer's callback will execute almost exactly every second instead of the asked 50 ms.

I timed the callback, to know if it took more than the interval to execute, but it takes between 0 and 3 ms.

Here is the class:

/// <summary>
/// DoubleAnimator animates a double value from a specified value to another one in the specified time-frame
/// </summary>
public class DoubleAnimator : IDisposable, IAnimator
{
#if DEBUG
    private readonly Logger _logger;
#endif

    private readonly double _startValue;
    private readonly double _endValue;
    private readonly TimeSpan _duration;
    private System.Threading.Timer _timer;
    private readonly double _incrementPerAnimation;
    private readonly TimeSpan _durationBetweenAnimations;

    private double _animatedValue;
    public double AnimatedValue
    {
        get { return _animatedValue; }
    }


    public DoubleAnimator(double startValue, double endValue,
                          TimeSpan duration, int numberOfAnimations)
    {
        if (numberOfAnimations <= 0)
        {
            throw new InvalidOperationException("Number of animation should be superior to 0");
        }
#if DEBUG
        _logger = new Logger();
#endif
        _startValue = startValue;
        _endValue = endValue;
        _duration = duration;
        _animatedValue = _startValue;
        _durationBetweenAnimations = TimeSpan.FromTicks(duration.Ticks / numberOfAnimations);
#if DEBUG
        _logger.Debug($"Duration between animations: {_durationBetweenAnimations.TotalMilliseconds}ms. Calcul: {duration.TotalMilliseconds}ms/{numberOfAnimations}");
#endif
        _incrementPerAnimation = (_endValue - _startValue) / numberOfAnimations;
    }

    public void Dispose()
    {
        _timer?.Dispose();
    }

    public void Start()
    {
        if (_timer != null) return;
        _timer = new System.Threading.Timer(Animate, null, TimeSpan.Zero, _durationBetweenAnimations);
    }

    public void Abort()
    {
        if (_timer == null) return;
        _timer.Change(Timeout.Infinite, Timeout.Infinite);
    }

    private void Animate(object state)
    {


#if DEBUG
        Stopwatch sw = new Stopwatch();
        sw.Start();
#endif
        try
        {
#if DEBUG
            _logger.Debug("Animating...");
#endif
            _animatedValue += _incrementPerAnimation;
            bool animationFinished = false;
            if (_endValue > _startValue)
            {
                animationFinished = _animatedValue > _endValue;
            }
            else
            {
                animationFinished = _animatedValue < _endValue;
            }


            if (animationFinished)
            {
                _animatedValue = _endValue;
                _timer.Change(Timeout.Infinite, Timeout.Infinite);
                OnProgressChanged(_animatedValue); //Useful?
                OnCompleted();
            }
            else
            {
#if DEBUG
                _logger.Debug($"Notification of progress with value {_animatedValue}");
#endif
                OnProgressChanged(_animatedValue);
            }
        }
        finally
        {
#if DEBUG
            _logger.Debug($"Time for executing Animate: {sw.ElapsedMilliseconds}ms.");
#endif
        }
    }

    public event EventHandler<EventArgs> Completed;

    private void OnCompleted()
    {
        Completed?.Invoke(this, EventArgs.Empty);
    }

    public event EventHandler<ValueEventArgs> ProgressChanged;

    private void OnProgressChanged(double progress)
    {
        ValueEventArgs arg = new ValueEventArgs(progress);
        ProgressChanged?.Invoke(this, arg);
    }
}

And an excerp of the output log file:

Debug;06-02-2020 11:23:11.612;;Duration between animations: 50ms. Calcul: 500ms/10
Debug;06-02-2020 11:23:12.215;;Animating...
Debug;06-02-2020 11:23:12.215;;Notification of progress with value 0,1
Debug;06-02-2020 11:23:12.215;;Time for executing Animate: 0ms.
Debug;06-02-2020 11:23:13.214;;Animating...
Debug;06-02-2020 11:23:13.214;;Notification of progress with value 0,2
Debug;06-02-2020 11:23:13.215;;Time for executing Animate: 0ms.
Debug;06-02-2020 11:23:14.213;;Animating...
Debug;06-02-2020 11:23:14.213;;Notification of progress with value 0,3
Debug;06-02-2020 11:23:14.213;;Time for executing Animate: 0ms.
Debug;06-02-2020 11:23:15.213;;Animating...
Debug;06-02-2020 11:23:15.213;;Notification of progress with value 0,4
Debug;06-02-2020 11:23:15.213;;Time for executing Animate: 0ms.
Debug;06-02-2020 11:23:16.215;;Animating...
Debug;06-02-2020 11:23:16.215;;Notification of progress with value 0,5
Debug;06-02-2020 11:23:16.215;;Time for executing Animate: 0ms.
Debug;06-02-2020 11:23:17.215;;Animating...
Debug;06-02-2020 11:23:17.215;;Notification of progress with value 0,6
Debug;06-02-2020 11:23:17.216;;Time for executing Animate: 0ms.
Debug;06-02-2020 11:23:18.215;;Animating...
Debug;06-02-2020 11:23:18.215;;Notification of progress with value 0,7
Debug;06-02-2020 11:23:18.216;;Time for executing Animate: 0ms.
Debug;06-02-2020 11:23:19.215;;Animating...
Debug;06-02-2020 11:23:19.215;;Notification of progress with value 0,8
Debug;06-02-2020 11:23:19.216;;Time for executing Animate: 0ms.
Debug;06-02-2020 11:23:20.213;;Animating...
Debug;06-02-2020 11:23:20.214;;Notification of progress with value 0,9
Debug;06-02-2020 11:23:20.214;;Time for executing Animate: 0ms.
Debug;06-02-2020 11:23:21.214;;Animating...
Debug;06-02-2020 11:23:21.214;;Notification of progress with value 1
Debug;06-02-2020 11:23:21.215;;Time for executing Animate: 0ms.

You can notice that the callback is executed every second, instead of every 50ms.

Could you please point me to the issue with my class?

Edit: As noted by @canton7, the issue was a threadpool starvation issue. Another object created a Thread per instance. The threadpool would take time to create a new Thread, trying to check if one completed before creating a new one.