Custom Columns where the Property Name contains a dot is not populated.

[tjackadams]

Please clearly describe what the SQL Sink is doing incorrectly:

custom columns where the property name contains a dot, but isn't hierarchical doesn't seem to get populated.

Please clearly describe the expected behavior:

Even though it contains a dot, it should be able to match on the property name.

List the names and versions of all Serilog packages used in the project:

<PackageReference Include="Serilog.AspNetCore" Version="8.0.1" />
<PackageReference Include="Serilog.Enrichers.Environment" Version="3.0.0" />
<PackageReference Include="Serilog.Expressions" Version="4.0.0" />
<PackageReference Include="Serilog.Formatting.Compact" Version="3.0.0" />
<PackageReference Include="Serilog.Sinks.Async" Version="2.0.0" />
<PackageReference Include="Serilog.Sinks.MSSqlServer" Version="6.6.1" />

Target framework and operating system:

.NET 8 Windows 11

Provide a simple reproduction of your Serilog configuration code:

    builder.Host.UseSerilog((hostContext, loggerBuilder) =>
    {
        loggerBuilder
        .ReadFrom.Configuration(hostContext.Configuration);
    });

Provide a simple reproduction of your Serilog configuration file, if any:

{
  "Serilog": {
    "Using": [ "Serilog.Sinks.MSSqlServer" ],
    "WriteTo": [
      {
        "Name": "Logger",
        "Args": {
          "configureLogger": {
            "WriteTo": [
              {
                "Name": "MSSqlServer",
                "Args": {
                  "columnOptionsSection": {
                    "addStandardColumns": [ "LogEvent", "TraceId", "SpanId" ],
                    "removeStandardColumns": [ "MessageTemplate", "Properties" ],
                    "customColumns": [
                      {
                        "columnName": "RequestId",
                        "dataType": "varchar",
                        "dataLength": 128
                      },
                      {
                        "columnName": "Method",
                        "PropertyName": "http.request.method",
                        "dataType": "nvarchar"
                      },
                      {
                        "columnName": "Path",
                        "PropertyName": "url.path",
                        "dataType": "nvarchar"
                      },
                      {
                        "columnName": "StatusCode",
                        "PropertyName": "http.response.status_code",
                        "dataType": "int"
                      },
                      {
                        "columnName": "RequestBody",
                        "dataType": "nvarchar"
                      },
                      {
                        "columnName": "ResponseBody",
                        "dataType": "nvarchar"
                      }
                    ],
                    "id": {
                      "columnName": "LogId",
                      "dataType": "bigint",
                      "nonClusteredIndex": false
                    },
                    "level": {
                      "columnName": "Level",
                      "storeAsEnum": false
                    },
                    "timeStamp": {
                      "columnName": "Timestamp",
                      "convertToUtc": false
                    },
                    "logEvent": {
                      "columnName": "LogEvent"
                    }
                  },
                  "connectionString": "Local",
                  "sinkOptionsSection": {
                    "tableName": "HttpClientLog",
                    "autoCreateSqlDatabase": true,
                    "autoCreateSqlTable":  true
                  },
                  "formatProvider": "System.Globalization.CultureInfo::CurrentCulture",
                  "restrictedToMinimumLevel": "Information"
                }
              }
            ],
            "Filter": [
              {
                "Name": "ByIncludingOnly",
                "Args": {
                  "expression": "SourceContext = 'Microsoft.Extensions.Http.Logging.HttpClientLogger'"
                }
              }
            ]
          }
        }
      }
    ]
  }
}

Provide a simple reproduction of your application code:

https://github.com/tjackadams/serilog-mssql-dot-property-name-repro

It uses the local db that comes with visual studio. When you run it, call posts/5 via swagger and it logs the request in the database. The Method, Path and StatusCode columns will all be null, even though they are supplied as a property. The properties are populated by the Microsoft.Extensions.Http.Diagnostics nuget package and AddExtendedHttpClientLogging call in program.

This is a LogEvent from that call

{
   "Timestamp":"2024-06-11T15:40:36.8575483",
   "Level":"Information",
   "Message":"GET jsonplaceholder.typicode.com//posts/5",
   "Properties":{
      "LatencyInfo":",",
      "http.request.method":"GET",
      "server.address":"jsonplaceholder.typicode.com",
      "url.path":"/posts/5",
      "Duration":519,
      "http.response.status_code":200,
      "RequestBody":"",
      "ResponseBody":"{\n  \"userId\": 1,\n  \"id\": 5,\n  \"title\": \"nesciunt quas odio\",\n  \"body\": \"repudiandae veniam quaerat sunt sed\\nalias aut fugiat sit autem sed est\\nvoluptatem omnis possimus esse voluptatibus quis\\nest aut tenetur dolor neque\"\n}",
      "LoggerMessageState":"GET jsonplaceholder.typicode.com//posts/5",
      "EventId":{
         "Id":1,
         "Name":"OutgoingRequest"
      },
      "SourceContext":"Microsoft.Extensions.Http.Logging.HttpClientLogger",
      "RequestId":"0HN4A4HNQNRGV:00000001",
      "RequestPath":"/posts/5",
      "ConnectionId":"0HN4A4HNQNRGV",
      "MachineName":"DESKTOP-KAHG7M1"
   },
   "Renderings":{
      "LoggerMessageState":[
         {
            "Format":"l",
            "Rendering":"GET jsonplaceholder.typicode.com//posts/5"
         }
      ]
   }
}

The http.request.method value does not populate the Method column - same with url.path and http.response.status_code. However, other properties such as RequestBody and ResponseBody which also come from the Microsoft.Extensions.Http.Diagnostics nuget package are populated ok.

[cancakar35]

I do some debugging about this issue. This method treats every property with dot character in name is hierarchical. https://github.com/serilog-mssql/serilog-sinks-mssqlserver/blob/d1c4f2180954f55546f42b5b97491d01a2a4708c/src/Serilog.Sinks.MSSqlServer/Sinks/MSSqlServer/SqlColumn.cs#L173

[ckadluba]

@cancakar35 I really appreciate your engangement and help in analyzing and fixing bugs. Thank you very much for analyzing this.

I remember when we added the hierarchical properties resolving to move a step towards structured logging. Now, maybe we should define an escape character (e.g. \) so that the dot in

{Nonhierarchical\.PropertyName}

will be ignored and the expression will not be treated as a hierarchical property specifier but rather as a single property name.

But this would possibly clash with any string escaping done in Serilog or if the caller uses C# format strings or string interpolation to generate the message (which is an antipattern anyway).

Another possibly would be to add a sink option to disable hierarchical property resolution altogerther.

Let me do some tests to see if we can implement an eacape character.

[ckadluba]

I thought about this issue. Having properties with dots really clashes with the way the MSSQL sink fundamentally handles properites for structured logging. And I'm afraid if we implement a way of escaping the dot within property names, this could have negative side effects on other code in Serilog which reads and interprets the message template.

Therefore I would put it up for discussion, if we should implement a sink option to disable hierarchical properties in the MSSQL sink as it was implemented for enhancement https://github.com/serilog-mssql/serilog-sinks-mssqlserver/issues/207. This way the scenario described in this issue would work since the property names containing dots would not be interpreted in any way but. In other words, property- and column names could contain dots. Consequently no processing of hierarchical properties would be done then.

@tjackadams @cancakar35 what do you think about that?

[cancakar35]

Having an option to disable hierarchical properties would be good. But if you think this will cause any other issues, we dont have to implement as this kind of scenarios are rare.

[ckadluba]

@tjackadams We would be able to add a solution for your problem to the sink but first, could you please give us more context about the use case? How do you get log event non structured log event properties with dots in their names into your log context? Can you maybe share a complete sample or describe why this is happening? Does HttpClientLogger do this?

[ckadluba]

In PR #599 we added an option to disable the hierarchical resolution per column which fixes the problem described in this issue. Preview version 8.1.0-dev-00116 was pushed to nuget.org (https://www.nuget.org/packages/Serilog.Sinks.MSSqlServer/8.1.0-dev-00116) and I would be very thankful to anyone who could give it a spin and let us know of any problems.

[tjackadams]

@tjackadams We would be able to add a solution for your problem to the sink but first, could you please give us more context about the use case? How do you get log event non structured log event properties with dots in their names into your log context? Can you maybe share a complete sample or describe why this is happening? Does HttpClientLogger do this?

The use case was to store http request and responses into a database using the logging framework that was already available to us. The Microsoft.Extensions.Http.Diagnostics provides the ability to log the request and response as a single log entry - This package also adds the logging properties to the log context, but how that happens in practice I'm unsure of. As we have quite a lot of http requests happening we wanted to split some of the properties off into separate columns, such as the http method, path and status code. These 3 properties are populated by the Microsoft.Extensions.Http.Diagnostics package and contain a dot in their names http.request.method, url.path, http.response.status_code. As they are coming from a Microsoft package, we have no control over what name they end up with in the log context.

I'm not sure if the allowed names are standardised in anyway - Looking through the open telemetry spec it would seem to suggest that a dot in the property is allowed.

So I would say your suggestion of disabling hierarchical resolution per column sounds like a good solution. I'll try and update the package in a project where we saw the issue and report back any issues.

Happy for this issue to be closed and thank you for taking the time to have a look/provide a fix!