output: Prevent flushing threads from consuming too much CPU.

[fujimotos]

I believe this patch fixes the CPU spikes issue reported by #1636 and #1889
(possibly also #1665).

Problem

If one flush thread sets the retry state, this makes other threads
wait until the next retry time. This behaviour itself is fine and ok.

However, in this case the interval variable has a meaningless value
because state.next_clock is behind the system time. And since the
sleep call gets skipped in such a case:

while @output_flush_threads_running
  current_clock = Fluent::Clock.now
  interval = state.next_clock - current_clock
  ...
  sleep interval if interval > 0
end

it effectively make the waiting threads to consume the resource
aggressively with busy loops.

Solution

This patch makes a flush thread to wait in a sleep state until the
next retry time, insteads of busy looping

Note

This bug seems to exist from v0.14 since this commit 6c5ba1a.

[fujimotos]

Note: How to reproduce this issue

You can reproduce this issue relatively trivially. Try the following settings
(optionally with a debug print statement in plugin/output.rb#L1334).

<source>
  @type dummy
  tag debug.log
  dummy {"a":"b"}
</source>

# Forward to a non-existent server.
<match debug.**>
  @type forward
  <server>
    host localhost
    port 9999
  </server>
  <buffer>
    flush_interval 3
    flush_thread_count 3
  </buffer>
</match>

Also, you can use this config to check this patch actually fixes the problem

[repeatedly]

Thanks! I will check it.

[repeatedly]

Confirmed. Thanks!