Adds some metrics related to job locks and executions

.github/workflows/pr.yml

@@ -18,7 +18,7 @@ jobs:
     - name: Setup .NET
       uses: actions/setup-dotnet@v1
       with:
-        dotnet-version: 6.0.x
+        dotnet-version: 8.0.x
     - name: Restore dependencies
       run: dotnet restore
     - name: Build

.github/workflows/publish.yml

@@ -17,7 +17,7 @@ jobs:
     - name: Setup .NET
       uses: actions/setup-dotnet@v1
       with:
-        dotnet-version: 7.0.x
+        dotnet-version: 8.0.x
     - name: Restore dependencies
       run: dotnet restore
     - name: Build

src/SimpleRecurringJobs.Samples.AspNetCore/SimpleRecurringJobs.Samples.AspNetCore.csproj

@@ -7,6 +7,8 @@
 
     <ItemGroup>
         <PackageReference Include="Swashbuckle.AspNetCore" Version="5.6.3" />
+        <PackageReference Include="OpenTelemetry.Exporter.Prometheus.AspNetCore" Version="1.5.0-alpha.1" />
+        <PackageReference Include="OpenTelemetry.Extensions.Hosting" Version="1.9.0" />
     </ItemGroup>
 
     <ItemGroup>

src/SimpleRecurringJobs.Samples.AspNetCore/Startup.cs

@@ -11,6 +11,7 @@
 using Microsoft.Extensions.Hosting;
 using Microsoft.Extensions.Logging;
 using Microsoft.OpenApi.Models;
+using OpenTelemetry.Metrics;
 using SimpleRecurringJobs.InMemory;
 
 namespace SimpleRecurringJobs.Samples.AspNetCore;
@@ -39,6 +40,8 @@ public void ConfigureServices(IServiceCollection services)
         );
 
         services.AddSimpleRecurringJobs(b => b.UseInMemoryJobStore().WithJob<SimpleJob>());
+
+        services.AddOpenTelemetry().WithMetrics(b => b.AddMeter("SimpleRecurringJobs").AddPrometheusExporter());
     }
 
     // This method gets called by the runtime. Use this method to configure the HTTP request pipeline.
@@ -54,11 +57,13 @@ public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
         }
 
         app.UseHttpsRedirection();
+
+        app.UseOpenTelemetryPrometheusScrapingEndpoint();
 
         app.UseRouting();
 
         app.UseAuthorization();
 
         app.UseEndpoints(endpoints => { endpoints.MapControllers(); });
     }
-}
+}

src/SimpleRecurringJobs.Tests.Mongo/SimpleRecurringJobs.Tests.Mongo.csproj

@@ -1,7 +1,7 @@
 <Project Sdk="Microsoft.NET.Sdk">
 
     <PropertyGroup>
-        <TargetFramework>net7.0</TargetFramework>
+        <TargetFramework>net8.0</TargetFramework>
         <Nullable>enable</Nullable>
         <IsPackable>false</IsPackable>
     </PropertyGroup>

src/SimpleRecurringJobs.Tests.Postgres/SimpleRecurringJobs.Tests.Postgres.csproj

@@ -1,7 +1,7 @@
 <Project Sdk="Microsoft.NET.Sdk">
 
     <PropertyGroup>
-        <TargetFramework>net7.0</TargetFramework>
+        <TargetFramework>net8.0</TargetFramework>
         <ImplicitUsings>enable</ImplicitUsings>
         <Nullable>enable</Nullable>
     </PropertyGroup>

src/SimpleRecurringJobs.Tests.Redis/SimpleRecurringJobs.Tests.Redis.csproj

@@ -1,7 +1,7 @@
 <Project Sdk="Microsoft.NET.Sdk">
 
     <PropertyGroup>
-        <TargetFramework>net7.0</TargetFramework>
+        <TargetFramework>net8.0</TargetFramework>
         <Nullable>enable</Nullable>
 
         <IsPackable>false</IsPackable>

src/SimpleRecurringJobs.Tests/SimpleRecurringJobs.Tests.csproj

@@ -1,7 +1,7 @@
 <Project Sdk="Microsoft.NET.Sdk">
 
   <PropertyGroup>
-    <TargetFramework>net7.0</TargetFramework>
+    <TargetFramework>net8.0</TargetFramework>
     <Nullable>enable</Nullable>
     <IsPackable>false</IsPackable>
   </PropertyGroup>

src/SimpleRecurringJobs/JobExecutor.cs

@@ -1,4 +1,5 @@
 using System;
+using System.Collections.Generic;
 using System.Diagnostics;
 using System.Threading;
 using System.Threading.Tasks;
@@ -14,11 +15,13 @@ internal class JobsExecutor : IJobExecutor
     private readonly IJobLogger _logger;
     private readonly IJobStore _store;
     private readonly ActivitySource _activitySource = new ("SimpleRecurringJobs");
+    private readonly JobMetrics _jobMetrics;
 
-    public JobsExecutor(IJobStore store, IJobLogger logger, IJobClock clock)
+    public JobsExecutor(IJobStore store, IJobLogger logger, IJobClock clock, JobMetrics jobMetrics)
     {
         _store = store;
         _clock = clock;
+        _jobMetrics = jobMetrics;
         _logger = logger.ForSource<JobsExecutor>();
     }
 
@@ -27,11 +30,34 @@ public async Task<bool> Execute(IJob job, CancellationToken cancellationToken)
         var instanceId = Guid.NewGuid().ToString("N");
         using var activity = _activitySource.StartActivity($"Job: {job.Id}");
         activity?.SetTag("InstanceId", instanceId);
-
-        var @lock = await _store.TryLock(job, instanceId);
 
-        if (@lock == null)
-            return false;
+        var sw = Stopwatch.StartNew();
+        string lockStatus = "unknown";
+        IJobLock? @lock;
+
+        try
+        {
+            _jobMetrics.JobLockAttemptStarted.Add(1, new KeyValuePair<string, object?>("id", job.Id));
+
+            @lock = await _store.TryLock(job, instanceId);
+
+            if (@lock == null)
+            {
+                lockStatus = "missed";
+                return false;
+            }
+            lockStatus = "acquired";
+        }
+        catch (Exception)
+        {
+            lockStatus = "error";
+            throw;
+        }
+        finally
+        {
+            _jobMetrics.JobLockAttemptCompleted.Add(1, new ("id", job.Id), new ("status", lockStatus));
+            _jobMetrics.JobLockAttemptDurationInMs.Add(sw.ElapsedMilliseconds, new ("id", job.Id), new ("status", lockStatus));
+        }
 
         await using var _ = @lock;
 
@@ -40,32 +66,41 @@ public async Task<bool> Execute(IJob job, CancellationToken cancellationToken)
         info.LastTriggered = _clock.UtcNow;
         await _store.Save(info);
 
+        string status = "unknown";
+
         try
         {
-            var sw = Stopwatch.StartNew();
             _logger.LogVerbose("Executing job {JobId}", job.Id);
+            _jobMetrics.JobStarted.Add(1, new KeyValuePair<string, object?>("id", job.Id));
+            sw.Restart();
             await job.Execute(cancellationToken);
+            status = "completed";
             sw.Stop();
             _logger.LogVerbose("Execution of {JobId} completed in {ElapsedMs}ms", job.Id, sw.ElapsedMilliseconds);
             info.LastSuccess = _clock.UtcNow;
-            await _store.Save(info);
+            return true;
         }
         catch (Exception ex)
         {
             if (ex is OperationCanceledException && cancellationToken.IsCancellationRequested)
             {
-                _logger.LogInfo(ex, "Job {JobId} was cancelled", job.Id);   
+                _logger.LogInfo(ex, "Job {JobId} was cancelled", job.Id);
+                status = "cancelled";
             }
             else
             {
                 _logger.LogError(ex, "Job {JobId} terminated unexpectedly", job.Id);
+                status = "error";
             }
 
             info.LastFailure = _clock.UtcNow;
-            await _store.Save(info);
             return false;
         }
-
-        return true;
+        finally
+        {
+            _jobMetrics.JobCompleted.Add(1, new ("id", job.Id), new ("status", status));
+            _jobMetrics.JobDurationInMs.Add(sw.ElapsedMilliseconds, new ("id", job.Id), new ("status", status));
+            await _store.Save(info);
+        }
     }
 }

src/SimpleRecurringJobs/JobMetrics.cs

@@ -0,0 +1,16 @@
+using System.Diagnostics.Metrics;
+
+namespace SimpleRecurringJobs;
+
+internal class JobMetrics(Meter meter)
+{
+    public Counter<long> JobStarted { get; } = meter.CreateCounter<long>("srj_job_started", description: "Increments once each time a job is started.");
+    public Counter<long> JobCompleted { get; } = meter.CreateCounter<long>("srj_job_completed", description: "Increments once each time a job completes, either successfully or with an error.");
+    public Counter<long> JobDurationInMs { get; } = meter.CreateCounter<long>("srj_job_duration_in_ms", description: "Counts the total time spent in a job.");
+
+    public Counter<long> JobLockAttemptStarted { get; } = meter.CreateCounter<long>("srj_job_lock_attempt_started", description: "Increments once each time a job lock is attempted to be acquired.");
+
+    public Counter<long> JobLockAttemptCompleted { get; } = meter.CreateCounter<long>("srj_job_lock_attempt_completed", description: "Increments once each time a job lock is either acquired or not.");
+
+    public Counter<long> JobLockAttemptDurationInMs { get; } = meter.CreateCounter<long>("srj_job_lock_attempt_duration_in_ms", description: "Counts the total time spent acquiring job locks.");
+}

src/SimpleRecurringJobs/ServiceCollectionExtensions.cs

@@ -1,4 +1,5 @@
 using System;
+using System.Diagnostics.Metrics;
 using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Hosting;
 using SimpleRecurringJobs.Interval;
@@ -12,6 +13,7 @@ public static void AddSimpleRecurringJobs(this IServiceCollection services, Acti
         services.AddSingleton<IJobLogger, MicrosoftLogger>();
         services.AddSingleton<IJobScheduler, IntervalScheduler>();
         services.AddSingleton<IJobExecutor, JobsExecutor>();
+        services.AddSingleton(new JobMetrics(new Meter("SimpleRecurringJobs")));
 
         services.AddSingleton(IJobClock.SystemClock);
         services.AddSingleton(IAsyncDelayer.SystemDelayer);