Problem statement
Recently I had to send a sizeable amount of logs into our log pipeline, a whole 23781261 log lines to be exact. Our log pipeline is the standard ELK stack, plus Filebeat, a lightweight log shipper from Elastic that forwards logs from the central log server into Logstash.
Here’s a diagram to illustrate the entire flow of logs in our system:
Nodes -> Syslog-NG -> Central logserver
Filebeat -> Logstash -> Elasticsearch
Pushing this number of logs with pretty much standard configurations of Filebeat and ELK completely saturated disk IO on the server running Elasticsearch (this node is using spinning disks so not that difficult of a feat to achieve). Additionally, Logstash would often end up failing to publish logs into Elasticsearch as a result of Elasticsearch being slow to acknowledge received events. This was no way to proceed, so I started looking at options to throttle the pipeline, or in other words, I was happy to sacrifice the total time it would take to process these logs for a reduced load on the disk drives - I wanted some of that IO for other tasks.
Throttle before the bottleneck
Naturally, throttling is best done at the point preceding the bottleneck. When done correctly, this should at least reduce the contention of the bottleneck or make it disappear completely. The bottleneck in our case was Elasticsearch, the heaviest consumer of disk IO on the node, so I started looking for ways to slow down the rate at which Logstasn sends events into ES. (Well OK, the bottleneck are the disks, but we’re stuck with what we’ve got).
A quick look at Longstash documentation yields the throttle filter plugin, which sounds exactly like what I needed. However I wasn’t able to achieve a good configuration that actually worked, for the most part it seemed that the filter wasn’t working at all. This was more than likely my misunderstanding of the documentation, but either way, I set out to look for alternative options, this approach failing the simplicity test.
Throttle at the bottleneck
ES also has some options for reducing disk IO, either at a cost of
either increased RAM usage or a delay in new events appearing in search
results, both of which I was happy to accept. One parameter recommended
by the official documentation and countless optimise ES indexing blog
posts all over the shallow and deep webs, is
index.merge.scheduler.max_thread_count,
which apparently should be set to 1 for systems with spinning disks.
Great, thats us! Unfortunately this either made zero difference or not
enough difference, we were still saturated on disk IO, so the time spent
figuring out how to import a template into ES to change a dynamic
setting (someone please explain to me why dymanic settings even exist?)
was a waste as well.
Next I experimented with available transaction
log
settings, index.translog.flush_threshold_size and
index.translog.durability options specifically, again both are dynamic
and can’t be set in the configuration file, but these too didn’t make
any noticeable difference and our disks stayed at 100% saturation.
And the same for disabling the index refresh completely via the index.refresh_interval option.
OK, time to reflect on progress - I failed to get either Logstash or ES to become at least a bit more reasonable about the rate of work they were doing and had to look further, at Filebeat.
Tool that does one job well to the rescue
Filebeat is actually one of my favourite tools from the entire Elastic product family - it seems like they (Elastic.co), finally wrote a tool that only does one thing and does it well, take logs and ship them to a receiver. This resulted in a dramatic reduction in complexity of the end product, which in turn meant that complete documentation consisted of a handful of pages that were simple to understand and didn’t need someone writing a book about it.
So I set out reading through the docs, and let me quickly say that
they’re rather good quality, not exactly at the supreme excellence of
the BSD
Unices, but certainly consise and clear enough, and it didn’t take long
at all to come accross the harvester_limit option in prospector
configuration
section. harvester_limit sets the number of files that Filebeat will
process and ship at once. The default configuration is 0, that’s a
zero, so Filebeat will ship things as fast as it can (doesn’t exactly
seem like a sane default, but that’s just my opinion). Anyway, I
limited the number of harvesters to 3 for a test and the results were
astounding - there’s no more disk IO saturation and we can do other
useful work on the node! Pause for an applause.
In the end, this option, together with a fairly aggressive use of
close_inactive timeout configuration allowed me to achieve the
tradeoff I was looking for - be gentle on the disk IO and don’t stress
too much about processing the 23 million log lines ASAP.
The final prospects configuration is thus:
filebeat:
prospectors:
- input_type: log
harvester_limit: 10
close_inactive: 10s
Conclusion
The simplest solution is, not always, but very often the correct one. From a systems engineering point of view, complex systems are almost never worth the trouble and things are best left as simple as possible. And with that, I KISS you all good night!