Fix Missed Ticks In Scheduler (#359)

* scheduler catch-up with missed ticks

* fix demo prj to reproduce issue

Demo/.dockerignore

@@ -0,0 +1,25 @@
+**/.dockerignore
+**/.env
+**/.git
+**/.gitignore
+**/.project
+**/.settings
+**/.toolstarget
+**/.vs
+**/.vscode
+**/.idea
+**/*.*proj.user
+**/*.dbmdl
+**/*.jfm
+**/azds.yaml
+**/bin
+**/charts
+**/docker-compose*
+**/Dockerfile*
+**/node_modules
+**/npm-debug.log
+**/obj
+**/secrets.dev.yaml
+**/values.dev.yaml
+LICENSE
+README.md

Demo/Demo.csproj

@@ -1,7 +1,8 @@
 <Project Sdk="Microsoft.NET.Sdk.Web">
 
   <PropertyGroup>
-    <TargetFramework>netcoreapp2.1</TargetFramework>
+    <TargetFramework>net6.0</TargetFramework>
+    <DockerDefaultTargetOS>Linux</DockerDefaultTargetOS>
   </PropertyGroup>
 
   <ItemGroup>

Demo/Dockerfile

@@ -0,0 +1,22 @@
+FROM mcr.microsoft.com/dotnet/aspnet:6.0 AS base
+WORKDIR /app
+EXPOSE 80
+EXPOSE 443
+
+FROM mcr.microsoft.com/dotnet/sdk:6.0 AS build
+ARG BUILD_CONFIGURATION=Release
+WORKDIR /src
+COPY ["Demo.csproj", "./"]
+RUN dotnet restore "Demo.csproj"
+COPY . .
+WORKDIR "/src/"
+RUN dotnet build "Demo.csproj" -c $BUILD_CONFIGURATION -o /app/build
+
+FROM build AS publish
+ARG BUILD_CONFIGURATION=Release
+RUN dotnet publish "Demo.csproj" -c $BUILD_CONFIGURATION -o /app/publish /p:UseAppHost=false
+
+FROM base AS final
+WORKDIR /app
+COPY --from=publish /app/publish .
+ENTRYPOINT ["dotnet", "Demo.dll"]

Demo/Startup.cs

@@ -1,4 +1,5 @@
 using System;
+using System.Threading;
 using Coravel;
 using Coravel.Events.Interfaces;
 using Coravel.Queuing.Interfaces;
@@ -42,7 +43,7 @@ public void ConfigureServices(IServiceCollection services)
             services.AddQueue();
 
             // Coravel Caching
-            services.AddSQLServerCache(this.Configuration.GetConnectionString("DefaultConnection"));
+            //services.AddSQLServerCache(this.Configuration.GetConnectionString("DefaultConnection"));
            // services.AddPostgreSQLCache(this.Configuration.GetConnectionString("PostGreSQL"));
 
             // Coravel Mail
@@ -74,12 +75,12 @@ public void Configure(IApplicationBuilder app, IHostingEnvironment env)
             app.UseStaticFiles();
             app.UseCookiePolicy();
 
-            app.UseMvc(routes =>
-            {
-                routes.MapRoute(
-                    name: "default",
-                    template: "{controller=Home}/{action=Index}/{id?}");
-            });
+            // app.UseMvc(routes =>
+            // {
+            //     routes.MapRoute(
+            //         name: "default",
+            //         template: "{controller=Home}/{action=Index}/{id?}");
+            // });
 
             IEventRegistration registration = app.ApplicationServices.ConfigureEvents();
 
@@ -94,15 +95,27 @@ public void Configure(IApplicationBuilder app, IHostingEnvironment env)
                     .Schedule<RebuildStaticCachedData>().Hourly();
 
                 scheduler.OnWorker("TestingSeconds");
-                scheduler.Schedule(
-                    () => Console.WriteLine($"Runs every second. Ran at: {DateTime.UtcNow}")
-                ).EverySecond();
-                scheduler.Schedule(() => Console.WriteLine($"Runs every thirty seconds. Ran at: {DateTime.UtcNow}")).EveryThirtySeconds().Zoned(TimeZoneInfo.Local);
-                scheduler.Schedule(() => Console.WriteLine($"Runs every ten seconds. Ran at: {DateTime.UtcNow}")).EveryTenSeconds();
-                scheduler.Schedule(() => Console.WriteLine($"Runs every fifteen seconds. Ran at: {DateTime.UtcNow}")).EveryFifteenSeconds();
-                scheduler.Schedule(() => Console.WriteLine($"Runs every thirty seconds. Ran at: {DateTime.UtcNow}")).EveryThirtySeconds();
-                scheduler.Schedule(() => Console.WriteLine($"Runs every minute Ran at: {DateTime.UtcNow}")).EveryMinute();
-                scheduler.Schedule(() => Console.WriteLine($"Runs every 2nd minute Ran at: {DateTime.UtcNow}")).Cron("*/2 * * * *");
+                // scheduler.Schedule(
+                //     () => Console.WriteLine($"Runs every second. Ran at: {DateTime.UtcNow}")
+                // ).EverySecond();
+                // scheduler.Schedule(() => Console.WriteLine($"Runs every thirty seconds. Ran at: {DateTime.UtcNow}")).EveryThirtySeconds().Zoned(TimeZoneInfo.Local);
+                // scheduler.Schedule(() => Console.WriteLine($"Runs every ten seconds. Ran at: {DateTime.UtcNow}")).EveryTenSeconds();
+                // scheduler.Schedule(() => Console.WriteLine($"Runs every fifteen seconds. Ran at: {DateTime.UtcNow}")).EveryFifteenSeconds();
+                // scheduler.Schedule(() => Console.WriteLine($"Runs every thirty seconds. Ran at: {DateTime.UtcNow}")).EveryThirtySeconds();
+                // scheduler.Schedule(() => Console.WriteLine($"Runs every minute Ran at: {DateTime.UtcNow}")).EveryMinute();
+                // scheduler.Schedule(() => Console.WriteLine($"Runs every 2nd minute Ran at: {DateTime.UtcNow}")).Cron("*/2 * * * *");
+
+
+                scheduler.Schedule(() => Thread.Sleep(5000)).EverySecond();
+                scheduler.Schedule(() => Thread.Sleep(5000)).EverySecond();
+                scheduler.Schedule(() => Thread.Sleep(5000)).EverySecond();
+                scheduler.Schedule(() => Thread.Sleep(5000)).EverySecond();
+                scheduler.Schedule(() => Thread.Sleep(5000)).EverySecond();
+                scheduler.Schedule(() => Thread.Sleep(5000)).EverySecond();
+                scheduler.Schedule(() => Thread.Sleep(5000)).EverySecond();
+                scheduler.Schedule(() => Thread.Sleep(5000)).EverySecond();
+                scheduler.Schedule(() => Thread.Sleep(5000)).EverySecond();
+                scheduler.Schedule(() => Thread.Sleep(5000)).EverySecond();
             });
 
             app.ApplicationServices

Demo/appsettings.json

@@ -1,7 +1,7 @@
 {
   "Logging": {
     "LogLevel": {
-      "Default": "Warning"
+      "Default": "Information"
     }
   },
   "AllowedHosts": "*"

Src/Coravel/Scheduling/HostedService/SchedulerHost.cs

@@ -1,4 +1,6 @@
 using System;
+using System.Collections.Generic;
+using System.Linq;
 using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.Extensions.Hosting;
@@ -15,6 +17,8 @@ internal class SchedulerHost : IHostedService, IDisposable
         private bool _schedulerEnabled = true;
         private ILogger<SchedulerHost> _logger;
         private IHostApplicationLifetime _lifetime;
+        private object _tickLockObj = new object();
+        private EnsureContinuousSecondTicks _ensureContinuousSecondTicks;
         private readonly string ScheduledTasksRunningMessage = "Coravel's Scheduling service is attempting to close but there are tasks still running." +
                                                                " App closing (in background) will be prevented until all tasks are completed.";
 
@@ -23,6 +27,7 @@ public SchedulerHost(IScheduler scheduler, ILogger<SchedulerHost> logger, IHostA
             this._scheduler = scheduler as Scheduler;
             this._logger = logger;
             this._lifetime = lifetime;
+            this._ensureContinuousSecondTicks = new EnsureContinuousSecondTicks(DateTime.UtcNow);
         }
 
         public Task StartAsync(CancellationToken cancellationToken)
@@ -44,7 +49,29 @@ private async void RunSchedulerPerSecondAsync(object state)
         {
             if (this._schedulerEnabled)
             {
-                await this._scheduler.RunSchedulerAsync();
+                // This will get any missed ticks that might arise from the Timer triggering a little too late. 
+                // If under CPU load or if the Timer is for some reason a little slow, then it's possible to
+                // miss a tick - which we want to make sure the scheduler doesn't miss and catches up.
+                var now = DateTime.UtcNow;
+                DateTime[] ticks = null;
+                lock (_tickLockObj)
+                {
+                    // This class isn't thread-safe.
+                    ticks = this._ensureContinuousSecondTicks.GetTicksBetweenPreviousAndNext(now).ToArray();
+                    this._ensureContinuousSecondTicks.SetNextTick(now);
+                }
+
+                if (ticks.Length > 0)
+                {
+                    this._logger.LogInformation($"Coravel's scheduler is behind {ticks.Length} ticks and is catching-up to the current tick. Triggered at {now.ToString("o")}.");
+                    foreach (var tick in ticks)
+                    {
+                        await this._scheduler.RunAtAsync(tick);
+                    }
+                }
+
+                // If we've processed any missed ticks, we also need to explicitly run the current tick.
+                await this._scheduler.RunAtAsync(now);
             }
         }
 

Src/Coravel/Scheduling/Schedule/EnsureContinuousSecondTicks.cs

@@ -0,0 +1,46 @@
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using Coravel.Scheduling.Schedule.Helpers;
+
+namespace Coravel.Scheduling.Schedule;
+
+public class EnsureContinuousSecondTicks
+{
+    private DateTime previousTick;
+
+    public EnsureContinuousSecondTicks(DateTime firstTick)
+    {
+        previousTick = firstTick;
+    }
+
+    /// <summary>
+    /// Give this method when the next tick occurs and it will return any intermediary ticks that should
+    /// have existed been the stored previous tick and the next one.
+    /// </summary>
+    /// <param name="nextTick"></param>
+    /// <returns></returns>
+    public IEnumerable<DateTime> GetTicksBetweenPreviousAndNext(DateTime nextTick)
+    {
+        // Starting at previousTick, we move ahead one second a time and record the next time until we get to the "nextTick".
+        // Then we check if there are any missed ticks between the two.
+        List<DateTime> missingTicks = null; // We don't want to commit any memory until we know for sure there's at least 1 missed tick.
+        DateTime nextTickToTest = previousTick.PreciseUpToSecond().AddSeconds(1);
+        while (nextTickToTest < nextTick.PreciseUpToSecond())
+        {
+            if (missingTicks is null)
+            {
+                missingTicks = new List<DateTime>();
+            }
+            missingTicks.Add(nextTickToTest);
+            nextTickToTest = nextTickToTest.PreciseUpToSecond().AddSeconds(1);
+        }
+
+        return missingTicks ?? Enumerable.Empty<DateTime>();
+    }
+
+    public void SetNextTick(DateTime nextTick)
+    {
+        previousTick = nextTick;
+    }
+}

Src/Coravel/Scheduling/Schedule/Helpers/DateHelpers.cs

@@ -4,8 +4,8 @@ namespace Coravel.Scheduling.Schedule.Helpers
 {
     public static class DateHelpers
     {
-        public static DateTime PreciseUpToMinute(this DateTime me) {
-            return new DateTime(me.Year, me.Month, me.Day, me.Hour, me.Minute, 0);
+        public static DateTime PreciseUpToSecond(this DateTime me) {
+            return new DateTime(me.Year, me.Month, me.Day, me.Hour, me.Minute, me.Second, DateTimeKind.Utc);
         }
     }
 }

Src/Coravel/Scheduling/Schedule/Scheduler.cs

@@ -99,12 +99,6 @@ public IScheduler OnWorker(string workerName)
             return this;
         }
 
-        public async Task RunSchedulerAsync()
-        {
-            DateTime utcNow = DateTime.UtcNow;
-            await this.RunAtAsync(utcNow);
-        }
-
         public async Task RunAtAsync(DateTime utcDate)
         {
             Interlocked.Increment(ref this._schedulerIterationsActiveCount);

Src/UnitTests/CoravelUnitTests/Scheduling/EnsureContinuousSecondTicksTests.cs

@@ -0,0 +1,116 @@
+using System;
+using System.Linq;
+using Coravel.Scheduling.Schedule;
+using Xunit;
+
+namespace CoravelUnitTests.Scheduling;
+
+public class EnsureContinuousSecondTicksTests
+{
+    public const int SecondsInMinute = 60;
+    public const int SecondsInHour = 60 * 60;
+    public const int SecondsInDay = 60 * 60 * 24;
+
+    [Theory]
+    // 1 second difference: no missing ticks
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T12:00:01.0000000Z")]
+    [InlineData("2024-01-12T12:00:00.2000000Z", "2024-01-12T12:00:01.2000000Z")]
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T12:00:01.9990000Z")]
+    [InlineData("2009-05-22T22:22:22.0000000Z", "2009-05-22T22:22:23.9999999Z")]
+
+    // Having less than a second between: no missing ticks
+    [InlineData("2009-05-22T22:22:22.0000000Z", "2009-05-22T22:22:22.9999999Z")]
+    [InlineData("2009-05-22T23:59:59.0000000Z", "2009-05-22T23:59:59.9999999Z")]
+
+    // Negative ticks
+    [InlineData("2009-05-22T23:59:59.9999999Z", "2009-05-22T23:59:59.0000000Z")]
+    [InlineData("2009-05-22T23:59:59.9999999Z", "2009-05-22T23:59:58.9999999Z")]
+    [InlineData("2009-05-22T23:59:59.9999999Z", "2009-05-22T23:58:59.9999999Z")]
+    [InlineData("2009-05-22T23:59:59.9999999Z", "2009-05-22T22:59:59.9999999Z")]
+    [InlineData("2009-05-22T23:59:59.9999999Z", "2009-05-21T23:59:59.9999999Z")]
+    [InlineData("2009-05-22T23:59:59.9999999Z", "2009-04-22T23:59:59.9999999Z")]
+    [InlineData("2009-05-22T23:59:59.9999999Z", "2008-05-22T23:59:59.9999999Z")]
+    public void ShouldNotHaveMissingTicks(string previousTick, string nextTick)
+    {
+        var previous = DateTime.Parse(previousTick);
+        var next = DateTime.Parse(nextTick);
+
+        var sut = new EnsureContinuousSecondTicks(previous);
+        var missingTicks = sut.GetTicksBetweenPreviousAndNext(next);
+
+        Assert.Empty(missingTicks);
+    }
+
+    [Theory]
+    // Same day but different seconds
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T12:00:02.0000000Z", 1)]
+    [InlineData("2024-01-12T12:00:00.9999999Z", "2024-01-12T12:00:02.0000000Z", 1)]
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T12:00:03.0000000Z", 2)]
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T12:00:04.0000000Z", 3)]
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T12:00:04.9999999Z", 3)]
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T12:00:59.9999999Z", 58)]
+
+    // Different seconds and minutes
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T12:01:02.0000000Z", 61)]
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T12:01:02.5500000Z", 61)]
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T12:01:02.9999998Z", 61)]
+
+    // Different seconds, minutes and/or hours
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T13:00:00.0000000Z", SecondsInHour - 1)]
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T13:00:00.9999999Z", SecondsInHour - 1)]
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-12T14:10:22.9999999Z", (SecondsInHour * 2) + (SecondsInMinute * 10) + 22 - 1)]
+
+    // Different day but same month
+    [InlineData("2024-01-12T13:00:00.0000000Z", "2024-01-13T13:00:00.0000000Z", SecondsInDay - 1)]
+    [InlineData("2024-01-12T12:00:00.0000000Z", "2024-01-17T14:10:22.9999999Z", (SecondsInDay * 5) + (SecondsInHour * 2) + (SecondsInMinute * 10) + 22 - 1)]
+
+    // Different month
+    [InlineData("2024-01-01T13:00:00.0000000Z", "2024-02-01T13:00:00.0000000Z", SecondsInDay * 31 - 1)]
+    [InlineData("2024-01-01T13:00:00.0000000Z", "2024-03-01T13:00:00.0000000Z", (SecondsInDay * 31) + (SecondsInDay * 29) - 1)]
+    [InlineData("2024-01-01T13:00:00.0000000Z", "2024-03-01T13:00:00.9999999Z", (SecondsInDay * 31) + (SecondsInDay * 29) - 1)]
+
+    // Different year (testing large ranges and moving from dec to jan)
+    [InlineData("2023-12-31T13:00:00.0000000Z", "2024-01-01T13:00:00.0000000Z", SecondsInDay - 1)]
+    [InlineData("2023-12-31T13:00:00.0000000Z", "2024-01-01T13:00:00.9456743Z", SecondsInDay - 1)]
+
+    // Entire year (not realistic but tests the logic).
+    [InlineData("2022-12-31T13:00:00.0000000Z", "2023-12-31T13:00:00.0000000Z", SecondsInDay * 365 - 1)]
+    [InlineData("2022-12-31T13:00:00.9999999Z", "2023-12-31T13:00:00.0000000Z", SecondsInDay * 365 - 1)]
+    [InlineData("2022-12-31T13:00:00.0000000Z", "2023-12-31T13:00:00.9999999Z", SecondsInDay * 365 - 1)]
+
+    public void ShouldHaveMissingTicks(string previousTick, string nextTick, int expectedMissingTicks)
+    {
+        var previous = DateTime.Parse(previousTick).ToUniversalTime();
+        var next = DateTime.Parse(nextTick).ToUniversalTime();
+
+        var sut = new EnsureContinuousSecondTicks(previous);
+        var missingTicks = sut.GetTicksBetweenPreviousAndNext(next);
+
+        Assert.Equal(expectedMissingTicks, missingTicks.Count());
+    }
+
+    [Fact]
+    public void MissingTicksAreExpectedTimes()
+    {
+        var previous = DateTime.Parse("2024-01-12T12:00:00.9994443Z").ToUniversalTime();
+        var next = DateTime.Parse("2024-01-12T12:00:05.2345633Z").ToUniversalTime();
+
+        var sut = new EnsureContinuousSecondTicks(previous);
+        var missingTicks = sut.GetTicksBetweenPreviousAndNext(next).ToArray();
+
+        Assert.Equal(4, missingTicks.Count());
+        Assert.Equal(DateTime.Parse("2024-01-12T12:00:01.0000000Z").ToUniversalTime(), missingTicks[0]);
+        Assert.Equal(DateTime.Parse("2024-01-12T12:00:02.0000000Z").ToUniversalTime(), missingTicks[1]);
+        Assert.Equal(DateTime.Parse("2024-01-12T12:00:03.0000000Z").ToUniversalTime(), missingTicks[2]);
+        Assert.Equal(DateTime.Parse("2024-01-12T12:00:04.0000000Z").ToUniversalTime(), missingTicks[3]);
+
+        // Set the next tick and test that the next check works.
+        sut.SetNextTick(DateTime.Parse("2024-01-12T12:00:06.2345633Z").ToUniversalTime());
+        missingTicks = sut.GetTicksBetweenPreviousAndNext(DateTime.Parse("2024-01-12T12:00:10.9999888Z").ToUniversalTime()).ToArray();
+
+        Assert.Equal(3, missingTicks.Count());
+        Assert.Equal(DateTime.Parse("2024-01-12T12:00:07.0000000Z").ToUniversalTime(), missingTicks[0]);
+        Assert.Equal(DateTime.Parse("2024-01-12T12:00:08.0000000Z").ToUniversalTime(), missingTicks[1]);
+        Assert.Equal(DateTime.Parse("2024-01-12T12:00:09.0000000Z").ToUniversalTime(), missingTicks[2]);
+    }
+}

Src/UnitTests/CoravelUnitTests/Scheduling/SchedulerEventDispatcherTests.cs

@@ -14,7 +14,7 @@ namespace CoravelUnitTests.Scheduling
 {
     public class SchedulerEventDispatcherTests
     {
-         [Fact]
+        [Fact]
         public async Task<bool> DoesNotThrowOnNullDispatcher()
         {
             var scheduler = new Scheduler(new InMemoryMutex(), new ServiceScopeFactoryStub(), null);