Fluentd: Large message overflow logic incorrect

[amread]

Check CONTRIBUTING guideline first and here is the list to help us investigate the problem.

• fluentd or td-agent version. v1.0.2 (also seems to be a problem on master right now)

I have a use case that allows for very log messages. While load testing using 2m buffers, I noticed that if I try to quickly jam these messages through back-to-back, the system will complain:

a 524596bytes record is larger than buffer chunk limit size

Looking at the code, I see the test for a single record overflowing the current chunk in write_step_by_step:

                  if split.size == 1 && original_bytesize == 0
                    big_record_size = format ? format.call(split).bytesize : split.first.bytesize
                    raise BufferChunkOverflowError, "a #{big_record_size}bytes record is larger than buffer chunk limit size"
                  end

Since original_bytesize is set outside of the inner loop, it does not detect if the current split is the first chunk. The fix to this is straightforward enough, but the retry logic isn't clever enough to do something different the next time.

Ideally, we would know ahead of time that the message would overflow the buffer and just not write it. I imagine the code does not take the approach for the sake of efficiency. It would be nice if there was something like the commit and rollback functionality for use while constructing the chunk, perhaps mark() and rewindToMark() functions, or maybe even restructure append and concat to take blocks and allow for rewinding on failure.

I took a stab at some minimal change, but found that I don't have a full appreciation for the nuance of this function's existing behavior, given the various assertions that failed in my attempts to fix this bug. It does seem that the underlying assumption of the current code is that records are small in comparison to the buffer so that the chunk_full_threshold will always be crossed while filling a chunk. I can probably work around this issue by either increasing my buffer size, or changing the chunk_full_threshold.

Here is a test that shows the problem adding one message that fills half the buffer, and then another that goes one byte over (added to 'with configuration for test with lower limits` sub_test_case):

    test '#write does not raise BufferOverflowError when chunk is not empty' do
      m = @p.metadata(timekey: Time.parse('2016-04-11 16:40:00 +0000').to_i)

      assert_nothing_raised Fluent::Plugin::Buffer::BufferOverflowError do
        @p.write({m => ["a" * 512, "b" * 513 ]})
      end
    end

Commit with new test: https://github.com/amread/fluentd/commit/d0653aa80d3022b6708303176475280f2fb29af5

[TheCoderGuyVlad]

Hi @amread / @repeatedly
I believe we are seeing the same thing. What is your recommendation: to increase the buffer size or to wait for a fix/workaround?
Thank you

[repeatedly]

@TheCoderGuyVlad If you don't have a problem, set larger chunk_limit_size is better.
Changing buffer internal need some design consideration so it needs more time.

[amread]

If you know the largest message size, you can adjust the chunk_limit_size or chunk_full_threshold to meet your needs (I ended up raising my chunk size and lowering the threshold slightly). I added message truncation to our pipeline to make sure no message exceeds the maximum message size.

You want to choose values for these such that when a chunk is one byte less than the threshold if a max sized message comes next it will not overflow the buffer.

[TheCoderGuyVlad]

Thanks @repeatedly and @amread for your inputs! Appreciate it!

[dennyac]

Ran into this issue and @amread 's suggestion worked for us.

Can we call this out in the fluentd docs till it is resolved? Took us a while to figure out that fluentd was dropping messages in our data pipeline.