Postgresql improvements (#76)

* fix PostgresDapper.ExecuteRawSqlAsync * fix logging escaping + postgres logging --------- Co-authored-by: Станислав Терещенков <tereschenkov.s@ati.su>
atidev · Mar 21, 2024 · c6e2719 · c6e2719
1 parent 0f48984
commit c6e2719
Show file tree

Hide file tree

Showing 5 changed files with 52 additions and 67 deletions.
diff --git a/ATI.Services.Common/Logging/LoggerExtension.cs b/ATI.Services.Common/Logging/LoggerExtension.cs
@@ -1,5 +1,6 @@
 using System;
 using System.Collections.Generic;
+using System.Text.Json;
 using ATI.Services.Common.Serializers;
 using ATI.Services.Common.Serializers.SystemTextJsonSerialization;
 using JetBrains.Annotations;
@@ -11,9 +12,6 @@ namespace ATI.Services.Common.Logging;
 [PublicAPI]
 public static class LoggerExtension
 {
-    private static ISerializer _serializer =
-        new SystemTextJsonSerializer(SystemTextJsonCustomOptions.IgnoreUserSensitiveDataOptions);
-
     public static void ErrorWithObject(this ILogger logger, Exception ex, string message,
         params object[] logObjects)
     {
@@ -58,7 +56,7 @@ public static void WarnWithObject(this ILogger logger, Exception ex, params obje
 
             var json = "";
             if (logObjects != null && logObjects.Length != 0)
-                json = _serializer.Serialize(logObjects);
+                json = JsonSerializer.Serialize(logObjects, SystemTextJsonCustomOptions.IgnoreUserSensitiveDataOptions);
 
 
             var eventInfo = new LogEventInfo(logLevel, logger.Name,

diff --git a/...mon/Logging/UserSensetiveDataAttribute.cs → ...mon/Logging/UserSensitiveDataAttribute.cs b/...mon/Logging/UserSensetiveDataAttribute.cs → ...mon/Logging/UserSensitiveDataAttribute.cs
diff --git a/ATI.Services.Common/Metrics/MetricsTimer.cs b/ATI.Services.Common/Metrics/MetricsTimer.cs
@@ -1,6 +1,7 @@
 using System;
 using System.Collections.Generic;
 using System.Diagnostics;
+using System.Text.Json;
 using ATI.Services.Common.Logging;
 using ATI.Services.Common.Serializers;
 using ATI.Services.Common.Serializers.SystemTextJsonSerialization;
@@ -18,7 +19,6 @@ public class MetricsTimer : IDisposable
     private readonly TimeSpan? _longRequestTime;
     private readonly object _context;
     private readonly LogSource? _logSource;
-    private readonly ISerializer _serializer;
 
     /// <summary>
     /// Конструктор таймера метрик, который считает только метрику (время выполнения + счётчик) для прометеуса
@@ -43,8 +43,6 @@ public class MetricsTimer : IDisposable
         _longRequestTime = longRequestTime;
         _context = context;
         _logSource = logSource;
-        _serializer = SerializerFactory.GetSerializerByType(SerializerType.SystemTextJson);
-        _serializer.SetSerializeSettings(SystemTextJsonCustomOptions.IgnoreUserSensitiveDataOptions);
     }
 
     public void Restart()
@@ -88,14 +86,14 @@ public void Dispose()
 
     private Dictionary<object, object> GetContext()
     {
-        var metricString = _serializer.Serialize(
+        var metricString = JsonSerializer.Serialize(
             new
             {
                 LogSource = _logSource,
                 RequestTime = _stopwatch.Elapsed,
                 Labels = _summaryLabels,
                 Context = _context
-            });
+            }, SystemTextJsonCustomOptions.IgnoreUserSensitiveDataOptions);
 
         return new Dictionary<object, object>
         {

diff --git a/ATI.Services.Common/Serializers/SystemTextJsonSerialization/SystemTextJsonCustomOptions.cs b/ATI.Services.Common/Serializers/SystemTextJsonSerialization/SystemTextJsonCustomOptions.cs
@@ -1,17 +1,21 @@
-using System.Text.Json;
+using System.Text.Encodings.Web;
+using System.Text.Json;
 using System.Text.Json.Serialization.Metadata;
 using ATI.Services.Common.Logging;
 
 namespace ATI.Services.Common.Serializers.SystemTextJsonSerialization;
 
 public static class SystemTextJsonCustomOptions
 {
-    public static readonly JsonSerializerOptions IgnoreUserSensitiveDataOptions = new JsonSerializerOptions
+    public static readonly JsonSerializerOptions IgnoreUserSensitiveDataOptions = new()
     {
         TypeInfoResolver = new DefaultJsonTypeInfoResolver
         {
             Modifiers = { IgnoreUserSensitiveData }
-        }
+        },
+        // https://learn.microsoft.com/en-us/dotnet/standard/serialization/system-text-json/character-encoding#serialize-all-characters
+        // dont escape html-tags, cyrillic 
+        Encoder = JavaScriptEncoder.UnsafeRelaxedJsonEscaping
     };
 
     private static void IgnoreUserSensitiveData(JsonTypeInfo typeInfo)

diff --git a/ATI.Services.Common/Sql/PostgresDapper.cs b/ATI.Services.Common/Sql/PostgresDapper.cs
@@ -9,7 +9,6 @@
 using ATI.Services.Common.Metrics;
 using Dapper;
 using JetBrains.Annotations;
-using Newtonsoft.Json;
 using NLog;
 using Npgsql;
 
@@ -477,38 +476,47 @@ public PostgresDapper(DataBaseOptions options)
 
     public async Task<OperationResult<List<T>>> ExecuteRawSqlAsync<T>(
         string sql,
+        string queryName,
         DynamicParameters parameters,
         string metricEntity,
         bool receiveNotice = false,
         TimeSpan? longTimeRequest = null, 
         int? timeoutInSeconds = null)
     {
-        using var _ = _metricsFactory.CreateMetricsTimerWithLogging(
-            metricEntity,
-            sql,
-            new { Action = sql, Parameters = parameters },
-            longTimeRequest,
-            FullMetricTypeLabel);
+        try
+        {
+            using var _ = _metricsFactory.CreateMetricsTimerWithLogging(
+                metricEntity,
+                queryName,
+                new { Action = queryName, Parameters = parameters },
+                longTimeRequest,
+                FullMetricTypeLabel);
 
-        var timeout = timeoutInSeconds ?? _options.Timeout.Seconds;
-        await using var connection = new NpgsqlConnection(_options.ConnectionString);
+            var timeout = timeoutInSeconds ?? _options.Timeout.Seconds;
+            await using var connection = new NpgsqlConnection(_options.ConnectionString);
 
-        if (receiveNotice)
-            connection.Notice += LoggOnNotice;
+            if (receiveNotice)
+                connection.Notice += LoggOnNotice;
 
-        var result = await ExecuteTaskWithMetrics(
-            connection.QueryAsync<T>(
-                sql,
-                parameters,
-                commandTimeout: timeout),
-            _metricsFactory.CreateMetricsTimerWithLogging(
-                metricEntity,
-                sql,
-                new { Action = sql, Parameters = parameters },
-                longTimeRequest,
-                QueryMetricTypeLabel));
+            var result = await ExecuteTaskWithMetrics(
+                connection.QueryAsync<T>(
+                    sql,
+                    parameters,
+                    commandTimeout: timeout),
+                _metricsFactory.CreateMetricsTimerWithLogging(
+                    metricEntity,
+                    queryName,
+                    new { Action = queryName, Parameters = parameters },
+                    longTimeRequest,
+                    QueryMetricTypeLabel));
 
-        return new OperationResult<List<T>>(result.AsList());
+            return new OperationResult<List<T>>(result.AsList());
+        }
+        catch (Exception e)
+        {
+            LogWithParameters(e, queryName, metricEntity, parameters);
+            return new OperationResult<List<T>>(e);
+        }
     }
 
     private string GetFunctionQuery(DynamicParameters @params, string functionName)
@@ -538,52 +546,29 @@ private int GetTimeOut(string procedureName)
     private void LogWithParameters(Exception e, string procedureName, string metricEntity, DynamicParameters parameters)
     {
         var parametersWithValues = GetProcedureParametersWithValues(parameters);
-        //С большой вероятностью лог может быть discarded на стороне logstash, если будет слишком много записей
-        if (parametersWithValues != null && parametersWithValues.Count <= 20)
-        {
-            _logger.ErrorWithObject(e,
-                new { procedureName, parameters = GetProcedureParametersWithValues(parameters), metricEntity });
-        }
-        else
-        {
-            _logger.ErrorWithObject(e, new { procedureName, metricEntity });
-        }
+        _logger.ErrorWithObject(e, new { procedureName, parameters = parametersWithValues, metricEntity });
     }
 
-    private Dictionary<string, string> GetProcedureParametersWithValues(DynamicParameters parameters)
+    private static Dictionary<string, object> GetProcedureParametersWithValues(DynamicParameters parameters)
     {
         if (parameters == null || parameters.ParameterNames == null || !parameters.ParameterNames.Any())
             return null;
 
-        var paramsArray = new Dictionary<string, string>(parameters.ParameterNames.Count());
+        var paramsArray = new Dictionary<string, object>(parameters.ParameterNames.Count());
 
         foreach (var name in parameters.ParameterNames)
         {
             var pValue = parameters.Get<dynamic>(name);
-            // Для итераторов-оберток над табличным типом udt_ невозможно просто так получить значения для логирования, поэтому вытаскиваем их через рефлексию
-            // В pValue хранится приватное поле data, в котором лежит наш TableWrapper
-            // В TableWrapper лежат приватные поля - _sqlDataRecord , IEnumerable<T> _{name}, возможны и другие приватные структуры, если мы объявим их в нашем TableWrapper
-            // Берем все, кроме _sqlDataRecord
-            if (pValue is SqlMapper.ICustomQueryParameter tableWrapperParameter)
+            if (pValue is SqlMapper.ICustomQueryParameter customParameter)
             {
                 try
                 {
-                    var dataProperty = tableWrapperParameter.GetType()
-                        .GetFields(BindingFlags.NonPublic | BindingFlags.Instance).First(p => p.Name == "data");
-
-                    var dataPropertyValue = dataProperty.GetValue(tableWrapperParameter);
-
-                    var tableWrapperProperties = dataPropertyValue.GetType()
-                        .GetFields(BindingFlags.NonPublic | BindingFlags.Instance)
-                        .Where(p => p.Name != "_sqlDataRecord").ToList();
-
-                    var resultValue = string.Join(',',
-                        tableWrapperProperties.Select(pr =>
-                            JsonConvert.SerializeObject(pr.GetValue(dataPropertyValue))
-                        )
-                    );
+                    var dataProperty = customParameter.GetType()
+                        .GetFields(BindingFlags.NonPublic | BindingFlags.Instance).First(p => p.Name == "_value");
+
+                    var dataPropertyValue = dataProperty.GetValue(customParameter);
 
-                    paramsArray.Add(name, resultValue);
+                    paramsArray.Add(name, dataPropertyValue);
                 }
                 catch (Exception ex)
                 {