Hi there,
I've searched the forum but it seems to be such a fundamental part of the elapsed time filter that no one else seems to have had the problem, but..... has the keep_start_event tag in this filter ever not been obeyed for anyone?
I have a situation whereby my request trail has multiple start events (all with the same unique id) but when the eventual end event is found, the elapsed time is being worked out as the last time the start_event was seen, not the first! The default is that it takes the first, correct?
My config is as below:
if [blah.message] == "Booked" {
mutate {
add_tag => ["journeyEnded"]
}
} else if [blah.operationName] == "GetProduct" {
mutate {
add_tag => ["journeyStarted"]
}
}
elapsed {
start_tag => "journeyStarted"
end_tag => "journeyEnded"
unique_id_field => "trace"
timeout => 2700
new_event_on_match => false
}
A list of my requests are as below
{
"timestamp":"2018-09-28T13:53:45.006+01:00",
"level":"INFO",
"service":"product",
"trace":"00000000374f3f41",
"span":"000000000f675b75",
"blah.operationName":"GetProduct",
"blah.value":"",
"blah.serviceMetric":"",
"blah.geoarea":"",
"blah.authcode":"",
"blah.pupilId":"",
"blah.lessonDateTime":"",
"blah.exceptionMessage":"",
"blah.message":"Operation started for: GetProduct"
}
tags OPP-VM, beats_input_codec_plain_applied, journeyStarted
{
"timestamp":"2018-09-28T14:00:31.874+01:00",
"level":"INFO",
"service":"product",
"trace":"00000000374f3f41",
"span":"6725ef0be7d66586",
"blah.operationName":"GetProduct",
"blah.value":"",
"blah.serviceMetric":"",
"blah.geoarea":"",
"blah.authcode":"",
"blah.pupilId":"",
"blah.lessonDateTime":"",
"blah.exceptionMessage":"",
"blah.message":"Operation started for: GetProduct"
}
tags OPP-VM, beats_input_codec_plain_applied, journeyStarted
{
"timestamp":"2018-09-28T14:01:54.882+01:00",
"level":"INFO",
"service":"product",
"trace":"00000000374f3f41",
"span":"ea0750a098f45aa7",
"blah.operationName":"GetProduct",
"blah.value":"",
"blah.serviceMetric":"",
"blah.geoarea":"",
"blah.authcode":"",
"blah.pupilId":"",
"blah.lessonDateTime":"",
"blah.exceptionMessage":"",
"blah.message":"Operation started for: GetProduct"
}
tags OPP-VM, beats_input_codec_plain_applied, journeyStarted
{
"timestamp":"2018-09-28T14:01:56.317+01:00",
"level":"INFO",
"service":"booking",
"trace":"00000000374f3f41",
"span":"00000000006df1fa",
"blah.operationName":"",
"blah.value":"1001",
"blah.serviceMetric":"Booked",
"blah.geoarea":"",
"blah.authcode":"",
"blah.pupilId":"",
"blah.lessonDateTime":"",
"blah.exceptionMessage":"",
"blah.message":"Booked"
}
tags OPP-VM, beats_input_codec_plain_applied, journeyEnded, elapsed, elapsed_match
elapsed_timestamp_start September 28th 2018, 14:01:54.882
elapsed_time 1.435
(Using version 6.4 of Logstash)
