Unable to get time difference with ruby in logstash

[zubair_aftab]

I have 2 time fields Time1 and Time2. I want to get there difference but getting error "Ruby exception occurred: undefined method `-' for nil:NilClass".

Below is the code. what is wrong in it??

`
if [Time1] {
date{
match=>["Time1","dd-MM-YYYY HH:mm:ss.SSS"]
target => "Time1"
timezone => "Asia/Riyadh"
}
}

if [Time2] {
date{
match=>["Time2","dd-MM-YYYY HH:mm:ss.SSS"]
target => "Time2"
timezone => "Asia/Riyadh"
}
}

ruby {
init => "require 'time'"
code => "
subtract = event.get('Time2') - event.get('Time1')
event.set('timediff',subtract)
"
}

`

[Badger]

@zubair_aftab

"Ruby exception occurred: undefined method `-' for nil:NilClass".

That means you have events where [Time2] does not exist. Test it before using it

time2 = event.get("Time2")
time1 = event.get("Time1")
if time1 and time2
    subtract = ...

[zubair_aftab]

11-05-2022,15:01:59.000,420032332630033,0,919890783809
11-05-2022,16:02:00.000,420032332630033,0,919890783809

This is content of the log file. I am calculating time difference for the same field imsi (420032332630033).
For this purpose i use the following in output so that both time1 and time2 come in the same document.

document_id => "%{imsi}"
action => "update"
doc_as_upsert => "true"

i create fields time1=11-05-2022 15:01:59.000 and time2=11-05-2022 16:02:00.000.
These are properly coming in the output. There is no reason it should be nilClass.
Am i doing anything wrong??

[Badger]

@zubair_aftab

Am i doing anything wrong??

Yes, unless you use an aggregate filter to connect them, the two lines of the log file are separate events, so each only has one time.

subtract = event.get('Time2') - event.get('Time1')

will be either "11-05-2022,15:01:59.000" - nil, which will return the string unchanged, or nil - "11-05-2022,16:02:00.000", which will throw that exception.

[zubair_aftab]

Oh so that's the issue.
Can u guide me on that cause I didn't use aggregate before.
I want to take time difference for lines having same imsi field value.

[Badger]

You should go through the documentation to understand the limitations.

If the other fields after [imsi] are common to the two lines then you could use

    csv {
        columns => [ "[@metadata][date]", "[@metadata][time]", "imsi", "a", "b" ]
        add_field => { "[@metadata][ts]" => "%{[@metadata][date]} %{[@metadata][time]}" }
    }
    date { match => [ "[@metadata][ts]", "dd-MM-YYYY HH:mm:ss.SSS" ] }
    aggregate {
        task_id => "%{imsi}"
        code => '
            map["a"] ||= event.get("a")
            map["b"] ||= event.get("b")
            t = event.get("@timestamp")
            if !map["start"]
                map["start"] = t
                map["@timestamp"] = t
            else
                map["end"] = t
            end
            event.cancel
        '
        push_map_as_event_on_timeout => true
        timeout_task_id_field => "imsi"
        timeout => 9
        timeout_code => '
            event.set("delta", event.get("end").to_f - event.get("start").to_f)
        '
    }

which will produce

         "a" => "0",
         "b" => "919890783809",
"@timestamp" => 2022-05-11T19:01:59Z,
     "delta" => 3601.0,
     "start" => 2022-05-11T19:01:59Z,
  "@version" => "1",
       "end" => 2022-05-11T20:02:00Z,
      "imsi" => "420032332630033"

when the timeout fires.

[zubair_aftab]

Thanks a lot @Badger
I have tested it with few additions and working fine.
There is just 1 issue now. For below input where we see 2 START/CLOSE transactions for same IMSI, the output is taking the 2nd START and 2nd CLOSE to give only 1 output, whereas it should give 2 outputs for 2 transactions.
How to handle this?

11-05-2022,16:01:59.000,420032332630033,0,919890783809,0,0,0,SS7,1,1652274119658,0,1,SS7_TXN_START
11-05-2022,16:02:05.000,420032332630033,0,919890783809,0,0,0,SS7,1,1652273791545,0,3,SS7_TXN_CLOSE
11-05-2022,16:02:10.000,420032332630033,0,919890783809,0,0,0,SS7,1,1652274119658,0,1,SS7_TXN_START
11-05-2022,16:02:15.000,420032332630033,0,919890783809,0,0,0,SS7,1,1652273791545,0,3,SS7_TXN_CLOSE

I edited the code as below but it gives 1 output only

if event.get("txn_type") == "SS7_TXN_START"
map["start"] = t
map["@timestamp"] = t
end
if event.get("txn_type") == "SS7_TXN_CLOSE"
map["end"] = t
end

[Badger]

If you have start and end events you should use something more like Example 1 than the Example 3 I suggested.