Message vs MessageTemplate, a clean output with the replaced values of placeholders

[wilsonchenau]

I am trying to add the the support for SQL Server database logging with this sink.

Here is my use case:

• Mesasge template: "This is a test. {Id} {LogType} {MyUniqueId} {OtherColumn}"
• parameters: fooGuid, I, 1234, "Something"

And in database, the Message value ends up being:

This is a test. 34B0C81E-334B-4CD1-9CDA-F04DD49D46F6 I 1234 Something

But what I really expect is:

• The Message value to be just the original message itself "This is a test."

And the other properties will go into corresponding columns, which it's what it is doing right, that part is fine.

I have to add those placeholder properties there simply because Serilog will complain missing the properties. But adding those property placeholders there, will stuff up the final output value in the database table.

In a nutshell:

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

• Serilog: 4.0.1
• Serilog.Sinks.MSSqlServer: 6.7.0

• Configuration:

          var columnOptions = new ColumnOptions
          {
              AdditionalColumns = new Collection<SqlColumn>
              {
                   new SqlColumn
                  {
                      ColumnName = "Id",
                      DataType = SqlDbType.UniqueIdentifier,
                      AllowNull = false
                  },
                  new SqlColumn
                  {
                      ColumnName = "LogType",
                      DataType = SqlDbType.Char,
                      DataLength= 1,
                      AllowNull = false
                  },
                  new SqlColumn
                  {
                      ColumnName = "fooGuid",
                      DataType = SqlDbType.UniqueIdentifier
                  },
                  new SqlColumn
                  {
                      ColumnName = "MyUniqueId",
                      DataType = SqlDbType.Int
                  },
                  new SqlColumn
                  {
                      ColumnName = "OtherColumn",
                      DataType = SqlDbType.NVarChar,
                      DataLength = 10
                  }
              }
          };
  
          columnOptions.PrimaryKey = columnOptions.AdditionalColumns.First(x => x.ColumnName == "Id");
  
          columnOptions.Store.Remove(StandardColumn.Id);
          columnOptions.Store.Remove(StandardColumn.Level);
          columnOptions.Store.Remove(StandardColumn.MessageTemplate);
          columnOptions.Store.Remove(StandardColumn.Exception);
          columnOptions.Store.Remove(StandardColumn.Properties);

  Target framework and operating system: [x] .NET Framework 4.8 OS: Windows 11

Provide a simple reproduction of your Serilog configuration code:

var logger = new LoggerConfiguration()
.MinimumLevel
.Debug()
.WriteTo.MSSqlServer(_connectionString,
sinkOptions: new MSSqlServerSinkOptions { TableName = "Log" },
columnOptions: columnOptions,
formatProvider: CultureInfo.CurrentCulture)
.CreateLogger();

Provide a simple reproduction of your application code: logger.Information("This is a test. {Id} {LogType} {MyUniqueId} {OtherColumn}", Guid.New(), "I", 1234, "Something");

[vlm---]

It's not a sink problem, it's a core Serilog message handling. If you want to have other properties only in custom columns and not in message itself, you should put them in as a correlation:

logger.ForContext("Id", 1).ForContext("LogType","I").ForContext("MyUniqueId", Guid.New()).ForContext("OtherColumn", "Something").Information("This is a test.");`

Or you can use LogContext as described here:

using (LogContext.PushProperty("Id", 1))
using (LogContext.PushProperty("LogType", "I"))
using (LogContext.PushProperty("MyUniqueId", Guid.New()))
using (LogContext.PushProperty("OtherColumn", "Something"))
{
    logger.Information("This is a test.");
}

[ckadluba]

Exactly. Thank you @vlm--- for the sample and explanation.

[wilsonchenau]

Hi @vlm--- thanks a lot for the explanation.

I ran your 2nd sample,:

using (LogContext.PushProperty("Id", 1))
using (LogContext.PushProperty("LogType", "I"))
using (LogContext.PushProperty("MyUniqueId", Guid.New()))
using (LogContext.PushProperty("OtherColumn", "Something"))
{
    logger.Information("This is a test.");
}

and with Serilog selflog enbabled:

Serilog.Debugging.SelfLog.Enable(msg =>
{
    Debug.WriteLine(msg);
});

It now complains the "Id" column does not allow nulls.

2024-08-20T23:29:36.6296861Z Unable to write batch of 1 log events to the database due to following error: System.Data.NoNullAllowedException: Column 'Id' does not allow nulls. at System.Data.DataColumn.CheckNullable(DataRow row) at System.Data.DataTable.RaiseRowChanging(DataRowChangeEventArgs args, DataRow eRow, DataRowAction eAction, Boolean fireEvent) at System.Data.DataTable.SetNewRecordWorker(DataRow row, Int32 proposedRecord, DataRowAction action, Boolean isInMerge, Boolean suppressEnsurePropertyChanged, Int32 position, Boolean fireEvent, Exception& deferredException) at System.Data.DataTable.InsertRow(DataRow row, Int64 proposedID, Int32 pos, Boolean fireEvent) at Serilog.Sinks.MSSqlServer.Platform.SqlBulkBatchWriter.FillDataTable(IEnumerable`1 events, DataTable dataTable) at Serilog.Sinks.MSSqlServer.Platform.SqlBulkBatchWriter.d__6.MoveNext()

I think somehow the LogContext.PushProperty is not working here.

Any thoughts on this?

That said, your 1st sample using ForContext works:

logger.ForContext("Id", 1).ForContext("LogType","I").ForContext("MyUniqueId", Guid.New()).ForContext("OtherColumn", "Something").Information("This is a test.");

Thanks for the great help.

[vlm---]

As per the documentation I've linked you have to enable enriching from LogContext when creating your logger:

            var logger = new LoggerConfiguration()
                .MinimumLevel
                    .Debug()
                .WriteTo.MSSqlServer(_connectionString,
                    sinkOptions: new MSSqlServerSinkOptions { TableName = "Log" },
                    columnOptions: columnOptions,
                    formatProvider: CultureInfo.CurrentCulture)
                .Enrich.FromLogContext()
                .CreateLogger();

[wilsonchenau]

Hi, it works very well with the Enrich.FromLogContext() using your 1st example.

Thank you very much!