Add masked backend API request logging

Logs backend API activity while masking card IDs and connection-style sensitive values.

Configures backend file logging and records startup, timer, cache sync, order sync, and shutdown events.
feature/centralized-offline-canteen
SYED MUSTUFA AHMED NAQVI 2026-06-01 15:12:31 +05:00
parent 4d8ee06b04
commit 1237878db2
4 changed files with 173 additions and 23 deletions

View File

@ -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))

View File

@ -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..];
}
}

View File

@ -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<CanteenBackendWorker> _logger;
private CancellationTokenSource? _apiCts;
private Task? _apiTask;
private System.Timers.Timer? _cacheSyncTimer;
@ -22,22 +24,41 @@ public sealed class CanteenBackendWorker : BackgroundService
public CanteenBackendWorker(
IConfigService config,
DbContextFactory dbFactory,
IHostApplicationLifetime lifetime,
IConfiguration configuration)
IConfiguration configuration,
ILogger<CanteenBackendWorker> 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...");
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);
var offlineCacheSync = new OfflineCacheSyncService(employeeRfidTagSync, mealMenuCacheSync);
@ -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

View File

@ -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";