We're updating the issue view to help you get more done. 

multiline plugin generate multiple @timestamp

Description

I tried to merge a multiline java stack trace log. with this config

logstash.conf

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 input { lumberjack { ... } } filter { grok { match => [ "message", "\[%{TIMESTAMP_ISO8601:java_timestamp}\] %{LOGLEVEL:severity_label} +%{JAVACLASS:java_class} : %{GREEDYDATA:logmessage}", "message", "%{JAVASTACKTRACEPART}", "message", "%{JAVACLASS:java_class}Exception(: %{GREEDYDATA:logmessage})?" ] } multiline { pattern => "^\[.*\]" negate => true # Not start with [TIMESTAMP] what => "previous" } date { match => [ "java_timestamp", "YYYY-MM-dd HH:mm:ss,SSS"] } output { stdout { codec => rubydebug } elasticsearch { cluster => foo template_overwrite => true } }

Logstash terminated with this error message:

stderr

1 2 3 4 5 6 7 8 9 10 11 NoMethodError: undefined method `tv_sec' for #<Array:0x1c9c8288> sprintf at /opt/logstash/lib/logstash/event.rb:223 gsub at org/jruby/RubyString.java:3041 sprintf at /opt/logstash/lib/logstash/event.rb:209 receive at /opt/logstash/lib/logstash/outputs/elasticsearch.rb:324 handle at /opt/logstash/lib/logstash/outputs/base.rb:86 initialize at (eval):176 call at org/jruby/RubyProc.java:271 output at /opt/logstash/lib/logstash/pipeline.rb:266 outputworker at /opt/logstash/lib/logstash/pipeline.rb:225 start_outputs at /opt/logstash/lib/logstash/pipeline.rb:152

AND

stdout

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 { "message" => [ [ 0] "[2014-03-21 10:27:28,623] WARN com.google.gerrit.sshd.GerritServerSession : Exception caught", [ 1] "java.io.IOException: Connection reset by peer", [ 2] "\tat sun.nio.ch.FileDispatcherImpl.read0(Native Method)", [ 3] "\tat sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)", [ 4] "\tat sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)", [ 5] "\tat sun.nio.ch.IOUtil.read(IOUtil.java:197)", [ 6] "\tat sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:379)", [ 7] "\tat org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:273)", [ 8] "\tat org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:44)", [ 9] "\tat org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:690)", [10] "\tat org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:664)", [11] "\tat org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:653)", [12] "\tat org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:67)", [13] "\tat org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1124)", [14] "\tat org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)", [15] "\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)", [16] "\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)", [17] "\tat java.lang.Thread.run(Thread.java:724)" ], "@version" => "1", "@timestamp" => [ [0] "2014-03-21T09:32:54.061Z", [1] "2014-03-21T09:32:54.062Z", [2] "2014-03-21T09:32:54.063Z", [3] "2014-03-21T09:32:54.064Z", [4] "2014-03-21T09:32:54.065Z" ], "file" => "/srv/tomcat/logs/catalina.out", "host" => "seldlnx119", "offset" => [ [ 0] "22706154", [ 1] "22706248", [ 2] "22706294", [ 3] "22706349", [ 4] "22706412", [ 5] "22706472", [ 6] "22706516", [ 7] "22706582", [ 8] "22706664", [ 9] "22706745", [10] "22706847", [11] "22706952", [12] "22707057", [13] "22707164", [14] "22707276", [15] "22707360", [16] "22707444", [17] "22707528" ], "type" => "java_error", "tags" => [ [0] "multiline" ] }

As you can see there are multiple @timestamp in the event which will be send to elasticsearch. This is wired. I think ES cloud not handle it and quit. I Also tried to remove the @timestamp field with mutate before I "date" it. But the field still there. I don't know if this is the default behavior of multiline plugin to keep all timestamp.

Environment

None

Status

Assignee

Colin Surprenant

Reporter

yuanl

Fix versions

Affects versions

1.4.0

Priority