fluent-plugin-measure_time

Fluentd plugin to measure elapsed time to process messages

Installation

Use RubyGems:

gem install fluent-plugin-measure_time

Parameters

• tag

  The output tag name. Default is measure_time

• hook (required)

  Specify the method to measure time.

• interval

  The time interval to emit measurement results. Default is nil which do not compute statistics and emit the time in each measurement.

Configuration Example 1 - Profile an Output Plugin

As an example, let's profile how long the emit method of fluent-plugin-grep is taking. Configure fluentd.conf as below:

For Fluentd v0.10:

<source>
  type measure_time
  # This makes available the `measure_time` directive for all plugins
</source>

<source>
  type forward
  port 24224
</source>

# measure_time plugin output comes here
<match measure_time>
  type stdout
</match>

# Whatever you want to do
<match greped.**>
  type stdout
</match>

<match **>
  type grep
  add_tag_prefix greped
  <measure_time>
    tag measure_time
    hook emit
  </measure_time>
</match>

For Fluentd v0.12:

<label @measure_time>
  <match>
    @type measure_time
    # This makes available the `measure_time` directive for all plugins
  </match>
</label>

<source>
  @type dummy
  tag raw.dummy
  dummy {"message":"foo"}
</source>

# measure_time plugin output comes here
<match measure_time>
  @type stdout
</match>

# Whatever you want to do
<match greped.**>
  @type stdout
</match>

<match **>
  @type grep
  add_tag_prefix greped
  <measure_time>
    tag measure_time
    hook emit
  </measure_time>
</match>

The output of fluent-plugin-measure_time will be as below:

measure_time: {"time":0.000849735,"class":"Fluent::GrepOutput","hook":"emit","object_id":83935080}

where time denotes the measured elapsed time, and class, hook, and object_id denotes the hooked class, the hooked method, and the object id of the plugin instance.

interval option

fluent-plugin-measure_time outputs the elapsed time for each calling, but you can use the interval option when you want to get statistics in each interval.

measure_time: {"max":1.011,"avg":0.002","num":10,"class":"Fluent::GrepOutput","hook":"emit","object_id":83935080}

where max and avg are the maximum and average elapsed times, and num is the number of being called in each interval.

Configuration Example (2) - Profile the in_forward plugin

I introduce an interesting example here.

Following illustration draws the sequence of that in_forward plugin receives a data, processes, and passes the data to output plugins.

Sequence Diagram

     +–––––––––––––+    +––––––––––––––+   +––––––––––––––+
     |  in_forwrd  |    |   Output     |   |   Output     |
     +––––––+––––––+    +––––––+–––––––+   +––––––+–––––––+
#on_message | start = Time.now |                  |
            +––––––––––––––––––>                  |
            |      #emit       |                  |
            |                  +––––––––––––––––––>
            |                  |      #emit       |
            |                  |                  |
            |                  |                  |
            |                  <– – – – – – – – – +
            | elapsed = Time.now - start          |
            <– – – – – - – – – +                  |
            |                  |                  |
            +                  +                  +

As the illustration, by hooking on_message method of in_forward plugin, we can measure the blocking time taking to process the received data, which also means that the time taking until in_forward will be ready for receiving a next data.

This profiling is very useful to investigate when you have a suspicion that throughputs of Fluentd fell down extremely.

The configuration will be as follows:

For Fluentd v0.10:

<source>
  type measure_time
  # This makes available the `measure_time` directive for all plugins
</source>

<source>
  type forward
  port 24224
  <measure_time>
    tag measure_time
    hook on_message
  </measure_time>
</source>

<match measure_time>
  type stdout
</match>

# whatever you want
<match **>
  type stdout
</match>

For Fluentd v0.12:

<label @measure_time>
  <match>
    @type measure_time
    # This makes available the `measure_time` directive for all plugins
  </match>
</match>

<source>
  @type forward
  port 24224
  <measure_time>
    tag measure_time
    hook on_message
  </measure_time>
</source>

<match measure_time>
  @type stdout
</match>

# whatever you want
<match **>
  @type stdout
</match>

Output becomes as below:

measure_time: {"time":0.000849735,"class":"Fluent::ForwardInput","hook":"on_message","object_id":83935080}

ChangeLog

See CHANGELOG.md for details.

Contributing

1. Fork it
2. Create your feature branch (git checkout -b my-new-feature)
3. Commit your changes (git commit -am 'Add some feature')
4. Push to the branch (git push origin my-new-feature)
5. Create new Pull Request

Copyright

Copyright (c) 2014 Naotoshi Seo. See LICENSE for details.