Serilog not filling custom column, and no error in selflog.

[LouisMach]

Bug Report / Support Request Template

Please clearly describe what the SQL Sink is doing incorrectly:

I have set up database logging which works, but my custom column is always null even though the property exists and I have added a mapping for the column. SelfLog to console and debug is enabled, but no error shows up. I can trigger a visible selflog by setting an invalid connection string, so I think selflogging is working correctly.

Please clearly describe the expected behavior:

I expect Serilog to fill the column with the value of the property when the property matches the mapping. I also expect Serilog to emit an error on selflog when an error prevents writing to the column.

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

• Serilog: 3.1.1 (also occurred on 3.0.1)
• Serilog.Sinks.MSSqlServer: 6.6.0
• Serilog.Extensions.Hosting 7.0.0
• Serilog.Extensions.Logging 7.0.0
• Serilog.Extensions.Logging.File 3.0.0
• Serilog.Sinks.Console 5.0.1
• Serilog.Sinks.File 5.0.0

Target framework and operating system:

.NET 7.0 OS: Windows 10

Provide a simple reproduction of your Serilog configuration code:

https://gist.github.com/LouisMach/a6c41f017dcb2fcf3d7e2ea79d880c82#file-program-cs

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

None, set in code.

Provide a simple reproduction of your application code:

Code: https://gist.github.com/LouisMach/a6c41f017dcb2fcf3d7e2ea79d880c82#file-service-cs SQL script: https://gist.github.com/LouisMach/a6c41f017dcb2fcf3d7e2ea79d880c82#file-tbllog-sql

The property is correctly added to the properties and scope part of the log entry, this is the content of the property column:

<properties>
    <property key='SourceContext'>MyProject.Services.x.Service</property>
    <property key='AssetNumber'>123</property>
    <property key='ActionId'>643b5dd4-1147-4c4b-aacf-e3f6766cbeac</property>
    <property key='ActionName'>MyProject.Controllers.x.Controller.Sync (projname)</property>
    <property key='RequestId'>redacted</property>
    <property key='RequestPath'>/api/v1/project/sync</property>
    <property key='ConnectionId'>redacted</property>
    <property key='Scope'>
        <sequence>
            <item>Asset Number: 123</item>
        </sequence>
    </property>
</properties>

If I set the wrong connection string, I get the following error in Console and Debug Output: 2024-04-30T08:11:32.8056928Z Unable to write batch of 1 log events to the database due to following error: Microsoft.Data.SqlClient.SqlException (0x80131904): A network-related or instance-specific error occurred while establishing a connection to SQL Server. The server was not found or was not accessible. Verify that the instance name is correct and that SQL Server is configured to allow remote connections. (provider: Named Pipes Provider, error: 40 - Could not open a connection to SQL Server) So it seems that errors from Serilog are being written, so I would expect error output when Serilog is unable to write to the column.

[LouisMach]

I also opened this stackoverflow thread for it: https://stackoverflow.com/questions/78408990/serilog-sql-server-sink-not-filling-custom-column-and-no-error-in-selflog

[ckadluba]

Hi @LouisMach!

Thank you for getting in touch. From a first look at your sample program, I could not see anything that looks obviously wrong. So I will try and debug it once I have some time for it.

I compared your sample to our samples/WorkerServiceDemo where we also use a custom column (AdditionalColumn1) and everything related to the custom column looks similar except that our sample has different names for the column and the property while yours does not. But that is probably not the cause.

Investigation continues.

[LouisMach]

Hi @ckadluba, thank you very much for your answer. I'm glad to hear you are investigating, I'd love to get this to work. I tried to include all relevant code in the samples but I could not share the whole project since it's proprietary. If you have any issues with reproducing this I will try to create a full sample app to reproduce the problem.

[ckadluba]

I have tried to get your code to compile but it seems to be incomplete (e.g. builder is used but not defined in Program.cs). So, can you please put together a simple but full sample project which I can use? That would be great.

P.S.: I modified our WorkerServiceDemo to test and rule out if the problem is caused by setting the column and property names differently, like in your sample. And as I assumed, this did not cause any trouble.

[pkokay]

Hi, I had this same problem and traced it back to the version of Serilog.Sinks.MSSqlServer. Upgrading from 6.3.0 to 6.4.0 seemed to silently break the logging we had in place for a couple of parameters, specifically for an int we had been logging as nvarchar for whatever reason and an enum we were also logging as nvarchar. Logging for a string parameter was unaffected.

We were able to get the logging to work by handling the conversion to string ourselves before passing the value, e.g. in 6.4.0 and later versions both of these work: logger.LogError("Step{RequestStep}: Error in workflow operation {Isin}", "_01_Start", context.Message.Isin);

using (logger.BeginScope("Asset Number: {WorkflowId}", "1234"))
 {
     logger.LogError("Error in workflow operation {Isin}", context.Message.Isin);
 }

but these don't: logger.LogError("Step{RequestStep}: Error in workflow operation {Isin}", MasterDataProcessStep._01_Start, context.Message.Isin);

using (logger.BeginScope("Asset Number: {WorkflowId}", 1234))
 {
     logger.LogError("Error in workflow operation {Isin}", context.Message.Isin);
 }

Since you handle the string conversion yourself, I am not sure why it is still broken for you. However, downgrading to Serilog.Sinks.MSSqlServer version 6.3.0 might help.

[IzaacJ]

I have a similar issue in my project. The properties are set correctly but not populated into the custom columns.

Serilog: 4.0.2-dev-02220 Serilog.Sinks.MSSqlServer: 6.7.2-dev-00087

[ckadluba]

@pkokay @IzaacJ can you please provide a complete sample app to demo your issues?

[ckadluba]

I just tested basic logging of numeric custom properties into additional columns based on the included WorkerServiceDemo app.

Here is logging code. I added line 34.

Here is the config of the column.

This works as expected with the current version of the MSSQL sink (same result when using the audit mode of the sink).

Without a sample to reproduce your problem I cannot further investigate this. I'm closing this issue. If you still have the problem you can open a new one.