Improved logging

This commit is contained in:
2025-06-11 13:23:51 +02:00
parent e6211a185b
commit a3d1a4679c
5 changed files with 35 additions and 16 deletions

View File

@@ -4,7 +4,7 @@ public interface IScriptable
{ {
ScriptToolSet ToolSet { get; set; } ScriptToolSet ToolSet { get; set; }
ScriptUpdateInfo UpdateInfo { get; set; } ScriptUpdateInfo UpdateInfo { get; set; }
ILogger Logger { get; set; } ILogger _logger { get; set; }
void Init(); void Init();
void Update(ICallbackInfos callbackInfos); void Update(ICallbackInfos callbackInfos);
bool IsScript(string filePath); bool IsScript(string filePath);

View File

@@ -11,10 +11,10 @@ public class PythonScriptable : IScriptable
public dynamic sys; public dynamic sys;
public string source; public string source;
public ScriptUpdateInfo UpdateInfo { get; set; } public ScriptUpdateInfo UpdateInfo { get; set; }
public ILogger Logger { get; set; } public ILogger _logger { get; set; }
public PythonScriptable(ScriptToolSet toolSet, ILogger logger) public PythonScriptable(ScriptToolSet toolSet, ILogger logger)
{ {
Logger = logger; _logger = logger;
Runtime.PythonDLL = @"libpython3.12.so"; Runtime.PythonDLL = @"libpython3.12.so";
if (!PythonEngine.IsInitialized) if (!PythonEngine.IsInitialized)
{ {
@@ -56,11 +56,11 @@ public class PythonScriptable : IScriptable
UpdateInfo = new() { DateTime = DateTime.Now, Successful = false, Exception = ex }; UpdateInfo = new() { DateTime = DateTime.Now, Successful = false, Exception = ex };
if (retryCounter < 3) if (retryCounter < 3)
{ {
Logger.LogWarning("Unable to init the scriptable - retrying", [ToolSet.filePath, ex]); _logger.LogWarning("Unable to init the scriptable - retrying", [ToolSet.filePath, ex]);
retryCounter++; retryCounter++;
goto retry; goto retry;
} }
Logger.LogError("Unable to init the scriptable", [ToolSet.filePath, ex]); _logger.LogError("Unable to init the scriptable", [ToolSet.filePath, ex]);
throw; throw;
} }
UpdateInfo = new() { DateTime = DateTime.Now, Successful = true }; UpdateInfo = new() { DateTime = DateTime.Now, Successful = true };
@@ -85,11 +85,11 @@ public class PythonScriptable : IScriptable
UpdateInfo = new() { DateTime = DateTime.Now, Successful = false, Exception = ex }; UpdateInfo = new() { DateTime = DateTime.Now, Successful = false, Exception = ex };
if (retryCounter < 3) if (retryCounter < 3)
{ {
Logger.LogWarning("Execution of script failed to an exception - retrying", [ToolSet.filePath, ex]); _logger.LogWarning("Execution of script failed to an exception - retrying", [ToolSet.filePath, ex]);
retryCounter++; retryCounter++;
goto retry; goto retry;
} }
Logger.LogError("Execution of script failed to an exception", [ToolSet.filePath, ex]); _logger.LogError("Execution of script failed to an exception", [ToolSet.filePath, ex]);
throw; throw;
} }
UpdateInfo = new() { DateTime = DateTime.Now, Successful = true }; UpdateInfo = new() { DateTime = DateTime.Now, Successful = true };

View File

@@ -82,17 +82,19 @@ public class IntervalCall : ICall
{ {
public System.Timers.Timer Timer; public System.Timers.Timer Timer;
public IScriptable Scriptable; public IScriptable Scriptable;
public ILogger _logger;
public IntervalCall(System.Timers.Timer timer, IScriptable scriptable) public IntervalCall(System.Timers.Timer timer, IScriptable scriptable, ILogger logger)
{ {
Timer = timer; Timer = timer;
Scriptable = scriptable; Scriptable = scriptable;
_logger = logger;
} }
public HealthCheckResult HealthCheck() public HealthCheckResult HealthCheck()
{ {
if (!Scriptable.UpdateInfo.Successful) if (!Scriptable.UpdateInfo.Successful)
{ {
_logger.LogWarning("HealthCheck revealed: The last execution of \"{name}\" was not successful", Scriptable.ToolSet.filePath);
return HealthCheckResult.Unhealthy(); return HealthCheckResult.Unhealthy();
} }
double timerInterval = Timer.Interval; // In ms double timerInterval = Timer.Interval; // In ms
@@ -101,6 +103,7 @@ public class IntervalCall : ICall
double millisecondsSinceLastExecution = now.Subtract(lastRunDateTime).TotalMilliseconds; double millisecondsSinceLastExecution = now.Subtract(lastRunDateTime).TotalMilliseconds;
if (millisecondsSinceLastExecution >= 2 * timerInterval) if (millisecondsSinceLastExecution >= 2 * timerInterval)
{ {
_logger.LogWarning("HealthCheck revealed: Since the last execution of \"{name}\" more than twice the interval has passed", Scriptable.ToolSet.filePath);
return HealthCheckResult.Unhealthy(); return HealthCheckResult.Unhealthy();
} }
return HealthCheckResult.Healthy(); return HealthCheckResult.Healthy();

View File

@@ -17,14 +17,21 @@ public class IndexerService : IHostedService
this.client = client; this.client = client;
this.workerCollection = workerCollection; this.workerCollection = workerCollection;
_logger = logger; _logger = logger;
_logger.LogInformation("Initializing IndexerService");
// Load and configure all workers // Load and configure all workers
var sectionMain = _config.GetSection("EmbeddingsearchIndexer"); var sectionMain = _config.GetSection("EmbeddingsearchIndexer");
if (!sectionMain.Exists())
{
_logger.LogCritical("Unable to load section \"EmbeddingsearchIndexer\"");
throw new IndexerConfigurationException("Unable to load section \"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) if (sectionWorker is not null)
{ {
foreach (WorkerConfig workerConfig in sectionWorker.Worker) foreach (WorkerConfig workerConfig in sectionWorker.Worker)
{ {
_logger.LogInformation("Initializing worker: {Name}", workerConfig.Name);
if (client.searchdomain == "" && workerConfig.Searchdomains.Count >= 1) if (client.searchdomain == "" && workerConfig.Searchdomains.Count >= 1)
{ {
client.searchdomain = workerConfig.Searchdomains.First(); client.searchdomain = workerConfig.Searchdomains.First();
@@ -34,11 +41,14 @@ public class IndexerService : IHostedService
workerCollection.Workers.Add(worker); workerCollection.Workers.Add(worker);
foreach (CallConfig callConfig in workerConfig.Calls) foreach (CallConfig callConfig in workerConfig.Calls)
{ {
_logger.LogInformation("Initializing call of type: {Type}", callConfig.Type);
switch (callConfig.Type) switch (callConfig.Type)
{ {
case "interval": case "interval":
if (callConfig.Interval is null) if (callConfig.Interval is null)
{ {
_logger.LogError("Interval not set for a Call in Worker \"{Name}\"", workerConfig.Name);
throw new IndexerConfigurationException($"Interval not set for a Call in Worker \"{workerConfig.Name}\""); throw new IndexerConfigurationException($"Interval not set for a Call in Worker \"{workerConfig.Name}\"");
} }
var timer = new System.Timers.Timer((double)callConfig.Interval); var timer = new System.Timers.Timer((double)callConfig.Interval);
@@ -50,12 +60,13 @@ public class IndexerService : IHostedService
} }
catch (Exception ex) catch (Exception ex)
{ {
_logger.LogError("Exception occurred in a Call of Worker \"{name}\": \"{ex}\"", worker.Name, ex.Message);
httpContextAccessor.HttpContext.RaiseError(ex); httpContextAccessor.HttpContext.RaiseError(ex);
} }
}; };
timer.AutoReset = true; timer.AutoReset = true;
timer.Enabled = true; timer.Enabled = true;
IntervalCall call = new(timer, worker.Scriptable); IntervalCall call = new(timer, worker.Scriptable, _logger);
worker.Calls.Add(call); worker.Calls.Add(call);
break; break;
case "schedule": // TODO implement scheduled tasks using Quartz case "schedule": // TODO implement scheduled tasks using Quartz
@@ -63,6 +74,7 @@ public class IndexerService : IHostedService
case "fileupdate": case "fileupdate":
if (callConfig.Path is null) if (callConfig.Path is null)
{ {
_logger.LogError("Path not set for a Call in Worker \"{Name}\"", workerConfig.Name);
throw new IndexerConfigurationException($"Path not set for a Call in Worker \"{workerConfig.Name}\""); throw new IndexerConfigurationException($"Path not set for a Call in Worker \"{workerConfig.Name}\"");
} }
throw new NotImplementedException("fileupdate not implemented yet"); throw new NotImplementedException("fileupdate not implemented yet");
@@ -75,7 +87,8 @@ public class IndexerService : IHostedService
} }
else else
{ {
throw new IndexerConfigurationException("Unable to find section \"Worker\""); _logger.LogCritical("Unable to load section \"Worker\"");
throw new IndexerConfigurationException("Unable to load section \"Worker\"");
} }
} }
@@ -90,6 +103,7 @@ public class IndexerService : IHostedService
return instance; return instance;
} }
} }
_logger.LogError("Unable to determine the script's language: \"{fileName}\"", fileName);
throw new UnknownScriptLanguageException(fileName); throw new UnknownScriptLanguageException(fileName);
} }

View File

@@ -47,8 +47,9 @@ public class EntityController : ControllerBase
{ {
searchdomain_ = _domainManager.GetSearchdomain(searchdomain); searchdomain_ = _domainManager.GetSearchdomain(searchdomain);
} }
catch (Exception) catch (Exception ex)
{ {
_logger.LogError("Unable to retrieve the searchdomain", [ex]);
return Ok(new EntityIndexResult() { Success = false }); return Ok(new EntityIndexResult() { Success = false });
} }
List<Entity>? entities = searchdomain_.EntitiesFromJSON(JsonSerializer.Serialize(jsonEntity)); List<Entity>? entities = searchdomain_.EntitiesFromJSON(JsonSerializer.Serialize(jsonEntity));
@@ -59,7 +60,7 @@ public class EntityController : ControllerBase
} }
else else
{ {
_logger.LogDebug("Unable to deserialize an entity"); _logger.LogError("Unable to deserialize an entity");
} }
return Ok(new EntityIndexResult() { Success = false }); return Ok(new EntityIndexResult() { Success = false });
@@ -72,8 +73,9 @@ public class EntityController : ControllerBase
try try
{ {
searchdomain_ = _domainManager.GetSearchdomain(searchdomain); searchdomain_ = _domainManager.GetSearchdomain(searchdomain);
} catch (Exception) } catch (Exception ex)
{ {
_logger.LogError("Unable to retrieve the searchdomain", [ex]);
return Ok(new EntityListResults() { Results = [], Success = false }); return Ok(new EntityListResults() { Results = [], Success = false });
} }
EntityListResults entityListResults = new() {Results = [], Success = true}; EntityListResults entityListResults = new() {Results = [], Success = true};