README.md in fluent-plugin-measure_time-0.1.1 vs README.md in fluent-plugin-measure_time-0.1.2
- old
+ new
@@ -3,95 +3,149 @@
[](http://travis-ci.org/sonots/fluent-plugin-measure_time)
[](https://codeclimate.com/github/sonots/fluent-plugin-measure_time)
Fluentd plugin to measure elapsed time to process messages
+
## Installation
Use RubyGems:
gem install fluent-plugin-measure_time
-## Configuration
+## Parameters
-This plugin is doing something tricky, which extends arbitrary plugins so that it can use `<measure_time></measure_time>` directive to measure elapsed times.
+* tag
-**Example 1:**
+ 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](https://github.com/sonots/fluent-plugin-grep/blob/master/lib/fluent/plugin/out_grep.rb#L56) method of [fluent-plugin-grep](https://github.com/sonots/fluent-plugin-grep) is taking.
+Configure fluentd.conf as below:
+
```apache
<source>
type measure_time
# This makes available the `masure_time` directive for all plugins
</source>
<source>
type forward
port 24224
- <measure_time>
- tag measure_time
- hook on_message
- </measure_time>
</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>
+</source>
```
-This example hooks the [on_message](https://github.com/fluent/fluentd/blob/e5a9a4ca03d18b45fdb89061d8251592a044e9fc/lib/fluent/plugin/in_forward.rb#L112) method of in_forward plugin, and measures how long it takes for processing. Output becomes as below:
+The output of fluent-plugin-measure_time will be as below:
```
-measure_time: {"time":0.000849735,"class":"Fluent::ForwardInput","hook":"on_message","object_id":83935080}
+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.
+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.
-**Example 2: interval**
+### interval option
-With `interval` option, this plugin compute statistics of measured elapsed times in each interval
+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:
+
```apache
<source>
type measure_time
+ # This makes available the `masure_time` directive for all plugins
</source>
<source>
type forward
port 24224
<measure_time>
tag measure_time
- interval 60
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: {"max":1.011,"avg":0.002","num":10,"class":"Fluent::ForwardInput","hook":"on_message","object_id":83935080}
+measure_time: {"time":0.000849735,"class":"Fluent::ForwardInput","hook":"on_message","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.
-
-## 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.
-
## ChangeLog
See [CHANGELOG.md](CHANGELOG.md) for details.
## Contributing