Elapsed filter ends in "elapsed_end_without_start"

[ajayraghuraj]

elapsed filter ends in "elapsed_end_without_start". I am running on a VM with 1 vCPU . How do I get over this problem ?
cpu cores : 1

/usr/share/logstash/bin/logstash --path.settings /etc/logstash --path.config /etc/logstash/conf.d/test3

{
"sequence" => 0,
"system" => {
"syslog" => {
"hostname" => "ROUTERNAME",
"program" => "51333",
"message" => "May 27 16:19:03.071: %LINEPROTO-5-UPDOWN: Line protocol on Interface Tunnel104, changed state to down",
"timestamp" => "May 28 00:19:03"
}
},
"@timestamp" => 2019-05-27T16:19:03.000Z,
"syslog_timestamp" => "May 27 16:19:03.071",
"@version" => "1",
"fingerprint" => 1590068521,
"host" => "centos6_vm_4",
"messageID" => "51333-1590068521",
"syslog_message" => "%LINEPROTO-5-UPDOWN: Line protocol on Interface Tunnel104, changed state to down",
"message" => "May 28 00:19:03 ROUTERNAME 51333: May 27 16:19:03.071: %LINEPROTO-5-UPDOWN: Line protocol on Interface Tunnel104, changed state to down",
"tags" => [
[0] "tunDOWN"
]
}
{
"sequence" => 0,
"system" => {
"syslog" => {
"hostname" => "ROUTERNAME",
"program" => "51340",
"message" => "May 27 16:19:33.075: %LINEPROTO-5-UPDOWN: Line protocol on Interface Tunnel104, changed state to up",
"timestamp" => "May 28 00:19:33"
}
},
"@timestamp" => 2019-05-27T16:19:33.000Z,
"syslog_timestamp" => "May 27 16:19:33.075",
"@version" => "1",
"fingerprint" => 2154331236,
"host" => "centos6_vm_4",
"messageID" => "51340-2154331236",
"syslog_message" => "%LINEPROTO-5-UPDOWN: Line protocol on Interface Tunnel104, changed state to up",
"message" => "May 28 00:19:33 ROUTERNAME 51340: May 27 16:19:33.075: %LINEPROTO-5-UPDOWN: Line protocol on Interface Tunnel104, changed state to up",
"tags" => [
[0] "tunUP",
[1] "elapsed_end_without_start"
]
}

[pastechecker (Charlie)]

@ajayraghuraj

elapsed_end_without_star

Have a look on this post: Problem with elapsed plugin - #3 by pantheo
Can you add your configuration file?

[ajayraghuraj]

here is the configuration file

input {
generator {
lines => ['May 28 00:19:03 ROUTERNAME 51333: May 27 16:19:03.071: %LINEPROTO-5-UPDOWN: Line protocol on Interface Tunnel104, changed state to down',
'May 28 00:19:33 ROUTERNAME 51340: May 27 16:19:33.075: %LINEPROTO-5-UPDOWN: Line protocol on Interface Tunnel104, changed state to up']
count => 1
}
}

filter {

grok {
match => { "message" => ["%{SYSLOGTIMESTAMP:[system][syslog][timestamp]} %{SYSLOGHOST:[system][syslog][hostname]} %{DATA:[system][syslog][program]}(?:[%{POSINT:[system][syslog][pid]}])?: %{GREEDYDATA:[system][syslog][message]}"] }
}

date {
match => [ "[system][syslog][timestamp]", "MMM d HH:mm:ss", "MMM dd HH:mm:ss" ]
}

Compute Unique message ID

fingerprint {
source => "[system][syslog][message]"
method => "MURMUR3"
}
mutate { add_field => { "messageID" => "%{[system][syslog][program]}-%{fingerprint}" } }

Get start and end tags for events

if [system][syslog][message] =~ "Line protocol on Interface Tunnel[0-9]+, changed state to down" {
mutate { add_tag => [ "tunnelDOWN" ] }
}
if [system][syslog][message] =~ "Line protocol on Interface Tunnel[0-9]+, changed state to up" {
mutate { add_tag => [ "tunnelUP" ] }
}

Measure the execution time between events

elapsed {
start_tag => "tunnelDOWN"
end_tag => "tunnelUP"
unique_id_field => "messageID"
new_event_on_match => true
}

}

output {
stdout { codec => rubydebug { metadata => true} }
}