From fef66f6d7b983ab5eeb7b7ba219a6c83e129eb85 Mon Sep 17 00:00:00 2001 From: cryptooda Date: Mon, 24 Nov 2025 01:02:53 +0700 Subject: [PATCH] Update configuration settings and logging behavior for SQL monitoring - Increased thresholds for maximum query and method executions per window to 500 and 250, respectively, to reduce false positives in loop detection. - Enabled logging of slow queries only, improving performance by reducing log volume. - Adjusted SQL query logging to capture only warnings and errors, further optimizing logging efficiency. - Updated various settings across appsettings files to reflect these changes, ensuring consistency in configuration. --- src/Managing.Api/Program.cs | 12 +++------ src/Managing.Api/appsettings.Production.json | 4 ++- src/Managing.Api/appsettings.Sandbox.json | 2 +- src/Managing.Api/appsettings.json | 6 ++--- .../PostgreSql/BaseRepositoryWithLogging.cs | 8 +++--- .../PostgreSql/ManagingDbContext.cs | 14 ++++++----- .../PostgreSql/SentrySqlMonitoringService.cs | 14 +++++------ .../PostgreSql/SqlLoopDetectionService.cs | 12 ++++----- .../PostgreSql/SqlMonitoringSettings.cs | 12 ++++----- .../PostgreSql/SqlQueryLogger.cs | 25 +++++++++++-------- 10 files changed, 56 insertions(+), 53 deletions(-) diff --git a/src/Managing.Api/Program.cs b/src/Managing.Api/Program.cs index 9852425f..a90d153d 100644 --- a/src/Managing.Api/Program.cs +++ b/src/Managing.Api/Program.cs @@ -132,22 +132,18 @@ builder.Services.AddDbContext((serviceProvider, options) => // Enable service provider caching for better performance options.EnableServiceProviderCaching(); - // Enable comprehensive SQL query logging for monitoring and debugging + // Enable SQL query logging for warnings and errors only (reduced logging) var logger = serviceProvider.GetRequiredService>(); var sentryMonitoringService = serviceProvider.GetRequiredService(); options.LogTo(msg => { - // Log SQL queries with enhanced formatting - if (msg.Contains("Executed DbCommand") || msg.Contains("Executing DbCommand")) - { - Console.WriteLine($"[EF-SQL] {msg}"); - } - else if (msg.Contains("Warning") || msg.Contains("Error")) + // Log only warnings and errors to reduce log volume + if (msg.Contains("Warning") || msg.Contains("Error")) { Console.WriteLine($"[EF-WARNING] {msg}"); } - }, LogLevel.Information); // Log all SQL operations for monitoring + }, LogLevel.Warning); // Log only warnings and errors to reduce SQL log volume }, ServiceLifetime.Scoped); // Explicitly specify scoped lifetime for proper request isolation // Add specific health checks for databases and other services diff --git a/src/Managing.Api/appsettings.Production.json b/src/Managing.Api/appsettings.Production.json index 503c898e..d2e9607f 100644 --- a/src/Managing.Api/appsettings.Production.json +++ b/src/Managing.Api/appsettings.Production.json @@ -37,7 +37,9 @@ "LoggingEnabled": false, "SentryEnabled": false, "LoopDetectionEnabled": true, - "LogErrorsOnly": true + "LogErrorsOnly": true, + "MaxQueryExecutionsPerWindow": 500, + "MaxMethodExecutionsPerWindow": 250 }, "Cors": { "AllowedOrigins": [ diff --git a/src/Managing.Api/appsettings.Sandbox.json b/src/Managing.Api/appsettings.Sandbox.json index 2d40b09d..5259f353 100644 --- a/src/Managing.Api/appsettings.Sandbox.json +++ b/src/Managing.Api/appsettings.Sandbox.json @@ -34,7 +34,7 @@ "LoggingEnabled": true, "SentryEnabled": false, "LoopDetectionEnabled": true, - "LogSlowQueriesOnly": false + "LogSlowQueriesOnly": true }, "RunOrleansGrains": true, "AllowedHosts": "*", diff --git a/src/Managing.Api/appsettings.json b/src/Managing.Api/appsettings.json index 319b1408..a8a73bdb 100644 --- a/src/Managing.Api/appsettings.json +++ b/src/Managing.Api/appsettings.json @@ -96,12 +96,12 @@ "LoopDetectionEnabled": true, "PerformanceMonitoringEnabled": true, "LoopDetectionWindowSeconds": 60, - "MaxQueryExecutionsPesrWindow": 100, - "MaxMethodExecutionsPerWindow": 50, + "MaxQueryExecutionsPerWindow": 500, + "MaxMethodExecutionsPerWindow": 250, "LongRunningQueryThresholdMs": 1000, "SentryAlertThreshold": 5, "SlowQueryThresholdMs": 1500, - "LogSlowQueriesOnly": false, + "LogSlowQueriesOnly": true, "LogErrorsOnly": false, "DataRetentionMinutes": 300 }, diff --git a/src/Managing.Infrastructure.Database/PostgreSql/BaseRepositoryWithLogging.cs b/src/Managing.Infrastructure.Database/PostgreSql/BaseRepositoryWithLogging.cs index f86ef214..e5abd1ec 100644 --- a/src/Managing.Infrastructure.Database/PostgreSql/BaseRepositoryWithLogging.cs +++ b/src/Managing.Infrastructure.Database/PostgreSql/BaseRepositoryWithLogging.cs @@ -50,8 +50,8 @@ public abstract class BaseRepositoryWithLogging var result = await operation(); stopwatch.Stop(); - // Only log if slow query (>2000ms) and logging is enabled - if (stopwatch.Elapsed.TotalMilliseconds > 2000 && _sentryMonitoringService.IsLoggingEnabled()) + // Only log if it should be logged based on monitoring settings (respects LogSlowQueriesOnly and thresholds) + if (_sentryMonitoringService.ShouldLogQuery(stopwatch.Elapsed)) { _logger.LogWarning( "[SLOW-SQL] {Repository}.{Method} | Pattern: {Pattern} | Time: {Time}ms", @@ -121,8 +121,8 @@ public abstract class BaseRepositoryWithLogging await operation(); stopwatch.Stop(); - // Only log if slow query (>2000ms) and logging is enabled - if (stopwatch.Elapsed.TotalMilliseconds > 2000 && _sentryMonitoringService.IsLoggingEnabled()) + // Only log if it should be logged based on monitoring settings (respects LogSlowQueriesOnly and thresholds) + if (_sentryMonitoringService.ShouldLogQuery(stopwatch.Elapsed)) { _logger.LogWarning( "[SLOW-SQL] {Repository}.{Method} | Pattern: {Pattern} | Time: {Time}ms", diff --git a/src/Managing.Infrastructure.Database/PostgreSql/ManagingDbContext.cs b/src/Managing.Infrastructure.Database/PostgreSql/ManagingDbContext.cs index b9efc9df..4dc63d49 100644 --- a/src/Managing.Infrastructure.Database/PostgreSql/ManagingDbContext.cs +++ b/src/Managing.Infrastructure.Database/PostgreSql/ManagingDbContext.cs @@ -768,12 +768,14 @@ public class ManagingDbContext : DbContext // Check for potential loops with Sentry integration var isLoopDetected = _sentryMonitoringService.TrackQueryExecution(repositoryName, methodName, queryPattern, executionTime); - // Log query execution details - var logLevel = executionTime.TotalMilliseconds > 1000 ? LogLevel.Warning : LogLevel.Debug; - _logger.Log(logLevel, - "[SQL-QUERY-TRACKED] {Repository}.{Method} | Pattern: {Pattern} | Time: {Time}ms | Count: {Count}", - repositoryName, methodName, queryPattern, executionTime.TotalMilliseconds, - _queryExecutionCounts[queryPattern]); + // Only log query execution details if it should be logged based on monitoring settings + if (_sentryMonitoringService.ShouldLogQuery(executionTime)) + { + _logger.LogWarning( + "[SQL-QUERY-TRACKED] {Repository}.{Method} | Pattern: {Pattern} | Time: {Time}ms | Count: {Count}", + repositoryName, methodName, queryPattern, executionTime.TotalMilliseconds, + _queryExecutionCounts[queryPattern]); + } // Alert on potential loops if (isLoopDetected) diff --git a/src/Managing.Infrastructure.Database/PostgreSql/SentrySqlMonitoringService.cs b/src/Managing.Infrastructure.Database/PostgreSql/SentrySqlMonitoringService.cs index 771f611c..6a53adbb 100644 --- a/src/Managing.Infrastructure.Database/PostgreSql/SentrySqlMonitoringService.cs +++ b/src/Managing.Infrastructure.Database/PostgreSql/SentrySqlMonitoringService.cs @@ -71,13 +71,13 @@ public class SentrySqlMonitoringService var sentryTags = new Dictionary(); var sentryExtras = new Dictionary(); - // Check execution frequency - if (executionsPerMinute > 20) + // Check execution frequency (increased threshold to reduce false positives) + if (executionsPerMinute > 100) { isLoopDetected = true; reasons.Add($"High frequency: {executionsPerMinute:F1} executions/minute"); - if (executionsPerMinute > 50) // Critical frequency threshold + if (executionsPerMinute > 200) // Critical frequency threshold (increased) { isCriticalAlert = true; sentryTags["alert_level"] = "critical"; @@ -99,8 +99,8 @@ public class SentrySqlMonitoringService } } - // Check for rapid successive executions - if (tracker.ExecutionCount > 5 && timeSinceFirst.TotalSeconds < 10) + // Check for rapid successive executions (increased threshold to reduce false positives) + if (tracker.ExecutionCount > 20 && timeSinceFirst.TotalSeconds < 10) { isLoopDetected = true; isCriticalAlert = true; @@ -109,8 +109,8 @@ public class SentrySqlMonitoringService sentryTags["issue_type"] = "rapid_execution"; } - // Check for consistently slow queries - if (tracker.ExecutionCount > 3 && tracker.AverageExecutionTime.TotalMilliseconds > 1000) + // Check for consistently slow queries (increased threshold to reduce false positives) + if (tracker.ExecutionCount > 10 && tracker.AverageExecutionTime.TotalMilliseconds > 1000) { isLoopDetected = true; reasons.Add($"Consistently slow: {tracker.AverageExecutionTime.TotalMilliseconds:F0}ms average"); diff --git a/src/Managing.Infrastructure.Database/PostgreSql/SqlLoopDetectionService.cs b/src/Managing.Infrastructure.Database/PostgreSql/SqlLoopDetectionService.cs index 43967b00..54ad49dc 100644 --- a/src/Managing.Infrastructure.Database/PostgreSql/SqlLoopDetectionService.cs +++ b/src/Managing.Infrastructure.Database/PostgreSql/SqlLoopDetectionService.cs @@ -73,8 +73,8 @@ public class SqlLoopDetectionService var isLoopDetected = false; var reasons = new List(); - // Check execution frequency - if (executionsPerMinute > 20) + // Check execution frequency (increased threshold to reduce false positives) + if (executionsPerMinute > 100) { isLoopDetected = true; reasons.Add($"High frequency: {executionsPerMinute:F1} executions/minute"); @@ -87,16 +87,16 @@ public class SqlLoopDetectionService reasons.Add($"High count: {tracker.ExecutionCount} executions in {timeSinceFirst.TotalMinutes:F1} minutes"); } - // Check for rapid successive executions - if (tracker.ExecutionCount > 5 && timeSinceFirst.TotalSeconds < 10) + // Check for rapid successive executions (increased threshold to reduce false positives) + if (tracker.ExecutionCount > 20 && timeSinceFirst.TotalSeconds < 10) { isLoopDetected = true; reasons.Add( $"Rapid execution: {tracker.ExecutionCount} executions in {timeSinceFirst.TotalSeconds:F1} seconds"); } - // Check for consistently slow queries - if (tracker.ExecutionCount > 3 && tracker.AverageExecutionTime.TotalMilliseconds > 1000) + // Check for consistently slow queries (increased threshold to reduce false positives) + if (tracker.ExecutionCount > 10 && tracker.AverageExecutionTime.TotalMilliseconds > 1000) { isLoopDetected = true; reasons.Add($"Consistently slow: {tracker.AverageExecutionTime.TotalMilliseconds:F0}ms average"); diff --git a/src/Managing.Infrastructure.Database/PostgreSql/SqlMonitoringSettings.cs b/src/Managing.Infrastructure.Database/PostgreSql/SqlMonitoringSettings.cs index 11d59cfd..c955e1fc 100644 --- a/src/Managing.Infrastructure.Database/PostgreSql/SqlMonitoringSettings.cs +++ b/src/Managing.Infrastructure.Database/PostgreSql/SqlMonitoringSettings.cs @@ -36,14 +36,14 @@ public class SqlMonitoringSettings public int LoopDetectionWindowSeconds { get; set; } = 60; /// - /// Maximum query executions per window for loop detection (default: 100) + /// Maximum query executions per window for loop detection (default: 500) /// - public int MaxQueryExecutionsPerWindow { get; set; } = 100; + public int MaxQueryExecutionsPerWindow { get; set; } = 500; /// - /// Maximum method executions per window for loop detection (default: 50) + /// Maximum method executions per window for loop detection (default: 250) /// - public int MaxMethodExecutionsPerWindow { get; set; } = 50; + public int MaxMethodExecutionsPerWindow { get; set; } = 250; /// /// Threshold for long-running queries in milliseconds (default: 1000) @@ -61,9 +61,9 @@ public class SqlMonitoringSettings public int SlowQueryThresholdMs { get; set; } = 2000; /// - /// Whether to log only slow queries (reduces overhead) (default: false) + /// Whether to log only slow queries (reduces overhead) (default: true) /// - public bool LogSlowQueriesOnly { get; set; } = false; + public bool LogSlowQueriesOnly { get; set; } = true; /// /// Whether to log only errors (minimal overhead) (default: false) diff --git a/src/Managing.Infrastructure.Database/PostgreSql/SqlQueryLogger.cs b/src/Managing.Infrastructure.Database/PostgreSql/SqlQueryLogger.cs index 3336c481..5ea4f4ff 100644 --- a/src/Managing.Infrastructure.Database/PostgreSql/SqlQueryLogger.cs +++ b/src/Managing.Infrastructure.Database/PostgreSql/SqlQueryLogger.cs @@ -34,6 +34,7 @@ public class SqlQueryLogger : IDisposable /// /// Logs the start of a database operation + /// Only logs at Debug level to reduce log volume (not logged by default) /// public void LogOperationStart(params (string name, object value)[] parameters) { @@ -42,20 +43,20 @@ public class SqlQueryLogger : IDisposable _parameters[name] = value; } - _logger.LogInformation( + _logger.LogDebug( "[SQL-OP-START] {OperationId} | {Repository}.{Method} | Started at {StartTime}", _operationId, _repositoryName, _methodName, _startTime.ToString("HH:mm:ss.fff")); } /// /// Logs a SQL query execution with timing and parameters + /// Only logs errors and slow queries (>1500ms) to reduce log volume /// public void LogQueryExecution(string query, TimeSpan executionTime, int? rowsAffected = null, Exception? exception = null) { _executedQueries.Add(query); - var logLevel = exception != null ? LogLevel.Error : - executionTime.TotalMilliseconds > 1000 ? LogLevel.Warning : LogLevel.Information; + const int slowQueryThresholdMs = 1500; // Only log queries slower than this threshold var logMessage = exception != null ? "[SQL-QUERY-ERROR] {OperationId} | {Repository}.{Method} | Query failed after {ExecutionTime}ms | Error: {Error}" @@ -75,23 +76,24 @@ public class SqlQueryLogger : IDisposable // Send SQL error to Sentry SendSqlErrorToSentry(query, executionTime, exception, rowsAffected); } - else + else if (executionTime.TotalMilliseconds > slowQueryThresholdMs) { - _logger.Log(logLevel, logMessage, args); + // Only log slow queries, not normal queries + _logger.LogWarning(logMessage, args); // Send slow query alert to Sentry if (executionTime.TotalMilliseconds > 2000) // Critical slow query threshold { SendSlowQueryToSentry(query, executionTime, rowsAffected); } - else if (executionTime.TotalMilliseconds > 1000) // Warning threshold + else { SendSlowQueryWarningToSentry(query, executionTime, rowsAffected); } } - // Log query details for slow queries or errors - if (executionTime.TotalMilliseconds > 500 || exception != null) + // Log query details for slow queries or errors only + if (executionTime.TotalMilliseconds > slowQueryThresholdMs || exception != null) { _logger.LogWarning( "[SQL-QUERY-DETAILS] {OperationId} | Query: {Query} | Parameters: {Parameters}", @@ -127,13 +129,14 @@ public class SqlQueryLogger : IDisposable args[5] = exception.Message; _logger.LogError(exception, logMessage, args); } - else + else if (totalTime.TotalMilliseconds > 1500 || _executedQueries.Count > 10) { + // Only log slow operations or operations with many queries _logger.Log(logLevel, logMessage, args); } - // Log operation summary for long-running operations - if (totalTime.TotalMilliseconds > 1000 || _executedQueries.Count > 5) + // Log operation summary for long-running operations or many queries + if (totalTime.TotalMilliseconds > 1500 || _executedQueries.Count > 10) { _logger.LogWarning( "[SQL-OP-SUMMARY] {OperationId} | Parameters: {Parameters} | Query Count: {QueryCount} | Total Time: {TotalTime}ms",