Search code examples
kibananlogfilebeat

Why do I get partial log message in Kibana from NLog FileTarget?


I am using NLog FileTarget to log messages in a file, which gets picked up by a filebeat to send to Kibana.

My messages are often multiline.

I have noticed that some messages show up clipped in Kibana, with only some of the lines on the multiline message.

For example, in the logfie I have something like this

2020-05-04 16:23:16.1523|::1|80000037-0000-fb00-b63f-84710c7967bb
    2020-05-04 16:23:16.1523|::1|80000037-0000-fb00-b63f-84710c7967bb||INFO|Microsoft.AspNetCore.Hosting.Diagnostics|Request starting HTTP/2.0 GET https://localhost:44328/Foo   
    2020-05-04 16:23:16.2287|::1|80000037-0000-fb00-b63f-84710c7967bb|user1|DEBUG|MyApp.Web.Controllers.FooController|Validation OK
    2020-05-04 16:23:16.2530|::1|80000037-0000-fb00-b63f-84710c7967bb|user1|DEBUG|MyApp.Web.BusinessLogic.FooLogic|Query results time:3ms 
    2020-05-04 16:23:16.2687|::1|80000037-0000-fb00-b63f-84710c7967bb|user1|DEBUG|MyApp.Web.BusinessLogic.FooLogic|Count:0 time:1ms 
    2020-05-04 16:23:16.6127|::1|80000037-0000-fb00-b63f-84710c7967bb|user1|INFO|Microsoft.AspNetCore.Hosting.Diagnostics|Request finished in 459.4438ms 200 text/html; charset=utf-8 

but in kibana I only see

2020-05-04 16:23:16.1523|::1|80000037-0000-fb00-b63f-84710c7967bb
    2020-05-04 16:23:16.1523|::1|80000037-0000-fb00-b63f-84710c7967bb||INFO|Microsoft.AspNetCore.Hosting.Diagnostics|Request starting HTTP/2.0 GET https://localhost:44328/Foo   
    2020-05-04 16:23:16.2287|::1|80000037-0000-fb00-b63f-84710c7967bb|user1|DEBUG|MyApp.Web.Controllers.FooController|Validation OK
    2020-05-04 16:23:16.2530|::1|80000037-0000-fb00-b63f-84710c7967bb|user1|DEBUG|MyApp.Web.BusinessLogic.FooLogic|Query results time:3ms 

Note that this only happens for some messages, not all, and the size of the log message does not seem to matter. I have had quite long messages logged whole, while smaller ones were cropped.

The only reason I can think of is that the message is not written in one go, but in parts, and kibana picks up the partial message and ignores the rest. Is this the case? If so, can I configure the target to write the message all at once?

My stack is:

  • .NET Core 3.1
  • C#
  • NLog 4.7.0
  • NLog.Web.AspNetCore 4.9.2

and my file target configuration looks like this:

"target": {
  "type": "File",
  "fileName": "c:\\wwwlogs\\MyApp.Web\\Combined.log",
  "archiveFileName": "c:\\wwwlogs\\MyApp.Web\\archives\\Combined.{#}.log",
  "archiveEvery": "Day",
  "archiveNumbering": "Rolling",
  "maxArchiveFiles": "7",
  "layout": "${longdate}|${aspnet-request-ip}|${aspnet-TraceIdentifier}|${aspnet-user-identity}|${uppercase:${level}}|${logger}|${message} ${exception:format=tostring}"
}

FileBeat configuration is:

- type: log
  enabled: true
  paths:
    - C:\wwwlogs\MyApp.Web\Combined.log
  multiline.pattern: '^[[:space:]]'
  multiline.negate: false
  multiline.match: after

Solution

  • Embarassing, but turns out that this is a non issue. The entire message was being picked up by filebeat, but was only partially displayed on the Kibana index view. If the message details are clicked, the entire message is visible.

    So, no problem with NLog and filebeat, it's a view issue in Kibana