Parsing Logstash Message Fields

Elastic Stack Logstash
1

I currently have logstash sending to Elastic cloud - I'd like to get that message section parsed out a bit so that its not one giant section. Could someone help me with that?

Here's my filter section - it is just the "out of the box" code

filter {
  if [type] == "syslog" {
    grok {
      match => { "message" => "%{SYSLOGTIMESTAMP:syslog_timestamp} %{SYSLOGHOST:syslog_hostname} %{DATA:syslog_program}(?:\[%{POSINT:syslog_pid}\])?: %{GREEDYDATA:syslog_message}" }
      add_field => [ "received_at", "%{@timestamp}" ]
      add_field => [ "received_from", "%{host}" ]
    }
    date {
      match => [ "syslog_timestamp", "MMM  d HH:mm:ss", "MMM dd HH:mm:ss" ]
    }
  }
}

Here's the syslog as parsed by logstash:

Mar 25 12:14:54 mid-mon1 logstash[938]: {
Mar 25 12:14:54 mid-mon1 logstash[938]:           "host" => "10.X.XX.XXX",
Mar 25 12:14:54 mid-mon1 logstash[938]:       "@version" => "1",
Mar 25 12:14:54 mid-mon1 logstash[938]:     "@timestamp" => 2021-03-25T17:14:53.793Z,
Mar 25 12:14:54 mid-mon1 logstash[938]:           "type" => "syslog",
Mar 25 12:14:54 mid-mon1 logstash[938]:        "message" => "<163>1 2021-03-25T12:14:53-05:00 mid-XXX wafd - - [meta sequenceId=\"155\"] [client 94.XXX.176.XXX] ModSecurity: Warning. String match \"multipart\" at REQUEST_HEADERS:Content-Type. [file \"/tmp/waf/10/modsecurity_slr_46_known_vulns.conf\"] [line \"720\"] [id \"2170100\"] [rev \"11202017\"] [msg \"SLR: Apache Struts (Body inspection Enabled)\"] [tag \"application-struts\"] [tag \"language-java\"] [tag \"platform-multi\"] [tag \"attack-injection\"] [hostname \"172.XX.X.XX (HTTP_redirect_no_cert)\"] [uri \"/\"] [unique_id \"3f77d992-0563-42a1-b62c-fc739ba7a124\"]\n",
Mar 25 12:14:54 mid-mon1 logstash[938]:           "tags" => [
Mar 25 12:14:54 mid-mon1 logstash[938]:         [0] "_grokparsefailure"
Mar 25 12:14:54 mid-mon1 logstash[938]:     ]
Mar 25 12:14:54 mid-mon1 logstash[938]: }

Any help in parsing the message section would be much appreciated.

2

I would use dissect first, then dive in to ruby to run a String::scan.

    mutate { gsub => [ "message", "\n", "" ] }
    dissect { mapping => { "message" => "<%{syslogPri}>%{aNumber} %{[@metadata][timestamp]} %{maybeHost} %{maybeProgram} %{} %{} %{[@metadata][restOfLine]}" } }
    ruby {
        code => '
            matches = event.get("[@metadata][restOfLine]").scan(/\[(\w+) ([^\]]+)\]/)
            # match is an array of arrays, like [["meta", "sequenceId=\"155\""], ["client", "94.XXX.176.XXX"], ...
            matches.each { |x|
                field = x[0]
                value = x[1].sub(/^"/, "").sub(/"$/, "")
                if event.include?(field)
                    a = Array(event.get(field))
                    a << value
                    event.set(field, a)
                else
                    event.set(field, value)
                end
            }
        '
    }
    mutate { gsub => [ "[@metadata][restOfLine]", "\[[^\]]+\]( )?", "" ] }
    mutate { add_field => { "restOfMessage" => "%{[@metadata][restOfLine]}" } }

This will result in

"restOfMessage" => "ModSecurity: Warning. String match \"multipart\" at REQUEST_HEADERS:Content-Type. ",
         "line" => "720",
    "maybeHost" => "mid-XXX",
          "tag" => [
    [0] "application-struts",
    [1] "language-java",
    [2] "platform-multi",
    [3] "attack-injection"
],
    "unique_id" => "3f77d992-0563-42a1-b62c-fc739ba7a124",
       "client" => "94.XXX.176.XXX",
 "maybeProgram" => "wafd",
          "uri" => "/"

etc. Feel free to mutate+gsub the trailing space from [restOfMessage], and change all the field names in the dissect if you know what they should be.

3

Hi @Badger thanks for the quick reply. I am really new to this - where does your code fit into mine? Also, the mutate and dissect - are those packages i need to install or can I just use them with Logstash out of the box?

4

My code would replace your grok filter. mutate and dissect are part of the logstash package out-of-the-box-- no need to install anything extra.

5

I was able to get it working and the logs are parsing in kibana correctly. I do see the following message filling my syslog - is there a way to prevent that? I also see some errors in there.

Also, I'm getting these errors- even after a refresh of the index.
image

Mar 29 13:35:47 mid-mon1 logstash[32268]: [2021-03-29T13:35:47,996][INFO ][logstash.inputs.tcp      ][main][d0420e500ec93f6bf33f96849528a9ab8968bba0a3cae497eb072d6555b76612] Starting tcp input listener {:address=>"0.0.0.0:5000", :ssl_enable=>"false"}
Mar 29 13:35:47 mid-mon1 logstash[32268]: [2021-03-29T13:35:47,996][WARN ][io.netty.channel.AbstractChannel][main][d0420e500ec93f6bf33f96849528a9ab8968bba0a3cae497eb072d6555b76612] Force-closing a channel whose registration task was not accepted by an event loop: [id: 0x49c08eea]
Mar 29 13:35:47 mid-mon1 logstash[32268]: java.util.concurrent.RejectedExecutionException: event executor terminated
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:926) ~[logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(SingleThreadEventExecutor.java:353) ~[logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:346) ~[logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:828) ~[logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:818) ~[logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.channel.AbstractChannel$AbstractUnsafe.register(AbstractChannel.java:471) [logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:87) [logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:81) [logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.channel.MultithreadEventLoopGroup.register(MultithreadEventLoopGroup.java:86) [logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.bootstrap.AbstractBootstrap.initAndRegister(AbstractBootstrap.java:323) [logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.bootstrap.AbstractBootstrap.doBind(AbstractBootstrap.java:272) [logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.bootstrap.AbstractBootstrap.bind(AbstractBootstrap.java:268) [logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at io.netty.bootstrap.AbstractBootstrap.bind(AbstractBootstrap.java:253) [logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at org.logstash.tcp.InputLoop.run(InputLoop.java:87) [logstash-input-tcp-6.0.6.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at jdk.internal.reflect.GeneratedMethodAccessor59.invoke(Unknown Source) ~[?:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:441) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at org.jruby.javasupport.JavaMethod.invokeDirect(JavaMethod.java:305) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at org.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:32) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_input_minus_tcp_minus_6_dot_0_dot_6_minus_java.lib.logstash.inputs.tcp.RUBY$method$run$0(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-tcp-6.0.6-java/lib/logstash/inputs/tcp.rb:163) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at usr.share.logstash.logstash_minus_core.lib.logstash.java_pipeline.RUBY$method$inputworker$0(/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:405) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at usr.share.logstash.logstash_minus_core.lib.logstash.java_pipeline.RUBY$method$inputworker$0$__VARARGS__(/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:80) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:70) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at org.jruby.ir.targets.InvokeSite.invoke(InvokeSite.java:207) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:47 mid-mon1 logstash[32268]: #011at usr.share.logstash.logstash_minus_core.lib.logstash.java_pipeline.RUBY$block$start_input$1(/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:396) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:48 mid-mon1 logstash[32268]: #011at org.jruby.runtime.CompiledIRBlockBody.callDirect(CompiledIRBlockBody.java:138) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:48 mid-mon1 logstash[32268]: #011at org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:58) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:48 mid-mon1 logstash[32268]: #011at org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:52) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:48 mid-mon1 logstash[32268]: #011at org.jruby.runtime.Block.call(Block.java:139) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:48 mid-mon1 logstash[32268]: #011at org.jruby.RubyProc.call(RubyProc.java:318) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:48 mid-mon1 logstash[32268]: #011at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:105) [jruby-complete-9.2.13.0.jar:?]
Mar 29 13:35:48 mid-mon1 logstash[32268]: #011at java.lang.Thread.run(Thread.java:834) [?:?]
Mar 29 13:35:48 mid-mon1 logstash[32268]: [2021-03-29T13:35:47,998][ERROR]*[logstash.javapipeline    ][main][d0420exxxxxxxxxxxxxxxxxxxxxxxxxxx9528a9ab8968bba0a3cae497eb072d6555b76612] A plugin had an unrecoverable error. Will restart this plugin.*
Mar 29 13:35:48 mid-mon1 logstash[32268]:   Pipeline_id:main
Mar 29 13:35:48 mid-mon1 logstash[32268]:   Plugin: <LogStash::Inputs::Tcp type=>"syslog", port=>5000, id=>"d0420exxxxxxxxxxxxx28a9ab8968bba0a3cae497eb072d6555b76612", enable_metric=>true, codec=><LogStash::Codecs::Line id=>"line_671566f5-145d-407f-a769-87fb0a91cabd", enable_metric=>true, charset=>"UTF-8", delimiter=>"\n">, host=>"0.0.0.0", mode=>"server", proxy_protocol=>false, ssl_enable=>false, ssl_verify=>true, ssl_key_passphrase=><password>, tcp_keep_alive=>false, dns_reverse_lookup_enabled=>true>
Mar 29 13:35:48 mid-mon1 logstash[32268]:   Error: event executor terminated
Mar 29 13:35:48 mid-mon1 logstash[32268]:   Exception: Java::JavaUtilConcurrent::RejectedExecutionException
Mar 29 13:35:48 mid-mon1 logstash[32268]:   Stack: io.netty.util.concurrent.SingleThreadEventExecutor.reject(io/netty/util/concurrent/SingleThreadEventExecutor.java:926)
Mar 29 13:35:48 mid-mon1 logstash[32268]: io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(io/netty/util/concurrent/SingleThreadEventExecutor.java:353)
Mar 29 13:35:48 mid-mon1 logstash[32268]: io.netty.util.concurrent.SingleThreadEventExecutor.addTask(io/netty/util/concurrent/SingleThreadEventExecutor.java:346)
Mar 29 13:35:48 mid-mon1 logstash[32268]: io.netty.util.concurrent.SingleThreadEventExecutor.execute(io/netty/util/concurrent/SingleThreadEventExecutor.java:828)
Mar 29 13:35:48 mid-mon1 logstash[32268]: io.netty.util.concurrent.SingleThreadEventExecutor.execute(io/netty/util/concurrent/SingleThreadEventExecutor.java:818)
Mar 29 13:35:48 mid-mon1 logstash[32268]: io.netty.channel.AbstractChannel$AbstractUnsafe.register(io/netty/channel/AbstractChannel.java:471)
Mar 29 13:35:48 mid-mon1 logstash[32268]: io.netty.channel.SingleThreadEventLoop.register(io/netty/channel/SingleThreadEventLoop.java:87)
Mar 29 13:35:48 mid-mon1 logstash[32268]: io.netty.channel.SingleThreadEventLoop.register(io/netty/channel/SingleThreadEventLoop.java:81)
Mar 29 13:35:48 mid-mon1 logstash[32268]: io.netty.channel.MultithreadEventLoopGroup.register(io/netty/channel/MultithreadEventLoopGroup.java:86)
Mar 29 13:35:48 mid-mon1 logstash[32268]: io.netty.bootstrap.AbstractBootstrap.initAndRegister(io/netty/bootstrap/AbstractBootstrap.java:323)
Mar 29 13:35:48 mid-mon1 logstash[32268]: io.netty.bootstrap.AbstractBootstrap.doBind(io/netty/bootstrap/AbstractBootstrap.java:272)
Mar 29 13:35:48 mid-mon1 logstash[32268]: io.netty.bootstrap.AbstractBootstrap.bind(io/netty/bootstrap/AbstractBootstrap.java:268)
Mar 29 13:35:48 mid-mon1 logstash[32268]: io.netty.bootstrap.AbstractBootstrap.bind(io/netty/bootstrap/AbstractBootstrap.java:253)
Mar 29 13:35:48 mid-mon1 logstash[32268]: org.logstash.tcp.InputLoop.run(org/logstash/tcp/InputLoop.java:87)
Mar 29 13:35:48 mid-mon1 logstash[32268]: jdk.internal.reflect.GeneratedMethodAccessor59.invoke(jdk/internal/reflect/GeneratedMethodAccessor59)
Mar 29 13:35:48 mid-mon1 logstash[32268]: jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(jdk/internal/reflect/DelegatingMethodAccessorImpl.java:43)
Mar 29 13:35:48 mid-mon1 logstash[32268]: java.lang.reflect.Method.invoke(java/lang/reflect/Method.java:566)
Mar 29 13:35:48 mid-mon1 logstash[32268]: org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(org/jruby/javasupport/JavaMethod.java:441)
Mar 29 13:35:48 mid-mon1 logstash[32268]: org.jruby.javasupport.JavaMethod.invokeDirect(org/jruby/javasupport/JavaMethod.java:305)
Mar 29 13:35:48 mid-mon1 logstash[32268]: usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_input_minus_tcp_minus_6_dot_0_dot_6_minus_java.lib.logstash.inputs.tcp.run(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-tcp-6.0.6-java/lib/logstash/inputs/tcp.rb:163)
Mar 29 13:35:48 mid-mon1 logstash[32268]: usr.share.logstash.logstash_minus_core.lib.logstash.java_pipeline.inputworker(/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:405)
Mar 29 13:35:48 mid-mon1 logstash[32268]: usr.share.logstash.logstash_minus_core.lib.logstash.java_pipeline.RUBY$method$inputworker$0$__VARARGS__(usr/share/logstash/logstash_minus_core/lib/logstash//usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb)
Mar 29 13:35:48 mid-mon1 logstash[32268]: usr.share.logstash.logstash_minus_core.lib.logstash.java_pipeline.start_input(/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:396)
Mar 29 13:35:48 mid-mon1 logstash[32268]: org.jruby.RubyProc.call(org/jruby/RubyProc.java:318)
Mar 29 13:35:48 mid-mon1 logstash[32268]: java.lang.Thread.run(java/lang/Thread.java:834)
6

In general this would suggest an attempt to do IO after the netty channel has shut down. I have no idea what would cause that.

7

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.