C#•3y ago

❔ Serilog file sink from multiple servers has interleaved messages

I have a web app deployed across 10 web servers. They are all configured as such (note, the

path

path

path

path below is a shared network path. So they are all pointing to the same log file):

  "Serilog": {
    "Using": [ "Serilog.Sinks.Console", "Serilog.Sinks.File" ],
    "MinimumLevel": "Debug",
    "WriteTo": [
      {
        "Name": "Console"
      },
      {
        "Name": "File",
        "Args": {
          "shared": true,
          "path": "logs/foo_.log",
          "rollingInterval": "Day",
          "retainedFileCountLimit": 7
        }
      }
    ],
    "Enrich": [ "FromLogContext", "WithMachineName", "WithThreadId" ]
  },

  "Serilog": {
    "Using": [ "Serilog.Sinks.Console", "Serilog.Sinks.File" ],
    "MinimumLevel": "Debug",
    "WriteTo": [
      {
        "Name": "Console"
      },
      {
        "Name": "File",
        "Args": {
          "shared": true,
          "path": "logs/foo_.log",
          "rollingInterval": "Day",
          "retainedFileCountLimit": 7
        }
      }
    ],
    "Enrich": [ "FromLogContext", "WithMachineName", "WithThreadId" ]
  },

  "Serilog": {
    "Using": [ "Serilog.Sinks.Console", "Serilog.Sinks.File" ],
    "MinimumLevel": "Debug",
    "WriteTo": [
      {
        "Name": "Console"
      },
      {
        "Name": "File",
        "Args": {
          "shared": true,
          "path": "logs/foo_.log",
          "rollingInterval": "Day",
          "retainedFileCountLimit": 7
        }
      }
    ],
    "Enrich": [ "FromLogContext", "WithMachineName", "WithThreadId" ]
  },

  "Serilog": {
    "Using": [ "Serilog.Sinks.Console", "Serilog.Sinks.File" ],
    "MinimumLevel": "Debug",
    "WriteTo": [
      {
        "Name": "Console"
      },
      {
        "Name": "File",
        "Args": {
          "shared": true,
          "path": "logs/foo_.log",
          "rollingInterval": "Day",
          "retainedFileCountLimit": 7
        }
      }
    ],
    "Enrich": [ "FromLogContext", "WithMachineName", "WithThreadId" ]
  },

However I'm noticing the log file has interleaved messages:

2023-02-28 00:03:16.105 -06:00 [DBG] Execution plan of result filters (in the following order): ["Microsoft.AspNetCore.Mvc.Infrastructure.C2023-02-28 00:03:16.054 -06:00 [INF] Requ2023-02-28 00:03:16.130 -06:00 [DBG] Execution plan of result filters (in the following order):

Notice the

[DBG]

[DBG]

[DBG]

[DBG] and

[INF]

[INF]

[INF]

[INF] log levels in the same message, and this here here specifically:

Infrastructure.C2023-02-28 00:03:16.054 -06:00 [INF] Requ2023-02-28 00:03:16.13

How can I prevent this from happening? I thought

shared: true

shared: true

shared: true

shared: true was the support Serilog needed to handle this situation?

toddlahakbar•3/1/23, 2:49 PM

So from what I can see, the SharedFileSink is only really applicable for multiple processes on the same server as it utilizes an os mutex. Are these servers on windows or Linux?

trustieOP•3/1/23, 2:50 PM

windows, app is running in IIS. the log file is at a network shared path that all apps are pointing to

toddlahakbar•3/1/23, 2:52 PM

Yeah, from everything I can see the shared functionality is implemented either by a lock or by a mutex, either of which is only going to work for multiple processes on the same box.

trustieOP•3/1/23, 2:53 PM

seems like a common use case, im pretty sure i use nlog on other apps and do the same thing without issue

trustieOP•3/1/23, 2:53 PM

i figured serilog would asynchronously try to log the message, such as building up a buffer, and then dump to the file as it is able to

toddlahakbar•3/1/23, 2:57 PM

I mean, it's kind of a common use case. At the point where you're running 10 servers logging to the same sink, I think the assumption is you're using a more mature log aggregation than a shared file

trustieOP•3/1/23, 3:01 PM

true

trustieOP•3/1/23, 3:01 PM

maybe time to switch to seq or something

Accord•3/2/23, 3:11 PM

Was this issue resolved? If so, run

/close

/close

otherwise I will mark this as stale and this post will be archived until there is new activity.