Mutate and statsd not work in my logstash


(Chengcheng Pei) #1

New to logstash.
Assume messages in kafka look like:

{'test message':[{'key':'key-1234'}]}
{"test message":[{"key":"key-1234"}]}
    ...

Try to increase the statsd key:test-1234.
There are two problems:

(1) when input kafka is {'test message':[{'key':'key-1234'}]}, 1234 is printed on the screen.
when input kafka is {"test message":[{"key":"key-1234"}]}, %{info} is printed on the screen.
The output:

Logstash startup completed
1234
%{info}

(2) can not increase the statsd key.
Why

The following is my config file for logstash. Any suggestions are welcome.

input
{
    kafka
    {
        topic_id => 'test2'
    }
}


filter
{
    mutate
    {
        gsub => [ "message", "\"", "'" ]
    }

    grok
    {
        match => ["message", ".*key-(?<info>[0-9]{4,6}).*"]
    }
}

output
{
    stdout
    {
        codec => line
        {
            format => "%{info}"
        }
    }

    statsd
    {
        host => "10.1.21.205"
        port => 8125
        increment => "test-%{info}" 
    }

    statsd
    {
        host => "localhost"
        port => 8125
        increment => "test-%{info}"
    }

}

(Magnus Bäck) #2
{'test message':[{'key':'key-1234'}]}

What, single quotes? That's not valid JSON.

If this is supposed to be JSON, please fix the broken system that emits the data. Failing that, replace single quotes with double quotes and parse it as JSON (and beware of corner cases if the key or values themselves contain quotes).

(1) when input kafka is {'test message':[{'key':'key-1234'}]}, 1234 is printed on the screen.
when input kafka is {"test message":[{"key":"key-1234"}]}, %{info} is printed on the screen.

I can't reproduce what you're describing with Logstash 1.5.4:

$ cat test.config
input { stdin { } }
output { stdout { codec => line { format => "%{info}" } } }
filter {
mutate
    {
        gsub => [ "message", "\"", "'" ]
    }

    grok
    {
        match => ["message", ".*key-(?<info>[0-9]{4,6}).*"]
    }
}
$ echo "{'test message':[{'key':'key-1234'}]}" | /opt/logstash/bin/logstash -f test.config
1234
Logstash startup completed
Logstash shutdown completed
$ echo '{"test message":[{"key":"key-1234"}]}' | /opt/logstash/bin/logstash -f test.config
Logstash startup completed
1234
Logstash shutdown completed

(2) can not increase the statsd key.

Anything interesting in the Logstash logs? What if you crank up the log level with --debug? Have you tried using e.g. Wireshark to see what's actually being sent over the wire?


(Chengcheng Pei) #3

If there are double quotes, try to use mutate to replace them with single quotes. Otherwise grok match may fail to do the work. But in my config file, mutate seems not wok. This is my first problem.

The second problem is that statsd output does not work.
below is part of debug info:

  • filter received
    {:event=>{"testmessage"=><Java::JavaUtil::ArrayList:452931790
    [{"key"=>"key-1234"}]>, "@version"=>"1",
    "@timestamp"=>"2015-11-09T19:42:03.701Z"}, :level=>:debug,
    :file=>"(eval)", :line=>"73", :method=>"filter_func"}
    gsub mutation is only applicable for Strings, skipping {:field=>"message", :value=>nil, :level=>:debug,
    :file=>"logstash/filters/mutate.rb", :line=>"322", :method=>"gsub"}
    Running grok filter {:event=>#<LogStash::Event:0x4c2a67cc @metadata={}, @accessors=#<LogStash::Util::Accessors:0x7404a924
    @store={"testmessage"=><Java::JavaUtil::ArrayList:452931790
    [{"key"=>"key-1234"}]>, "@version"=>"1",
    "@timestamp"=>"2015-11-09T19:42:03.701Z"},
    @lut={"message"=>[{"testmessage"=><Java::JavaUtil::ArrayList:452931790
    [{"key"=>"key-1234"}]>, "@version"=>"1",
    "@timestamp"=>"2015-11-09T19:42:03.701Z"}, "message"]}>,
    @data={"testmessage"=><Java::JavaUtil::ArrayList:452931790
    [{"key"=>"key-1234"}]>, "@version"=>"1",
    "@timestamp"=>"2015-11-09T19:42:03.701Z"},
    @metadata_accessors=#<LogStash::Util::Accessors:0x2c416dc0 @store={},
    @lut={}>, @cancelled=false>, :level=>:debug,
    :file=>"logstash/filters/grok.rb", :line=>"283", :method=>"filter"}
    Event now: {:event=>#<LogStash::Event:0x4c2a67cc @metadata={}, @accessors=#<LogStash::Util::Accessors:0x7404a924
    @store={"testmessage"=><Java::JavaUtil::ArrayList:452931790
    [{"key"=>"key-1234"}]>, "@version"=>"1",
    "@timestamp"=>"2015-11-09T19:42:03.701Z",
    "tags"=>["_grokparsefailure"]},
    @lut={"message"=>[{"testmessage"=><Java::JavaUtil::ArrayList:452931790
    [{"key"=>"key-1234"}]>, "@version"=>"1",
    "@timestamp"=>"2015-11-09T19:42:03.701Z",
    "tags"=>["_grokparsefailure"]}, "message"],
    "tags"=>[{"testmessage"=><Java::JavaUtil::ArrayList:452931790
    [{"key"=>"key-1234"}]>, "@version"=>"1",
    "@timestamp"=>"2015-11-09T19:42:03.701Z",
    "tags"=>["_grokparsefailure"]}, "tags"]}>,
    @data={"testmessage"=><Java::JavaUtil::ArrayList:452931790
    [{"key"=>"key-1234"}]>, "@version"=>"1",
    "@timestamp"=>"2015-11-09T19:42:03.701Z",
    "tags"=>["_grokparsefailure"]},
    @metadata_accessors=#<LogStash::Util::Accessors:0x2c416dc0 @store={},
    @lut={}>, @cancelled=false>, :level=>:debug,
    :file=>"logstash/filters/grok.rb", :line=>"303", :method=>"filter"}
    output received {:event=>{"testmessage"=><Java::JavaUtil::ArrayList:452931790
    [{"key"=>"key-1234"}]>, "@version"=>"1",
    "@timestamp"=>"2015-11-09T19:42:03.701Z",
    "tags"=>["_grokparsefailure"]}, :level=>:debug, :file=>"(eval)",
    :line=>"80", :method=>"output_func"}
    %{info}
    Original sender: %{host} {:level=>:debug, :file=>"logstash/outputs/statsd.rb", :line=>"94", :method=>"receive"}
    Munged sender: %{host} {:level=>:debug, :file=>"logstash/outputs/statsd.rb", :line=>"96", :method=>"receive"}
    Event: 2015-11-09T19:42:03.701Z %{host} %{message} {:level=>:debug, :file=>"logstash/outputs/statsd.rb", :line=>"97",
    :method=>"receive"}
    Formatted value {:sender=>"%{host}", :metric=>"test.%{info}", :level=>:debug, :file=>"logstash/outputs/statsd.rb", :line=>"125",
    :method=>"build_stat"}
    Original sender: %{host} {:level=>:debug, :file=>"logstash/outputs/statsd.rb", :line=>"94", :method=>"receive"}
    Munged sender: %{host} {:level=>:debug, :file=>"logstash/outputs/statsd.rb", :line=>"96", :method=>"receive"}
    Event: 2015-11-09T19:42:03.701Z %{host} %{message} {:level=>:debug, :file=>"logstash/outputs/statsd.rb", :line=>"97",
    :method=>"receive"}
    Formatted value {:sender=>"%{host}", :metric=>"test.%{info}", :level=>:debug, :file=>"logstash/outputs/statsd.rb", :line=>"125",
    :method=>"build_stat"}

(Magnus Bäck) #4

Your message field contains an array with a single dictionary. It's not a string, so gsub won't work. If message points to a nested structure you can access its elements directly and you don't need gsub.

If you use a stdout { codec => rubydebug } output you'll see more clearly what the field contains and you can easily tweak your configuration and observe what happens.

The statsd problem is caused by the grok problem. Solve one problem at a time.


(Chengcheng Pei) #5

I tried your postings. If the input is stdin, mutate works.


(Chengcheng Pei) #6

Now I changed my config file to the following:

> input
> {
>     kafka
>     {
>         topic_id => 'test2'
>     }
> }
> # Try to match sensor info
> filter
> {
>     json { source => "message"}
> }
> # StatsD and stdout output
> output
> {
>     stdout
>     {
>         codec => line
>         {
>             format => "%{[testmessage][0][key]}"
>         }
>     }
>     stdout { codec=>rubydebug}
>     statsd
>     {
>         host => "10.1.21.205"
>         port => 8125
>         increment => "test.%{[testmessage][0][key]}"
>     }
>     statsd
>     {
>         host => "localhost"
>         port => 8125
>         increment => "test.%{[testmessage][0][key]}"
>     }
>     statsd
>     {
>         host => "10.1.21.205"
>         port => 8125
>         count => ["test1", "%{[testmessage][0][key]}"]
>     }
>     statsd
>     {
>         host => "localhost"
>         port => 8125
>         count => ["test2", "%{[testmessage][0][key]}"]
>     }
> }

The input is : {"testmessage":[{"key":"key-1234"}]}

Output is:

Logstash startup completed
key-1234
{
"testmessage" => [
[0] {
"key" => "key-1234"
}
],
"@version" => "1",
"@timestamp" => "2015-11-09T19:53:16.864Z"
}

It seems that statsd still does not work.


(Magnus Bäck) #7

Then inspect the debug logs and, if necessary, check what's being sent over the wire.


(Chengcheng Pei) #8

debug info:
Original sender: %{host} {:level=>:debug, :file=>"logstash/outputs/statsd.rb", :line=>"94", :method=>"receive"}
Munged sender: %{host} {:level=>:debug, :file=>"logstash/outputs/statsd.rb", :line=>"96", :method=>"receive"}
Event: 2015-11-09T20:00:47.153Z %{host} %{message} {:level=>:debug, :file=>"logstash/outputs/statsd.rb", :line=>"97", :method=>"receive"}
Formatted value {:sender=>"%{host}", :metric=>"test.key-1234", :level=>:debug, :file=>"logstash/outputs/statsd.rb", :line=>"125", :method=>"build_stat"}

No idea what is the problem.... Try to figure it out.


(system) #9