Logstash metrics don't make sense

Elastic Stack Logstash
1

I have a 1,000 line sample web log file that I run through logstash and I time the run.

$ time cat apache_combined_log.20160420.1000-lines | ../logstash-2.3.1/bin/logstash -f apache_logstash.3.conf > foo

real 0m25.678s
user 0m29.378s
sys 0m0.904s

So, it takes almost 26 seconds, including the overhead of logstash starting up, to process 1,000 records. That rate is a bit over 2,000 records per minute, which is really slow.

Here's the output of the metrics filter, showing 1,000 records read and showing rates of 12 to 13 records per minute.

{
"@version" => "1",
"@timestamp" => "2016-04-25T20:29:12.669Z",
"message" => "lxelk1.mydomain",
"events" => {
"count" => 1000,
"rate_1m" => 11.960577390181204,
"rate_5m" => 12.785128899681027,
"rate_15m" => 12.927978024063657
},
"tags" => [
[0] "metric"
]
}

2,000 records per minute is way different than 13 records per minute.

What am I missing?

2

I'm quite sure the emitted rate is actually per second rather than per minute. It still doesn't quite match though (one-minute rate of ~720 eps), but I suspect that might be because you only ran for about 25 seconds and if you calculate the rate based on sliding one-minute windows I could easily see why 2000 eps would be reported as 720 eps. See the GitHub issue below.

3

Thanks for your reply. I would suggest an addition to the metrics filter document to state that metrics are in records per second.

Last night I loaded 1.2 million records and, looking at those metrics after logstash had been running for a while, the reported one minute rate of around 1,000 is very consistent with my calculation of 1,000 records per second being processed.

So, I'm good. Thanks again for your help.

4

I would suggest an addition to the metrics filter document to state that metrics are in records per second.

I've filed a pull request that should clarify the situation.

5

Thank you.