logstash configuration for Dropwizard Metrics

This post is older than a year. Consider some information might not be accurate anymore.

Dropwizard Metrics generates application metrics for Java applications. This post demonstrates an example of the Slf4jReporter and its logstash configuration.

grokking the output

Depending on your log config the Slf4jReporter creates following output:

16:16:10,966 [metrics] type=TIMER, name=delivery.header.parsing.time, count=1, min=9.517406, max=9.517406, mean=9.517406, stddev=0.0, median=9.517406, p75=9.517406, p95=9.517406, p98=9.517406, p99=9.517406, p999=9.517406, mean_rate=0.03727438239447458, m1=0.1433062621147579, m5=0.18710139700632353, m15=0.19560457449692012, rate_unit=events/second, duration_unit=milliseconds

Using the grok debugger, gives you a grok pattern, which will parsed the log data.

%{TIME} \[(?<logthread>(?:[a-z]*))\] %{GREEDYDATA}

The GREEDYDATA pattern might not be known on logstash, so it we changed it into:

%{TIME} \[(?<logthread>(?:[a-z]*))\] (?<data>(.*))

This results in

{
  "TIME": [
    [
      "16:16:10,966"
    ]
  ],
  "HOUR": [
    [
      "16"
    ]
  ],
  "MINUTE": [
    [
      "16"
    ]
  ],
  "SECOND": [
    [
      "10,966"
    ]
  ],
  "logthread": [
    [
      "metrics"
    ]
  ],
  "data": [
    [
      "type=TIMER, name=delivery.header.parsing.time, count=1, min=9.517406, max=9.517406, mean=9.517406, stddev=0.0, median=9.517406, p75=9.517406, p95=9.517406, p98=9.517406, p99=9.517406, p999=9.517406, mean_rate=0.03727438239447458, m1=0.1433062621147579, m5=0.18710139700632353, m15=0.19560457449692012, rate_unit=events/second, duration_unit=milliseconds"
    ]
  ]
}

logstash test configuration

With the know grok pattern, we take the data field as input for the key value filter plugin, that parses the data. We need to configure it properly with a custom field split.

input {
    stdin {}
}
filter {
    grok {
        match => { "message" => "%{TIME} \[(?<logthread>(?:[a-z]*))\] (?<data>(.*))" }
    }
    kv {
        source => "data"
        field_split => ", "
    }
}
output {
    stdout {
        codec => "rubydebug"
    }
}

It creates for each key the respective field:

{
          "message" => "16:16:10,966 [metrics] type=TIMER, name=delivery.header.parsing.time, count=1, min=9.517406, max=9.517406, mean=9.517406, stddev=0.0, median=9.517406, p75=9.517406, p95=9.517406, p98=9.517406, p99=9.517406, p999=9.517406, mean_rate=0.03727438239447458, m1=0.1433062621147579, m5=0.18710139700632353, m15=0.19560457449692012, rate_unit=events/second, duration_unit=milliseconds\r",
         "@version" => "1",
       "@timestamp" => "2015-09-28T10:28:51.620Z",
             "host" => "cinhtau",
        "logthread" => "metrics",
             "data" => "type=TIMER, name=delivery.header.parsing.time, count=1,min=9.517406, max=9.517406, mean=9.517406, stddev=0.0, median=9.517406, p75=9.517406, p95=9.517406, p98=9.517406, p99=9.517406, p999=9.517406, mean_rate=0.03727438239447458, m1=0.1433062621147579, m5=0.18710139700632353, m15=0.19560457449692012, rate_unit=events/second, duration_unit=milliseconds\r",
             "type" => "TIMER",
             "name" => "delivery.header.parsing.time",
            "count" => "1",
              "min" => "9.517406",
              "max" => "9.517406",
             "mean" => "9.517406",
           "stddev" => "0.0",
           "median" => "9.517406",
              "p75" => "9.517406",
              "p95" => "9.517406",
              "p98" => "9.517406",
              "p99" => "9.517406",
             "p999" => "9.517406",
        "mean_rate" => "0.03727438239447458",
               "m1" => "0.1433062621147579",
               "m5" => "0.18710139700632353",
              "m15" => "0.19560457449692012",
        "rate_unit" => "events/second",
    "duration_unit" => "milliseconds\r"
}

Pay attention when dumping to elasticsearch the data type is String and needs to be probably converted with the mutate filter plugin or the respective mapping on elasticsearch needs to be modified.