| | | 1 | | using System.Data.Common; |
| | | 2 | | using System.Text.RegularExpressions; |
| | | 3 | | using Microsoft.EntityFrameworkCore.Diagnostics; |
| | | 4 | | using Serilog; |
| | | 5 | | |
| | | 6 | | namespace OzonOrdersWeb.Observability; |
| | | 7 | | |
| | 0 | 8 | | public sealed class SlowDbCommandInterceptor(int slowMilliseconds) : DbCommandInterceptor |
| | | 9 | | { |
| | | 10 | | public override DbDataReader ReaderExecuted( |
| | | 11 | | DbCommand command, |
| | | 12 | | CommandExecutedEventData eventData, |
| | | 13 | | DbDataReader result) |
| | | 14 | | { |
| | 0 | 15 | | LogIfSlow(command, eventData.Duration); |
| | 0 | 16 | | return result; |
| | | 17 | | } |
| | | 18 | | |
| | | 19 | | public override ValueTask<DbDataReader> ReaderExecutedAsync( |
| | | 20 | | DbCommand command, |
| | | 21 | | CommandExecutedEventData eventData, |
| | | 22 | | DbDataReader result, |
| | | 23 | | CancellationToken cancellationToken = default) |
| | | 24 | | { |
| | 0 | 25 | | LogIfSlow(command, eventData.Duration); |
| | 0 | 26 | | return ValueTask.FromResult(result); |
| | | 27 | | } |
| | | 28 | | |
| | | 29 | | public override int NonQueryExecuted(DbCommand command, CommandExecutedEventData eventData, int result) |
| | | 30 | | { |
| | 0 | 31 | | LogIfSlow(command, eventData.Duration); |
| | 0 | 32 | | return result; |
| | | 33 | | } |
| | | 34 | | |
| | | 35 | | public override ValueTask<int> NonQueryExecutedAsync( |
| | | 36 | | DbCommand command, |
| | | 37 | | CommandExecutedEventData eventData, |
| | | 38 | | int result, |
| | | 39 | | CancellationToken cancellationToken = default) |
| | | 40 | | { |
| | 0 | 41 | | LogIfSlow(command, eventData.Duration); |
| | 0 | 42 | | return ValueTask.FromResult(result); |
| | | 43 | | } |
| | | 44 | | |
| | | 45 | | public override object? ScalarExecuted(DbCommand command, CommandExecutedEventData eventData, object? result) |
| | | 46 | | { |
| | 0 | 47 | | LogIfSlow(command, eventData.Duration); |
| | 0 | 48 | | return result; |
| | | 49 | | } |
| | | 50 | | |
| | | 51 | | public override ValueTask<object?> ScalarExecutedAsync( |
| | | 52 | | DbCommand command, |
| | | 53 | | CommandExecutedEventData eventData, |
| | | 54 | | object? result, |
| | | 55 | | CancellationToken cancellationToken = default) |
| | | 56 | | { |
| | 0 | 57 | | LogIfSlow(command, eventData.Duration); |
| | 0 | 58 | | return ValueTask.FromResult(result); |
| | | 59 | | } |
| | | 60 | | |
| | | 61 | | public override void CommandFailed(DbCommand command, CommandErrorEventData eventData) |
| | | 62 | | { |
| | 0 | 63 | | LogFailure(command, eventData.Duration, eventData.Exception); |
| | 0 | 64 | | } |
| | | 65 | | |
| | | 66 | | public override Task CommandFailedAsync( |
| | | 67 | | DbCommand command, |
| | | 68 | | CommandErrorEventData eventData, |
| | | 69 | | CancellationToken cancellationToken = default) |
| | | 70 | | { |
| | 0 | 71 | | LogFailure(command, eventData.Duration, eventData.Exception); |
| | 0 | 72 | | return Task.CompletedTask; |
| | | 73 | | } |
| | | 74 | | |
| | | 75 | | private void LogIfSlow(DbCommand command, TimeSpan duration) |
| | | 76 | | { |
| | 0 | 77 | | if (duration.TotalMilliseconds < slowMilliseconds) |
| | | 78 | | { |
| | 0 | 79 | | return; |
| | | 80 | | } |
| | | 81 | | |
| | 0 | 82 | | Log.ForContext("EventKind", "SlowDatabaseCommand") |
| | 0 | 83 | | .ForContext("EventCategory", "database") |
| | 0 | 84 | | .ForContext("ElapsedMilliseconds", duration.TotalMilliseconds) |
| | 0 | 85 | | .ForContext("Database", command.Connection?.Database) |
| | 0 | 86 | | .ForContext("CommandType", command.CommandType) |
| | 0 | 87 | | .ForContext("CommandText", SanitizeCommand(command.CommandText)) |
| | 0 | 88 | | .Warning("Медленная команда БД выполнялась {ElapsedMilliseconds:0} мс", duration.TotalMilliseconds); |
| | 0 | 89 | | } |
| | | 90 | | |
| | | 91 | | private static void LogFailure(DbCommand command, TimeSpan duration, Exception exception) |
| | | 92 | | { |
| | 0 | 93 | | Log.ForContext("EventKind", "DatabaseCommandFailed") |
| | 0 | 94 | | .ForContext("EventCategory", "database") |
| | 0 | 95 | | .ForContext("ElapsedMilliseconds", duration.TotalMilliseconds) |
| | 0 | 96 | | .ForContext("Database", command.Connection?.Database) |
| | 0 | 97 | | .ForContext("CommandType", command.CommandType) |
| | 0 | 98 | | .ForContext("CommandText", SanitizeCommand(command.CommandText)) |
| | 0 | 99 | | .Error(exception, "Ошибка выполнения команды БД через {ElapsedMilliseconds:0} мс", duration.TotalMillisecond |
| | 0 | 100 | | } |
| | | 101 | | |
| | | 102 | | private static string SanitizeCommand(string commandText) |
| | | 103 | | { |
| | | 104 | | const int maxLength = 4_096; |
| | 0 | 105 | | var normalized = string.Join(' ', commandText.Split((char[]?)null, StringSplitOptions.RemoveEmptyEntries)); |
| | 0 | 106 | | normalized = Regex.Replace(normalized, "'(?:''|[^'])*'", "'?'", RegexOptions.CultureInvariant); |
| | 0 | 107 | | normalized = Regex.Replace(normalized, "\"(?:\"\"|[^\"])*\"", "\"?\"", RegexOptions.CultureInvariant); |
| | 0 | 108 | | return normalized.Length <= maxLength ? normalized : string.Concat(normalized.AsSpan(0, maxLength), "…"); |
| | | 109 | | } |
| | | 110 | | } |