[rsyslog] ElasticSearch Bulk Indexing (was: Load balancing for rsyslog aggregators)

Vlad Grigorescu vladg at illinois.edu
Fri Feb 10 15:42:13 CET 2012


-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Thanks for the reply. I should point out that my goal isn't to advise any one particular approach - just to share my experiences in the hopes that others might find them useful, and/or point out some mistake(s) I'm making.

On 2/9/12 4:10 AM, Nathan Scott wrote: 
>> - - "Pushing" to ES seems to work much less reliably than having ES
>> "pull" messages. For similarly small-sized batches (~250 messages), ES
>> would often take 6-8ms for the bulk insert. However, it would
> 
> That's quite surprising.
> 
>> occasionally spike up to 6000ms, which would cause quite a backlog in
>> the queue.
> 
> That's *really* surprising - 6 seconds?!??  Did you figure out what
> was going on there, OOC?  That sounds like a network/socket timeout
> on connect perhaps?  Can you describe the platform that you're using
> (Linux?  distro?  kernel version etc) - could be something like this
> old chestnut causing this...
> http://lkml.indiana.edu/hypermail/linux/net/0908.2/00003.html

You know, I did some poking around and couldn't find anything. Neither libcurl nor elasticsearch were reporting any errors. My queue just kept filling faster than it was emptying, and I'd see the occasional spike to 2, 3, 4 or 6 seconds. Load, memory, etc. all seemed fine on all systems. Reading over that thread, it very well could be a backlog issue. Backlog is currently set to 128 - I'll ask the system admin to up that and see if I get more consistent writes.

Just for the record, for this setup, I have one box running rsyslog, and 2 ES nodes, with replication=1. All machines are VMs, either on the same VM host, or very near to each other - latency should be <1ms. They're all running RHEL6, with 2.6.32-220.2.1 64-bit. ES nodes are quad-core, 4 GB RAM, while rsyslog is single-core, 1 GB RAM.

I am pointing the firehose at the setup, which is roughly 6000 messages/second right now.

> That sounds like its just dodging the problem a bit though, by putting
> a persistent queueing system in the middle to hide a deficiency.  I'd
> really prefer improving/fixing the underlying issues, which all seem
> to me to not be inherently unfixable...?  (except perhaps the first
> issue of needing at least one ES hostname ... but again, the same issue
> must affect rabbitmq, so must be solvable somehow?  or using a floating
> IP address or some such trickery).

No, I agree - I think these are issues that are fixable, and of course the simpler the solution, the better. 

> What happens when the queueing system in the middle goes down though?
> Or when that queueing system gets very busy - haven't we just moved the
> same problem somewhere else?

The reason I started playing around with rabbit was for greater performance. From what I've read, the river should be faster than simply using the bulk API, simply because it's designed to deal with the constant stream of messages I'm sending it. However, I need to do some additional testing, to figure out exactly how much faster it is. However, if I can figure out how to get the performance I need without the extra layer of complexity, that'd be preferred. 

>> well, and the indexing throughput seems higher, due to not pushing
>> messages to ES when it's very busy.
> 
> OOC, when you see elasticsearch getting very busy, is it network or
> CPU bound, or something else?

I had assumed that when the ES insert would take seconds, that was because ES load was momentarily high. I didn't see anything on the network on the on ES nodes to indicate an issue. It seems reasonable, however, that having ES grab data asynchronously would be more efficient, but again, I still need to test this.

> Limiting the batch size to something that can't blow that limit would
> seem preferable than a libcurl rebuild, perhaps.  The ES responses are
> fairly terse, we should be able to calculate a fixed upper bound.

I did some looking into this, and the numbers seemed to be pretty low. The response I see is:

{"took":8,"items":[{"create":{"_index":"system","_type":"events","_id":01234567890123456890ab","_version":1,"ok":true}},{"create":{"_index":"system","_type":"events","_id":01234567890123456890ab","_version":1,"ok":true}}]}

The value of took is the milliseconds that the operation took to complete. Let's assume a slow operation that took >=10 ms to complete. So, we have a fixed value of:
{"took":10,"items":[]} (22 characters).

Then, each message has a response of:
{"create":{"_index":"system","_type":"events","_id":01234567890123456890ab","_version":1,"ok":true}}, (101 characters).

The last message won't have the trailing comma, so that gives us 22 + 101*n - 1, where n is the number of messages sent in a batch. The result is just ASCII encoded (one byte/character).

16 KB minus the 21 bytes of overhead give us a maximum of only 162 messages at 101 bytes each. (Obviously this will change depending on your index and type name). 

However, in the event of an error, the reply is much more verbose. ElasticSearch will return the exception name, the error message, and in the case of a parse error, it will return your message in comma-separated decimal ASCII format. I introduced an extra character in the messages I was sending, and had an average error length of 718 bytes (in addition to the 101 baseline). That would be less than 20 messages/batch, and that's only in the average case.


Thanks,

  --Vlad
-----BEGIN PGP SIGNATURE-----
Version: GnuPG/MacGPG2 v2.0.18 (Darwin)

iQIcBAEBAgAGBQJPNSzDAAoJEMEVj6tjLlJyGpwP/RmuOTEyUrGgxkGYYYocqbYE
SMc9NOCXxB+ML6K3kQ5nG8op/hBNkjbkC2x3ALTucs/HwmImRMEN2/twGLDT2b5p
CMS9dzlJWHSP5SoVYoYMCooBqrSCHJaAxXw+5bwWlG4tIjnZ3/cxA+LrwkrxGpYl
gQ/KehvVJWyhYAYEofPg52dSvEHh/z+pLzUa1t+MDP+OKbVJgKKOpSggCaTXDN7Y
yvUdSGwEb5dVmJ4N38htBlsxT15MiS6NalY+YyII+MaFLMm+imZBqxlvb/+c33XR
NonvMZvHUIMj1x/kg9kZ768M4Tl1njFDnEXa7+dlGu5R2swcetFRuLK321zjkvoK
bO9+IxkOYzkAUAaMSsFwl4+DDD4k66wkF+M/8SKdJBHR+vf2jzipbgd7CUFx3NOT
RUo+hhIrb0SKLwWtxfQWBEWpLqACtj/fgjNkeaPubpXrDWisqENhHWWjsxrp09qe
q95DxNHKjLC7AXIEJbX8n9xQucX4NmR/NwPI8O8ODM1kyvhqUe9t9jDMYauDK9nd
z53sgVZLteIQ7Qi5z8ls/T3tyPOkPH+NMxGxGV14wM7LbWC6QKKHpUqCfI0a1MjF
uDoH7EGpP1UCEq0nSbeAXyowp+Hf4UK+hu8M+dwM+oK9m39a1DtUuFGTBkI/yJTS
FLLeOHx8PXoJhWGG39fe
=NPn0
-----END PGP SIGNATURE-----



More information about the rsyslog mailing list