DurableHttpUsingFileSizeRolledBuffers - interval flush period doubts

[sheltertake]

Hi @FantasticFiasco ,

Last friday I start playing with this sink. I want to replace the way I log now applications (terrible). So I'm studying a bit.
From what I understood... but everything I write here can be wrong by my limited experience on serilog and elk.

• Http sink is not usable directly to send logs to logstash. Event arrive broken (es: {"events":[{"Timestamp":"2021-01-23T10:47:12.8307313+01:00","Level":"Information","MessageTemplate":"Log information","RenderedMessage":"Log information","Properties":{"SourceContext":"ConsoleAppSerilogElk.Program"}}). I tried every single Formatter, also the ElasticSearch one of another sink.

console application very similar of your sample

• Using instead DurableHttpUsingFileSizeRolledBuffers + ArrayBatchFormatter option and using the json codec on logstash configuration, events arrive on elk in the right format

api setup
api recipe

• Then I tried to understand if this sink "scale". I setup a benchmark. What I noticed is strange.

repo

Benchmark results are not the problem. The wrk setup could be too much aggressive and I didn't setup a warmup phase and most of all, the benchmark is not honest because the serilog-elk scenario have an elk cluster up and running on my poor laptop in concurrency with same resources. The other ones not.

The problem is the scenario produce in 20s from 70k to 100k events. And these events arrive to elk very very slowly.
2 minutes between each packet. I tried playing with "period:" option but nothing change. I tried to raise batchPostingLimit: to 10000. I collected in this way 40k events in 6-8 minutes after benchmark finish.

It's a behavior explainable? Is a sort of exponential retry alghoritm of serilog that feels api very stressed and schedule logs flush with interval very lazy? switching off api cause flush but it seems "one" packet more sent. Not all it has on the file.

Thank you for any kind of attention you want to give to this post.
I tried to write it down as best as I can.

Max

[FantasticFiasco]

Hi @sheltertake and welcome to the repo!

I would like to propose that we break down you questions. I'll try to answer them one at a time, and when we both feel the question is answered we'll proceed with the next question in your post, all the way down to your final question. Would that be alright with you?

• Http sink is not usable directly to send logs to logstash. Event arrive broken (es: {"events":[{"Timestamp":"2021-01-23T10:47:12.8307313+01:00","Level":"Information","MessageTemplate":"Log information","RenderedMessage":"Log information","Properties":{"SourceContext":"ConsoleAppSerilogElk.Program"}}). I tried every single Formatter, also the ElasticSearch one of another sink.

console application very similar of your sample

Let's start with this question, shall we?

What do you mean when you say that "the events arrive broken"? Let me start by building the foundation for our discussion. When you write a log event using Serilog, what will happen is that Serilog will pass that event to this sink. This sink will then proceed to serialize the CLR log event to a textual representation using a ITextFormatter and store it, in your case, on disk in a buffer file. The log event has at this point never left the application. Then, at given intervalls, this sink is checking if new log event have been written to the buffer file, and if the sink finds that they have, it reads these events and formats them into a payload using a batch formatter. The sink is by default using the DefaultBatchFormatter, but if you would like to send the log events to Logstash you are better off using the ArrayBatchFormatter.

{"events":[{"Timestamp":"2...

Looking at your sample code it seems like you are using the ArrayBatchFormatter, but the quote above from your post looks like it was created using the DefaultBatchFormatter. Which batch formatter are you using?

Let's summarize this, my two initial questions are:

1. What do you mean when you say that the "events arrive broken"?
2. Are you using the DefaultBatchFormatter or the ArrayBatchFormatter? You say that the payload looks like this: {"events":[{"Ti..., but that payload is produced by DefaultBatchFormatter and not by ArrayBatchFormatter as stated in your code.

[sheltertake]

Hi @FantasticFiasco

thank you for the effort on answer me and on explanation.
I started from scratch.

The first issue is explained here:
https://github.com/sheltertake/serilog-http-playground

• On logstash configuration I removed json codec setting.
• The serilog configuration is via code.

In this first implementation I use Http sink with batchFormatter: new Serilog.Sinks.Http.BatchFormatters.ArrayBatchFormatter().

The log entry contain this text message property (un-escaped by me):
,{"Timestamp":"2021-01-25T12:28:06.1609791+01:00","Level":"Information","MessageTemplate":"Get","RenderedMessage":"Get","Properties":{"SourceContext":"FooApi.Controllers.WeatherForecastController","ActionId":"c11badc3-5c00-4b8f-bd03-894f4a677c69","ActionName":"FooApi.Controllers.WeatherForecastController.Get (FooApi)","RequestId":"0HM614H4FNOIE:00000002","RequestPath":"/weatherforecast","ConnectionId":"0HM614H4FNOIE"}}

There's something wrong I think (on dotnet side or on my elk configuration).

Max

[FantasticFiasco]

On logstash configuration I removed json codec setting.

This is your problem. If you remove the codec Logstash assumes you send log events in a textual representation. But you don't. You send each log event as a complete and valid JSON document. Thus you cannot remove the configuration and expect it to behave the same. Here's the configuration in my ELK sample.

Please let me know if this part is resolved and we should continue with the next of your questions.

[sheltertake]

Hi @FantasticFiasco,

I fixed the logstash configuration (http instead of tcp + logstash http plugin).
Now run like clockwork!

Using Http sink (I configured it via appsettings) all logs arrive to elk.

Thank you very much.

Max

PS: I'd like to continue experimenting, work permitting, by I'm stuck for this mess

[FantasticFiasco]

I feel your pain, that seems to be a mess.

Please let me know when you've got the bandwidth to continue. And keep up the spirit of experimentation!