ability to log missed ticks + breaking change to API (#407)

Demo/Startup.cs

@@ -52,6 +52,7 @@ public void ConfigureServices(IServiceCollection services)
 
             services.AddScoped<SendNightlyReportsEmailJob>();
             services.AddScoped<DoExpensiveCalculationAndStore>();
+            services.AddScoped<Demo.Invocables.RebuildStaticCachedData>();
 
             services.AddEvents();
 
@@ -93,7 +94,7 @@ public void Configure(IApplicationBuilder app, IHostingEnvironment env)
             {
                 scheduler.OnWorker("CPUIntensiveTasks");
                 scheduler
-                    .Schedule<RebuildStaticCachedData>().Hourly();
+                    .Schedule<RebuildStaticCachedData>().EveryFifteenSeconds();
 
                 scheduler.OnWorker("TestingSeconds");
                 scheduler.Schedule(
@@ -108,7 +109,7 @@ public void Configure(IApplicationBuilder app, IHostingEnvironment env)
 
 
                 scheduler.Schedule(() => Thread.Sleep(5000)).EverySecond();
-            });
+            }).LogScheduledTaskProgress();
 
             app.ApplicationServices
                 .ConfigureQueue()

Demo/appsettings.json

@@ -24,6 +24,9 @@
     },
     "Queue": {
         "ConsummationDelay": 5
+    },
+    "Schedule": {
+        "LogTickCatchUp": true
     }
   }
 }

DocsV2/docs/Scheduler/README.md

@@ -330,34 +330,39 @@ You can, of course, add error handling inside your specific tasks too.
 
 ## Logging Executed Task Progress
 
-Coravel uses the `ILogger` .Net Core interface to allow logging scheduled task progress.
-
-In your `Startup.cs` file, you need to inject an instance of `IServiceProvider` to the constructor and assign it to a member field / property:
+If you want Coravel to output log statements about scheduled task progress (usually to debug issues), you can call `LogScheduledTaskProgress()`:
 
 ```csharp
-public Startup(IConfiguration configuration, /* Add this */ IServiceProvider services)
+provider.UseScheduler(scheduler =>
 {
-    Configuration = configuration;
-    Services = services;
-}
+    // Assign scheduled tasks...
+})
+.LogScheduledTaskProgress();
+```
 
-public IConfiguration Configuration { get; }
+Your logging level should also be set to `Debug` in your `appsettings.json` file.
 
-/* Add this property */
-public IServiceProvider Services { get; }
-```
+:::tip
+This method had a breaking change in Coravel `6.0.0`.
+:::
 
-Next, do the following:
+## Logging Tick Catch Up
 
-```csharp
-provider.UseScheduler(scheduler =>
-{
-    // Assign scheduled tasks...
-})
-.LogScheduledTaskProgress(Services.GetService<ILogger<IScheduler>>());
+Coravel's scheduling runs on an internal `Timer`. Sometimes, due to a lack of resources or an overloaded system (common in small containerized processes),
+the next "tick" could occur after 1 second. For example, a constrained container process might be overloaded and the `Timer` misses 10 seconds of ticks. 
+Coravel will chronologically replay each tick in order to catch up to "now".
+
+You can enable Coravel to output a log statement by setting the following configuration value in `appsettings.json`:
+
+```json
+"Coravel": {
+    "Schedule": {
+        "LogTickCatchUp": true
+    }
+}
 ```
 
-The `LogScheduledTaskProgress()` method accepts an instance of `ILogger<IScheduler>`, which is available through the service provider.
+This will be outputted as an `Informational` log statement.
 
 ## Force Run A Task At App Startup
 
@@ -376,8 +381,6 @@ scheduler.Schedule<CacheSomeStuff>()
 
 This will run immediately on application startup - even on weekends. After this initial run, any further runs will respect the assigned schedule of running once an hour only on weekdays.
 
-
-
 ## On App Closing
 
 When your app is stopped, Coravel will wait until any running scheduled tasks are completed. This will keep your app running in the background - as long as the parent process is not killed.

Src/Coravel.Mailer/Mail/MessageBody.cs

@@ -5,7 +5,7 @@ public class MessageBody
     public string Html { get; set; }
     public string Text { get; set; }
 
-    public MessageBody(string? html, string? text)
+    public MessageBody(string html, string text)
     {
         if(html is null && text is null)
         {

Src/Coravel/Coravel.csproj

@@ -23,6 +23,7 @@
   <ItemGroup>
     <PackageReference Include="Microsoft.Extensions.Caching.Memory" Version="3.1.0" />
     <PackageReference Include="Microsoft.Extensions.DependencyInjection" Version="6.0.1" />
+    <PackageReference Include="Microsoft.Extensions.Configuration.Binder" Version="6.0.0" />
     <PackageReference Include="Microsoft.Extensions.Logging.Abstractions" Version="3.1.0" />
     <PackageReference Include="Microsoft.Extensions.Hosting.Abstractions" Version="3.1.0" />
     <PackageReference Include="Microsoft.SourceLink.GitHub" Version="1.1.1" PrivateAssets="All" />

Src/Coravel/Scheduling/HostedService/SchedulerHost.cs

@@ -1,33 +1,35 @@
 using System;
-using System.Collections.Generic;
 using System.Linq;
 using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.Extensions.Hosting;
 using Coravel.Scheduling.Schedule;
 using Coravel.Scheduling.Schedule.Interfaces;
 using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Configuration;
 
 namespace Coravel.Scheduling.HostedService
 {
     internal class SchedulerHost : IHostedService, IDisposable
     {
-        private Scheduler _scheduler;
+        private readonly Scheduler _scheduler;
+        private readonly ILogger<SchedulerHost> _logger;
+        private readonly IHostApplicationLifetime _lifetime;
+        private readonly IConfiguration _config;
         private Timer _timer;
         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.";
 
-        public SchedulerHost(IScheduler scheduler, ILogger<SchedulerHost> logger, IHostApplicationLifetime lifetime)
+        public SchedulerHost(IScheduler scheduler, ILogger<SchedulerHost> logger, IHostApplicationLifetime lifetime, IConfiguration config)
         {
             this._scheduler = scheduler as Scheduler;
             this._logger = logger;
             this._lifetime = lifetime;
             this._ensureContinuousSecondTicks = new EnsureContinuousSecondTicks(DateTime.UtcNow);
+            this._config = config;
         }
 
         public Task StartAsync(CancellationToken cancellationToken)
@@ -62,7 +64,12 @@ private async void RunSchedulerPerSecondAsync(object state)
                 }
 
                 if (ticks.Length > 0)
-                {                
+                {       
+                    if(this._config.GetValue<bool?>("Coravel:Schedule:LogTickCatchUp") ?? false) 
+                    {        
+                        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);

Src/Coravel/Scheduling/Schedule/Interfaces/ISchedulerConfiguration.cs

@@ -18,8 +18,7 @@ public interface ISchedulerConfiguration
         /// <summary>
         /// Log the progress of scheduled tasks.
         /// </summary>
-        /// <param name="logger"></param>
         /// <returns></returns>
-        ISchedulerConfiguration LogScheduledTaskProgress(ILogger<IScheduler> logger);        
+        ISchedulerConfiguration LogScheduledTaskProgress();        
     }
 }

Src/Coravel/Scheduling/Schedule/Scheduler.cs

@@ -18,7 +18,7 @@ public class Scheduler : IScheduler, ISchedulerConfiguration
     {
         private ConcurrentDictionary<string, ScheduledTask> _tasks;
         private Action<Exception> _errorHandler;
-        private ILogger<IScheduler> _logger;
+        private bool _shouldLogProgress = false;
         private IMutex _mutex;
         private readonly int EventLockTimeout_24Hours = 1440;
         private IServiceScopeFactory _scopeFactory;
@@ -114,9 +114,9 @@ public ISchedulerConfiguration OnError(Action<Exception> onError)
             return this;
         }
 
-        public ISchedulerConfiguration LogScheduledTaskProgress(ILogger<IScheduler> logger)
+        public ISchedulerConfiguration LogScheduledTaskProgress()
         {
-            this._logger = logger;
+            this._shouldLogProgress = true;
             return this;
         }
 
@@ -136,26 +136,34 @@ public bool TryUnschedule(string uniqueIdentifier)
         }
 
         private async Task InvokeEventWithLoggerScope(ScheduledEvent scheduledEvent)
-        {
+        {         
+            using var scope = this._scopeFactory.CreateAsyncScope();
+            ILogger<IScheduler> logger = null;
+
+            if(this._shouldLogProgress)
+            {
+                logger = scope.ServiceProvider.GetRequiredService<ILogger<IScheduler>>();
+            }
+
             var eventInvocableTypeName = scheduledEvent.InvocableType()?.Name;
-            using (_logger != null && eventInvocableTypeName != null ?
-                _logger.BeginScope($"Invocable Type : {eventInvocableTypeName}") : null)
+            using (logger != null && eventInvocableTypeName != null ?
+                logger.BeginScope($"Invocable Type : {eventInvocableTypeName}") : null)
             {
-                await InvokeEvent(scheduledEvent);
+                await InvokeEvent(scheduledEvent, logger);
             }
         }
 
-        private async Task InvokeEvent(ScheduledEvent scheduledEvent)
+        private async Task InvokeEvent(ScheduledEvent scheduledEvent, ILogger<IScheduler> logger)
         {
             try
             {
                 await this.TryDispatchEvent(new ScheduledEventStarted(scheduledEvent));
 
                 async Task Invoke()
                 {
-                    this._logger?.LogDebug("Scheduled task started...");
+                    logger?.LogDebug("Scheduled task started...");
                     await scheduledEvent.InvokeScheduledEvent(this._cancellationTokenSource.Token);
-                    this._logger?.LogDebug("Scheduled task finished...");
+                    logger?.LogDebug("Scheduled task finished...");
                 };
 
                 if (scheduledEvent.ShouldPreventOverlapping())
@@ -183,7 +191,7 @@ async Task Invoke()
             {
                 await this.TryDispatchEvent(new ScheduledEventFailed(scheduledEvent, e));
 
-                this._logger?.LogError(e, "A scheduled task threw an Exception: ");
+                logger?.LogError(e, "A scheduled task threw an Exception: ");
 
                 this._errorHandler?.Invoke(e);
             }

Src/UnitTests/CoravelUnitTests/Scheduling/Stubs/ServiceScopeFactoryStub.cs

@@ -1,3 +1,4 @@
+using System;
 using Microsoft.Extensions.DependencyInjection;
 
 namespace CoravelUnitTests.Scheduling.Stubs
@@ -6,7 +7,17 @@ public class ServiceScopeFactoryStub : IServiceScopeFactory
     {
         public IServiceScope CreateScope()
         {
-            throw new System.NotImplementedException();
+            return new AsyncServiceScope(new ServiceScopeStub());
+        }
+    }
+
+    public class ServiceScopeStub : IServiceScope
+    {
+        public IServiceProvider ServiceProvider => throw new NotImplementedException();
+
+        public void Dispose()
+        {
+            // no-op
         }
     }
 }