Elapsed Time Filter for calculating session Duration (elapsed_time is very big)

Elastic Stack Logstash
#1

Hello folks,

I am using Elapsed Filter Plugin for calculating the time between start_session and session_timeout events in my logs.

Here are some events with Timestamps

[27/Apr/2015:10:41:45 -0500] 1 ENG NORMAL TOUCH START_SESSION
[27/Apr/2015:10:41:45 -0500] 1 ENG NORMAL TOUCH DISPLAY_LANGUAGE_SELECT
[27/Apr/2015:10:43:50 -0500] 1 ENG NORMAL TOUCH SESSION_TIMEOUT

Now my elapsed filter configuration looks something like this

if [event] == "START_SESSION" {
mutate { add_tag => ["taskStarted"] }
} else if [event] == "SESSION_TIMEOUT" {
mutate { add_tag => ["taskTerminated"] }
}
elapsed {
start_tag => "taskStarted"
end_tag => "taskTerminated"
unique_id_field => "sessionID"
#timeout => 10000
new_event_on_match => false
}

Now I see these outputs in the stdout with the session timeout event

{
"message" => "[27/Apr/2015:10:43:50 -0500] 1 ENG NORMAL TOUCH SESSION_TIMEOUT ",
"@timestamp" => "2015-04-27T15:43:50.000Z",
"timestamp" => "27/Apr/2015:10:43:50 -0500",
"sessionID" => "1",
"tags" => [
[0] "taskTerminated",
[1] "elapsed",
[2] "elapsed.match"
],
"elapsed.time" => 15478784.435,
"elapsed.timestamp_start" => "2015-04-27T15:41:45.000Z"
}

Now I see this elapsed.time = 15478784.435 which is ideally from the doucmentation is in seconds. But if you calculate the actual time between timestamps of the start and timeout events show above it should be just 125 secs.

Could someone pls explain what's going on here and what's 15478784.435 number?

Thanks

#2

Hello,

Anybody can throw some light on this please?

Thanks

#3

Anyone? pls give this a try

#4

could somebody help out on this one

#5

Did somebody tried elapsed filter?

#6

I am not so into Ruby but i looked at the source of elapsed. The following snippet:

The method is invoked by LogStash every 5 seconds.

def flush()
expired_elements = []
@mutex.synchronize do
increment_age_by(5)
expired_elements = remove_expired_elements()
end
return create_expired_events_from(expired_elements)
end

needs to be (imoo):

The method is invoked by LogStash every 5 seconds.

def flush()
expired_elements = []
increment_age_by(5)
@mutex.synchronize do
expired_elements = remove_expired_elements()
end
return create_expired_events_from(expired_elements)
end

otherwise the elapsed time for every element/event gets increased 5 secs the number of elements/events times. So "increment_age_by(5)"needs to be outside the loop!

#7

Adding to it!
Adding to my previous answer/comment, here is the increment_age_by function:

private
def increment_age_by(seconds)
@start_events.each_pair do |key, element|
element.age += seconds
end
end

It looks like it is incrementing for every key, and for every key is already the case in the loop in my previous comment.

#8