diff --git a/Api/CanteenBackendHost.cs b/Api/CanteenBackendHost.cs index 7bf5101..0cf5035 100644 --- a/Api/CanteenBackendHost.cs +++ b/Api/CanteenBackendHost.cs @@ -7,6 +7,7 @@ using UtopiaCanteen.Shared; using UtopiaCanteenSystem.Data; using UtopiaCanteenSystem.Models; using UtopiaCanteenSystem.Services; +using UtopiaCanteenSystem.Services.Logging; namespace UtopiaCanteenSystem.Api; @@ -41,7 +42,7 @@ public static class CanteenBackendHost listener.Prefixes.Add(prefix); listener.Start(); - Logger.Log(new Exception($"Canteen backend API listening: {string.Join(", ", prefixes)}"), "CanteenBackendHost"); + FileLogger.Info("BackendHost", $"Listening on {string.Join(", ", prefixes)}"); try { @@ -85,10 +86,14 @@ public static class CanteenBackendHost var path = ctx.Request.Url?.AbsolutePath?.TrimEnd('/') ?? string.Empty; var method = ctx.Request.HttpMethod ?? "GET"; + var clientIp = GetClientIp(ctx); var rfid = backend.Rfid; + FileLogger.Info("BackendHost", $"{method} {path} from {clientIp}"); + if (method == "GET" && path.Equals("/api/health", StringComparison.OrdinalIgnoreCase)) { + FileLogger.Debug("BackendHost", "Health check OK."); await WriteJsonAsync(ctx, new HealthResponse { Status = "ok", @@ -98,6 +103,12 @@ public static class CanteenBackendHost return; } + if (method == "GET" && path.Equals("/api/logs/path", StringComparison.OrdinalIgnoreCase)) + { + await WriteJsonAsync(ctx, new { logsPath = LogPaths.BackendLogsDirectory }).ConfigureAwait(false); + return; + } + if (method == "POST" && path.Equals("/api/rfid/scan", StringComparison.OrdinalIgnoreCase)) { await HandleScanAsync(ctx, rfid).ConfigureAwait(false); @@ -211,12 +222,14 @@ public static class CanteenBackendHost private static async Task HandleCacheSyncAsync(HttpListenerContext ctx, CanteenBackendServices backend) { var started = DateTime.UtcNow; + FileLogger.Info("CacheSync", "Manual cache sync API request received (POST /api/cache/sync-now)."); try { var result = await backend.RunCacheSyncExclusiveAsync(async () => { if (string.IsNullOrWhiteSpace(backend.Config.GetHrmsLookupConnectionString())) { + FileLogger.Warn("CacheSync", "Manual cache sync failed. MySQL connection string is not configured."); return ApiDtoMapper.ToManualSync(false, "MySQL connection string is not configured.", started, DateTime.UtcNow); } @@ -224,6 +237,7 @@ public static class CanteenBackendHost var completed = DateTime.UtcNow; if (!sync.Success) { + FileLogger.Error("CacheSync", $"Manual cache sync failed. Error={sync.ErrorMessage}"); return ApiDtoMapper.ToManualSync(false, sync.ErrorMessage ?? "Cache sync failed.", started, completed, sync.ErrorMessage); } @@ -236,14 +250,17 @@ public static class CanteenBackendHost $"Menu items: {meal?.LunchMenuItemCount ?? 0}; " + $"Menu catalog: {meal?.MenuItemCount ?? 0}."; + FileLogger.Info("CacheSync", $"Manual cache sync completed successfully. {details}"); return ApiDtoMapper.ToManualSync(true, "Employee and menu cache synced successfully.", started, completed, details); }).ConfigureAwait(false); + FileLogger.Info("CacheSync", $"Cache sync API response. Success={result.Success}, Message={result.Message}"); await WriteJsonAsync(ctx, result, result.Success ? 200 : 500).ConfigureAwait(false); } catch (Exception ex) { Logger.Log(ex, "CanteenBackendHost.HandleCacheSyncAsync"); + FileLogger.Error("CacheSync", "Manual cache sync API failed with exception.", ex); await WriteJsonAsync(ctx, ApiDtoMapper.ToManualSync(false, ex.Message, started, DateTime.UtcNow, ex.ToString()), 500).ConfigureAwait(false); } } @@ -251,30 +268,44 @@ public static class CanteenBackendHost private static async Task HandleOrdersSyncAsync(HttpListenerContext ctx, CanteenBackendServices backend) { var started = DateTime.UtcNow; + FileLogger.Info("OrderSync", "Manual order sync API request received (POST /api/orders/sync-now)."); try { var result = await backend.RunOrderSyncExclusiveAsync(async () => { if (string.IsNullOrWhiteSpace(backend.Config.GetMySqlConnectionString())) { + FileLogger.Warn("OrderSync", "Manual order sync failed. Production MySQL connection is not configured."); return ApiDtoMapper.ToManualSync(false, "Production MySQL connection is not configured.", started, DateTime.UtcNow); } - await backend.ProductionSync.SyncNowAsync().ConfigureAwait(false); + var stats = await backend.ProductionSync.SyncNowAsync().ConfigureAwait(false); var completed = DateTime.UtcNow; - return ApiDtoMapper.ToManualSync( - true, - "Pending orders posted to production.", - started, - completed, - "Unsynced lunch_order_transactions were posted and marked IsSynced where successful."); + var details = + $"Pending={stats.PendingCount}, Posted={stats.PostedCount}, " + + $"DuplicatesSkipped={stats.DuplicatesSkippedCount}, Failed={stats.FailedCount}."; + var success = !stats.SkippedNoConnection && stats.FailedCount == 0; + var message = stats.PendingCount == 0 + ? "No pending orders to post." + : success + ? "Pending orders posted to production." + : "Order sync completed with errors."; + + if (success) + FileLogger.Info("OrderSync", $"Manual order sync completed. {details}"); + else + FileLogger.Warn("OrderSync", $"Manual order sync finished with issues. {details}"); + + return ApiDtoMapper.ToManualSync(success, message, started, completed, details); }).ConfigureAwait(false); + FileLogger.Info("OrderSync", $"Order sync API response. Success={result.Success}, Message={result.Message}"); await WriteJsonAsync(ctx, result, result.Success ? 200 : 500).ConfigureAwait(false); } catch (Exception ex) { Logger.Log(ex, "CanteenBackendHost.HandleOrdersSyncAsync"); + FileLogger.Error("OrderSync", "Manual order sync API failed with exception.", ex); await WriteJsonAsync(ctx, ApiDtoMapper.ToManualSync(false, ex.Message, started, DateTime.UtcNow, ex.ToString()), 500).ConfigureAwait(false); } } @@ -313,7 +344,19 @@ public static class CanteenBackendHost IpAddress = ip }; + FileLogger.Info( + "RfidScan", + $"Scan request. CardId={LogMasking.MaskCardId(dto.CardId)}, DeviceId={clientCtx.DeviceId}, SiteId={clientCtx.SiteId}, ClientIp={remoteIp}"); + var result = rfid.ProcessScanDetailed(dto.CardId.Trim(), clientCtx); + + var duplicateBlocked = !result.Success && + (result.Message.Contains("already", StringComparison.OrdinalIgnoreCase) || + result.Message.Contains("within", StringComparison.OrdinalIgnoreCase)); + FileLogger.Info( + "RfidScan", + $"Scan result. Success={result.Success}, Message={result.Message}, DuplicateBlocked={duplicateBlocked}, OrderSaved={result.Success}"); + string? mealLabel = null; string? mealItems = null; double totalPrice = 0; @@ -500,6 +543,12 @@ public static class CanteenBackendHost return int.TryParse(s, out var n) ? n : defaultValue; } + private static string GetClientIp(HttpListenerContext ctx) + { + var ip = ctx.Request.RemoteEndPoint?.Address?.ToString() ?? "unknown"; + return ip == "::1" ? "127.0.0.1" : ip; + } + private static string? ParseQueryString(string? query, string key) { if (string.IsNullOrEmpty(query)) diff --git a/Services/Logging/LogMasking.cs b/Services/Logging/LogMasking.cs new file mode 100644 index 0000000..3f9f9dc --- /dev/null +++ b/Services/Logging/LogMasking.cs @@ -0,0 +1,29 @@ +namespace UtopiaCanteenSystem.Services.Logging; + +public static class LogMasking +{ + public static string MaskCardId(string? cardId) + { + if (string.IsNullOrWhiteSpace(cardId)) + return "(empty)"; + + var s = cardId.Trim(); + if (s.Length <= 4) + return new string('*', s.Length); + + var visible = Math.Min(4, s.Length); + return s[..visible] + new string('*', s.Length - visible); + } + + public static string MaskConnectionString(string? connectionString) + { + if (string.IsNullOrWhiteSpace(connectionString)) + return "(not configured)"; + + var s = connectionString.Trim(); + if (s.Length <= 20) + return "***"; + + return s[..12] + "***" + s[^4..]; + } +} diff --git a/UtopiaCanteen.BackendService/CanteenBackendWorker.cs b/UtopiaCanteen.BackendService/CanteenBackendWorker.cs index 5f380bf..3c8a503 100644 --- a/UtopiaCanteen.BackendService/CanteenBackendWorker.cs +++ b/UtopiaCanteen.BackendService/CanteenBackendWorker.cs @@ -1,7 +1,9 @@ using Microsoft.EntityFrameworkCore; +using Microsoft.Extensions.Logging; using UtopiaCanteenSystem.Api; using UtopiaCanteenSystem.Data; using UtopiaCanteenSystem.Services; +using UtopiaCanteenSystem.Services.Logging; namespace UtopiaCanteen.BackendService; @@ -9,8 +11,8 @@ public sealed class CanteenBackendWorker : BackgroundService { private readonly IConfigService _config; private readonly DbContextFactory _dbFactory; - private readonly IHostApplicationLifetime _lifetime; private readonly IConfiguration _configuration; + private readonly ILogger _logger; private CancellationTokenSource? _apiCts; private Task? _apiTask; private System.Timers.Timer? _cacheSyncTimer; @@ -22,21 +24,40 @@ public sealed class CanteenBackendWorker : BackgroundService public CanteenBackendWorker( IConfigService config, DbContextFactory dbFactory, - IHostApplicationLifetime lifetime, - IConfiguration configuration) + IConfiguration configuration, + ILogger logger) { _config = config; _dbFactory = dbFactory; - _lifetime = lifetime; _configuration = configuration; + _logger = logger; } public override async Task StartAsync(CancellationToken cancellationToken) { - Logger.Log(new Exception("UtopiaCanteen backend service starting."), "CanteenBackendWorker"); + _logger.LogInformation("Service starting..."); + FileLogger.Info("BackendService", "Service starting..."); - using (var db = _dbFactory.CreateDbContext()) - db.EnsureDatabaseCreated(); + try + { + using (var db = _dbFactory.CreateDbContext()) + db.EnsureDatabaseCreated(); + + FileLogger.Info("BackendService", $"Configuration loaded. SQLite DB path={DatabasePath.GetDbPath()}"); + FileLogger.Info("BackendService", $"ListenUrls={_config.GetLocalServerListenUrls()}"); + FileLogger.Info( + "BackendService", + $"MySqlConnectionString={LogMasking.MaskConnectionString(_config.GetMySqlConnectionString())}"); + FileLogger.Info( + "BackendService", + $"HrmsConnection(effective)={LogMasking.MaskConnectionString(_config.GetHrmsLookupConnectionString())}"); + FileLogger.Info("BackendService", $"Logs directory={LogPaths.BackendLogsDirectory}"); + } + catch (Exception ex) + { + FileLogger.Error("BackendService", "Failed during startup initialization.", ex); + throw; + } var employeeRfidTagSync = new EmployeeRfidTagSyncService(_dbFactory, _config); var mealMenuCacheSync = new MealMenuCacheSyncService(_dbFactory, _config); @@ -61,10 +82,11 @@ public sealed class CanteenBackendWorker : BackgroundService } catch (OperationCanceledException) { - // Shutdown + FileLogger.Info("BackendService", "API host stopped (cancellation)."); } catch (Exception ex) { + FileLogger.Error("BackendService", "API host failed.", ex); Logger.Log(ex, "CanteenBackendWorker.ApiHost"); } }, CancellationToken.None); @@ -75,24 +97,37 @@ public sealed class CanteenBackendWorker : BackgroundService if (!string.IsNullOrWhiteSpace(_config.GetHrmsLookupConnectionString())) { _cacheSyncTimer = new System.Timers.Timer(TimeSpan.FromMinutes(cacheMinutes).TotalMilliseconds) { AutoReset = true }; - _cacheSyncTimer.Elapsed += async (_, _) => await RunCacheSyncSafeAsync().ConfigureAwait(false); + _cacheSyncTimer.Elapsed += async (_, _) => await RunCacheSyncSafeAsync("timer").ConfigureAwait(false); _cacheSyncTimer.Start(); + FileLogger.Info("BackendService", $"Background cache sync timer started. IntervalMinutes={cacheMinutes}"); + } + else + { + FileLogger.Warn("BackendService", "Background cache sync timer not started (MySQL/HRMS connection not configured)."); } var orderMinutes = Math.Max(1, _configuration.GetValue("ProductionSyncIntervalMinutes", 1)); if (_config.GetSyncServiceEnabled() && !string.IsNullOrWhiteSpace(_config.GetMySqlConnectionString())) { _orderSyncTimer = new System.Timers.Timer(TimeSpan.FromMinutes(orderMinutes).TotalMilliseconds) { AutoReset = true }; - _orderSyncTimer.Elapsed += async (_, _) => await RunOrderSyncSafeAsync().ConfigureAwait(false); + _orderSyncTimer.Elapsed += async (_, _) => await RunOrderSyncSafeAsync("timer").ConfigureAwait(false); _orderSyncTimer.Start(); + FileLogger.Info("BackendService", $"Background production sync timer started. IntervalMinutes={orderMinutes}"); + } + else + { + FileLogger.Warn("BackendService", "Background production sync timer not started (disabled or MySQL not configured)."); } + _logger.LogInformation("Service started."); + FileLogger.Info("BackendService", "Service started."); await base.StartAsync(cancellationToken).ConfigureAwait(false); } public override async Task StopAsync(CancellationToken cancellationToken) { - Logger.Log(new Exception("UtopiaCanteen backend service stopping."), "CanteenBackendWorker"); + _logger.LogInformation("Service stopping..."); + FileLogger.Info("BackendService", "Service stopping..."); _cacheSyncTimer?.Stop(); _orderSyncTimer?.Stop(); _apiCts?.Cancel(); @@ -111,6 +146,7 @@ public sealed class CanteenBackendWorker : BackgroundService _cacheSyncTimer?.Dispose(); _orderSyncTimer?.Dispose(); _apiCts?.Dispose(); + FileLogger.Info("BackendService", "Service stopped."); await base.StopAsync(cancellationToken).ConfigureAwait(false); } @@ -120,8 +156,12 @@ public sealed class CanteenBackendWorker : BackgroundService private async Task RunStartupCacheSyncAsync(CancellationToken cancellationToken) { if (_backend == null || string.IsNullOrWhiteSpace(_config.GetHrmsLookupConnectionString())) + { + FileLogger.Info("CacheSync", "Startup cache sync skipped (MySQL/HRMS connection not configured)."); return; + } + FileLogger.Info("CacheSync", "Startup cache sync started."); for (var i = 0; i < 30 && !cancellationToken.IsCancellationRequested; i++) { try @@ -131,20 +171,32 @@ public sealed class CanteenBackendWorker : BackgroundService await _backend.OfflineCacheSync.SyncEmployeeAndMenuCacheAsync().ConfigureAwait(false); return true; }).ConfigureAwait(false); + FileLogger.Info("CacheSync", "Startup cache sync completed."); return; } catch (Exception ex) { + FileLogger.Warn("CacheSync", $"Startup cache sync attempt {i + 1} failed; retrying.", ex); Logger.Log(ex, "CanteenBackendWorker.RunStartupCacheSyncAsync"); } await Task.Delay(1000, cancellationToken).ConfigureAwait(false); } + + FileLogger.Error("CacheSync", "Startup cache sync failed after retries."); } - private async Task RunCacheSyncSafeAsync() + private async Task RunCacheSyncSafeAsync(string trigger) { - if (_backend == null || Interlocked.Exchange(ref _cacheSyncRunning, 1) == 1) + if (_backend == null) return; + + if (Interlocked.Exchange(ref _cacheSyncRunning, 1) == 1) + { + FileLogger.Info("CacheSync", $"Background cache sync skipped ({trigger}): already running."); + return; + } + + FileLogger.Info("CacheSync", $"Background cache sync started ({trigger})."); try { await _backend.RunCacheSyncExclusiveAsync(async () => @@ -152,9 +204,11 @@ public sealed class CanteenBackendWorker : BackgroundService await _backend.OfflineCacheSync.SyncEmployeeAndMenuCacheAsync().ConfigureAwait(false); return true; }).ConfigureAwait(false); + FileLogger.Info("CacheSync", $"Background cache sync completed ({trigger})."); } catch (Exception ex) { + FileLogger.Error("CacheSync", $"Background cache sync failed ({trigger}).", ex); Logger.Log(ex, "CanteenBackendWorker.RunCacheSyncSafeAsync"); } finally @@ -163,10 +217,18 @@ public sealed class CanteenBackendWorker : BackgroundService } } - private async Task RunOrderSyncSafeAsync() + private async Task RunOrderSyncSafeAsync(string trigger) { - if (_backend == null || Interlocked.Exchange(ref _orderSyncRunning, 1) == 1) + if (_backend == null) return; + + if (Interlocked.Exchange(ref _orderSyncRunning, 1) == 1) + { + FileLogger.Info("OrderSync", $"Background order sync skipped ({trigger}): already running."); + return; + } + + FileLogger.Info("OrderSync", $"Background order sync started ({trigger})."); try { await _backend.RunOrderSyncExclusiveAsync(async () => @@ -174,9 +236,11 @@ public sealed class CanteenBackendWorker : BackgroundService await _backend.ProductionSync.SyncNowAsync().ConfigureAwait(false); return true; }).ConfigureAwait(false); + FileLogger.Info("OrderSync", $"Background order sync completed ({trigger})."); } catch (Exception ex) { + FileLogger.Error("OrderSync", $"Background order sync failed ({trigger}).", ex); Logger.Log(ex, "CanteenBackendWorker.RunOrderSyncSafeAsync"); } finally diff --git a/UtopiaCanteen.BackendService/Program.cs b/UtopiaCanteen.BackendService/Program.cs index 265b603..488df5e 100644 --- a/UtopiaCanteen.BackendService/Program.cs +++ b/UtopiaCanteen.BackendService/Program.cs @@ -2,10 +2,18 @@ using Microsoft.EntityFrameworkCore; using UtopiaCanteen.BackendService; using UtopiaCanteenSystem.Data; using UtopiaCanteenSystem.Services; +using UtopiaCanteenSystem.Services.Logging; DatabasePath.UseBackendServiceStorage(); var builder = Host.CreateApplicationBuilder(args); +var logsDirectory = builder.Configuration["LogsDirectory"]; +if (!string.IsNullOrWhiteSpace(logsDirectory)) + LogPaths.SetBackendLogsDirectory(logsDirectory); + +FileLogger.ConfigureBackend(); +builder.Logging.ClearProviders(); +builder.Logging.AddProvider(new FileLoggerProvider()); builder.Services.AddWindowsService(options => { options.ServiceName = "UtopiaCanteenBackend";