Added Serilog logging, added Elmah error logging, added health checks

.gitignore

@@ -12,4 +12,5 @@ src/Models/bin
 src/Models/obj
 src/Indexer/bin
 src/Indexer/obj
-src/Indexer/Scripts/__pycache__
+src/Indexer/Scripts/__pycache__
+src/Indexer/logs

docs/Indexer.md

@@ -1,5 +1,10 @@
 # Overview
-
+The indexer by default
+- runs on port 5210
+- Uses Swagger UI in development mode (endpoint: `/swagger/index.html`)
+- Ignores API keys when in development mode
+- Uses Elmah error logging (endpoint: `/elmah`, local files: `~/logs`)
+- Uses serilog logging (local files: `~/logs`)
 ## Installing the dependencies
 ## Ubuntu 24.04
 1. Install the .NET SDK: `sudo apt update && sudo apt install dotnet-sdk-8.0 -y`

docs/Server.md

@@ -2,7 +2,7 @@
 The server by default
 - runs on port 5146
 - Uses Swagger UI in development mode (`/swagger/index.html`)
-- Ignores API keys when not in development mode
+- Ignores API keys when in development mode
 
 # Installing the dependencies
 ## Ubuntu 24.04

src/Indexer/Indexer.csproj

@@ -7,7 +7,10 @@
   </PropertyGroup>
 
   <ItemGroup>
+    <PackageReference Include="ElmahCore" Version="2.1.2" />
     <PackageReference Include="Microsoft.AspNetCore.OpenApi" Version="8.0.14" />
+    <PackageReference Include="Serilog.AspNetCore" Version="9.0.0" />
+    <PackageReference Include="Serilog.Sinks.File" Version="7.0.0" />
     <PackageReference Include="Swashbuckle.AspNetCore" Version="6.6.2" />
     <PackageReference Include="Python" Version="3.13.3" />
     <PackageReference Include="Pythonnet" Version="3.0.5" />

src/Indexer/IndexerHealthChecks.cs

@@ -0,0 +1,44 @@
+using System.Collections.ObjectModel;
+using Indexer.Models;
+using Microsoft.Extensions.Diagnostics.HealthChecks;
+
+namespace Indexer;
+
+public class WorkerHealthCheck : IHealthCheck
+{
+    private readonly WorkerCollection _workerCollection;
+    public WorkerHealthCheck(WorkerCollection workerCollection)
+    {
+        _workerCollection = workerCollection;
+    }
+    public Task<HealthCheckResult> CheckHealthAsync(
+        HealthCheckContext context, CancellationToken cancellationToken = default)
+    {
+        bool hasDegraded = false;
+        bool hasUnhealthy = false;
+        Dictionary<string, HealthStatus> degradedWorkerList = [];
+        foreach (Worker worker in _workerCollection.Workers)
+        {
+            HealthCheckResult workerHealth = worker.HealthCheck();
+            hasDegraded |= workerHealth.Status == HealthStatus.Degraded;
+            hasUnhealthy |= workerHealth.Status == HealthStatus.Unhealthy;
+            if (workerHealth.Status != HealthStatus.Healthy)
+            {
+                degradedWorkerList[worker.Name] = workerHealth.Status;
+            }
+        }
+        string degradedWorkerListString = "{" + string.Join(",", [.. degradedWorkerList.Select(kv => '"' + kv.Key + "\": " + kv.Value)]) + "}";
+        if (hasUnhealthy)
+        {
+            return Task.FromResult(
+                HealthCheckResult.Unhealthy(degradedWorkerListString));
+        }
+        else if (hasDegraded)
+        {
+            return Task.FromResult(
+                HealthCheckResult.Degraded(degradedWorkerListString));
+        }
+        return Task.FromResult(
+                HealthCheckResult.Healthy());
+    }
+}

src/Indexer/Models/Interfaces.cs

@@ -3,6 +3,8 @@ namespace Indexer.Models;
 public interface IScriptable
 {
     ScriptToolSet ToolSet { get; set; }
+    ScriptUpdateInfo UpdateInfo { get; set; }
+    ILogger Logger { get; set; }
     void Init();
     void Update(ICallbackInfos callbackInfos);
     bool IsScript(string filePath);

src/Indexer/Models/Script.cs

@@ -1,4 +1,3 @@
-using System.Text.Json;
 using System.Timers;
 using Python.Runtime;
 
@@ -11,8 +10,11 @@ public class PythonScriptable : IScriptable
     public PyModule scope;
     public dynamic sys;
     public string source;
-    public PythonScriptable(ScriptToolSet toolSet)
+    public ScriptUpdateInfo UpdateInfo { get; set; }
+    public ILogger Logger { get; set; }
+    public PythonScriptable(ScriptToolSet toolSet, ILogger logger)
     {
+        Logger = logger;
         Runtime.PythonDLL = @"libpython3.12.so";
         if (!PythonEngine.IsInitialized)
         {
@@ -37,24 +39,60 @@ public class PythonScriptable : IScriptable
 
     public void Init()
     {
-        using (Py.GIL())
+        int retryCounter = 0;
+        retry:
+        try
         {
-            pyToolSet = ToolSet.ToPython();
+            using (Py.GIL())
-            scope.Set("toolset", pyToolSet);
+            {
-            scope.Exec(source);
+                pyToolSet = ToolSet.ToPython();
-            scope.Exec("init(toolset)");
+                scope.Set("toolset", pyToolSet);
+                scope.Exec(source);
+                scope.Exec("init(toolset)");
+            }
         }
+        catch (Exception ex)
+        {
+            UpdateInfo = new() { DateTime = DateTime.Now, Successful = false, Exception = ex };
+            if (retryCounter < 3)
+            {
+                Logger.LogWarning("Unable to init the scriptable - retrying", [ToolSet.filePath, ex]);
+                retryCounter++;
+                goto retry;
+            }
+            Logger.LogError("Unable to init the scriptable", [ToolSet.filePath, ex]);
+            throw;
+        }
+        UpdateInfo = new() { DateTime = DateTime.Now, Successful = true };
     }
 
     public void Update(ICallbackInfos callbackInfos)
     {
-        using (Py.GIL())
+        int retryCounter = 0;
+        retry:
+        try
         {
-            pyToolSet = ToolSet.ToPython();
+            using (Py.GIL())
-            pyToolSet.SetAttr("callbackInfos", callbackInfos.ToPython());
+            {
-            scope.Set("toolset", pyToolSet);
+                pyToolSet = ToolSet.ToPython();
-            scope.Exec("update(toolset)");
+                pyToolSet.SetAttr("callbackInfos", callbackInfos.ToPython());
+                scope.Set("toolset", pyToolSet);
+                scope.Exec("update(toolset)");
+            }
         }
+        catch (Exception ex)
+        {
+            UpdateInfo = new() { DateTime = DateTime.Now, Successful = false, Exception = ex };
+            if (retryCounter < 3)
+            {
+                Logger.LogWarning("Execution of script failed to an exception - retrying", [ToolSet.filePath, ex]);
+                retryCounter++;
+                goto retry;
+            }
+            Logger.LogError("Execution of script failed to an exception", [ToolSet.filePath, ex]);
+            throw;
+        }
+        UpdateInfo = new() { DateTime = DateTime.Now, Successful = true };
     }
 
     public bool IsScript(string fileName)
@@ -87,5 +125,12 @@ public class IntervalCallbackInfos : ICallbackInfos
 {
     public object? sender;
     public required ElapsedEventArgs e;
-     
+
+}
+
+public struct ScriptUpdateInfo
+{
+    public DateTime DateTime { get; set; }
+    public bool Successful { get; set; }
+    public Exception? Exception { get; set; }
 }

src/Indexer/Models/Worker.cs

@@ -1,3 +1,5 @@
+using System.Diagnostics;
+using Microsoft.Extensions.Diagnostics.HealthChecks;
 namespace Indexer.Models;
 
 public class WorkerCollection
@@ -13,13 +15,41 @@ public class WorkerCollection
 
 public class Worker
 {
+    public string Name { get; set; }
     public WorkerConfig Config { get; set; }
     public IScriptable Scriptable { get; set; }
+    public List<ICall> Calls { get; set; }
 
-    public Worker(WorkerConfig workerConfig, IScriptable scriptable)
+    public Worker(string Name, WorkerConfig workerConfig, IScriptable scriptable)
     {
+        this.Name = Name;
         this.Config = workerConfig;
         this.Scriptable = scriptable;
+        Calls = [];
+    }
+
+    public HealthCheckResult HealthCheck()
+    {
+        bool hasDegraded = false;
+        bool hasUnhealthy = false;
+        foreach (ICall call in Calls)
+        {
+            HealthCheckResult callHealth = call.HealthCheck();
+            if (callHealth.Status != HealthStatus.Healthy)
+            {
+                hasDegraded |= callHealth.Status == HealthStatus.Degraded;
+                hasUnhealthy |= callHealth.Status == HealthStatus.Unhealthy;
+            }
+        }
+        if (hasUnhealthy)
+        {
+            return HealthCheckResult.Unhealthy(); // TODO: Retrieve and forward the error message for each call
+        }
+        else if (hasDegraded)
+        {
+            return HealthCheckResult.Degraded();
+        }
+        return HealthCheckResult.Healthy();
     }
 }
 
@@ -33,13 +63,64 @@ public class WorkerConfig
     public required string Name { get; set; }
     public required List<string> Searchdomains { get; set; }
     public required string Script { get; set; }
-    public required List<Call> Calls { get; set; }
+    public required List<CallConfig> Calls { get; set; }
 }
 
-public class Call
+public class CallConfig
 {
     public required string Type { get; set; }
     public long? Interval { get; set; } // For Type: Interval
     public string? Path { get; set; } // For Type: FileSystemWatcher
 }
 
+public interface ICall
+{
+    public HealthCheckResult HealthCheck();
+}
+
+public class IntervalCall : ICall
+{
+    public System.Timers.Timer Timer;
+    public IScriptable Scriptable;
+
+    public IntervalCall(System.Timers.Timer timer, IScriptable scriptable)
+    {
+        Timer = timer;
+        Scriptable = scriptable;
+    }
+
+    public HealthCheckResult HealthCheck()
+    {
+        if (!Scriptable.UpdateInfo.Successful)
+        {
+            Debug.WriteLine(Scriptable.UpdateInfo.Exception);
+            return HealthCheckResult.Unhealthy();
+        }
+        double timerInterval = Timer.Interval; // In ms
+        DateTime lastRunDateTime = Scriptable.UpdateInfo.DateTime;
+        DateTime now = DateTime.Now;
+        double millisecondsSinceLastExecution = now.Subtract(lastRunDateTime).TotalMilliseconds;
+        if (millisecondsSinceLastExecution >= 2 * timerInterval)
+        {
+            return HealthCheckResult.Unhealthy();
+        }
+        return HealthCheckResult.Healthy();
+    }
+
+}
+
+public class ScheduleCall : ICall
+{
+    public HealthCheckResult HealthCheck()
+    {
+        return HealthCheckResult.Unhealthy(); // Not implemented yet
+    }
+}
+
+public class FileUpdateCall : ICall
+{
+    public HealthCheckResult HealthCheck()
+    {
+        return HealthCheckResult.Unhealthy(); // Not implemented yet
+    }
+}

src/Indexer/Program.cs

@@ -1,6 +1,11 @@
+using Indexer;
 using Indexer.Models;
 using Indexer.Services;
+using ElmahCore;
+using ElmahCore.Mvc;
 using Server;
+using ElmahCore.Mvc.Logger;
+using Serilog;
 
 var builder = WebApplication.CreateBuilder(args);
 
@@ -10,16 +15,32 @@ builder.Services.AddControllers();
 // Learn more about configuring Swagger/OpenAPI at https://aka.ms/aspnetcore/swashbuckle
 builder.Services.AddEndpointsApiExplorer();
 builder.Services.AddSwaggerGen();
+Log.Logger = new LoggerConfiguration()
+    .WriteTo.File("logs/log-.txt", rollingInterval: RollingInterval.Day)  // Output files with daily rolling
+    .CreateLogger();
+builder.Logging.AddSerilog();
+builder.Services.AddHttpContextAccessor();
 builder.Services.AddSingleton<Client.Client>();
 builder.Services.AddSingleton<WorkerCollection>();
 builder.Services.AddHostedService<IndexerService>();
+builder.Services.AddHealthChecks()
+    .AddCheck<WorkerHealthCheck>("WorkerHealthCheck");
+
+builder.Services.AddElmah<XmlFileErrorLog>(Options =>
+{
+    Options.LogPath = "~/logs";
+});
+
 var app = builder.Build();
+app.UseElmah();
+app.MapHealthChecks("/healthz");
 
 // Configure the HTTP request pipeline.
 if (app.Environment.IsDevelopment())
 {
     app.UseSwagger();
     app.UseSwaggerUI();
+    app.UseElmahExceptionPage();
 }
 else
 {

src/Indexer/Services/IndexerService.cs

@@ -1,12 +1,6 @@
-using System;
-using System.Collections.Generic;
-using System.Linq;
-using System.Threading.Tasks;
 using Indexer.Exceptions;
 using Indexer.Models;
-using System.Timers;
+using ElmahCore;
-using Microsoft.AspNetCore.Http.HttpResults;
-using Python.Runtime;
 
 namespace Indexer.Services;
 
@@ -15,16 +9,18 @@ public class IndexerService : IHostedService
     private readonly WorkerCollection workerCollection;
     private readonly IConfiguration _config;
     private readonly Client.Client client;
+    public ILogger<IndexerService> _logger;
 
-    public IndexerService(WorkerCollection workerCollection, IConfiguration configuration, Client.Client client)
+    public IndexerService(WorkerCollection workerCollection, IConfiguration configuration, Client.Client client, ILogger<IndexerService> logger, IHttpContextAccessor httpContextAccessor)
     {
         this._config = configuration;
         this.client = client;
         this.workerCollection = workerCollection;
+        _logger = logger;
         // Load and configure all workers
         var sectionMain = _config.GetSection("EmbeddingsearchIndexer");
 
-        WorkerCollectionConfig? sectionWorker = (WorkerCollectionConfig?) sectionMain.Get(typeof(WorkerCollectionConfig)); //GetValue<WorkerCollectionConfig>("Worker");
+        WorkerCollectionConfig? sectionWorker = (WorkerCollectionConfig?)sectionMain.Get(typeof(WorkerCollectionConfig)); //GetValue<WorkerCollectionConfig>("Worker");
         if (sectionWorker is not null)
         {
             foreach (WorkerConfig workerConfig in sectionWorker.Worker)
@@ -34,26 +30,38 @@ public class IndexerService : IHostedService
                     client.searchdomain = workerConfig.Searchdomains.First();
                 }
                 ScriptToolSet toolSet = new(workerConfig.Script, client);
-                Worker worker = new(workerConfig, GetScriptable(toolSet));
+                Worker worker = new(workerConfig.Name, workerConfig, GetScriptable(toolSet));
                 workerCollection.Workers.Add(worker);
-                foreach (Call call in workerConfig.Calls)
+                foreach (CallConfig callConfig in workerConfig.Calls)
                 {
-                    switch (call.Type)
+                    switch (callConfig.Type)
                     {
                         case "interval":
-                            if (call.Interval is null)
+                            if (callConfig.Interval is null)
                             {
                                 throw new IndexerConfigurationException($"Interval not set for a Call in Worker \"{workerConfig.Name}\"");
                             }
-                            var timer = new System.Timers.Timer((double)call.Interval);
+                            var timer = new System.Timers.Timer((double)callConfig.Interval);
-                            timer.Elapsed += (sender, e) => worker.Scriptable.Update(new IntervalCallbackInfos() { sender = sender, e = e });
+                            timer.Elapsed += (sender, e) =>
+                            {
+                                try
+                                {
+                                    worker.Scriptable.Update(new IntervalCallbackInfos() { sender = sender, e = e });
+                                }
+                                catch (Exception ex)
+                                {
+                                    httpContextAccessor.HttpContext.RaiseError(ex);
+                                }                                
+                            };
                             timer.AutoReset = true;
                             timer.Enabled = true;
+                            IntervalCall call = new(timer, worker.Scriptable);
+                            worker.Calls.Add(call);
                             break;
                         case "schedule": // TODO implement scheduled tasks using Quartz
                             throw new NotImplementedException("schedule not implemented yet");
                         case "fileupdate":
-                            if (call.Path is null)
+                            if (callConfig.Path is null)
                             {
                                 throw new IndexerConfigurationException($"Path not set for a Call in Worker \"{workerConfig.Name}\"");
                             }
@@ -76,7 +84,7 @@ public class IndexerService : IHostedService
         string fileName = toolSet.filePath;
         foreach (Type type in workerCollection.types)
         {
-            IScriptable? instance = (IScriptable?)Activator.CreateInstance(type, toolSet);
+            IScriptable? instance = (IScriptable?)Activator.CreateInstance(type, [toolSet, _logger]);
             if (instance is not null && instance.IsScript(fileName))
             {
                 return instance;