Unable to perform airthmetic operations in ruby using logstash pipeline

Hi guys,
I am facing an issue where i am trying to perform an airthmetic operation using ruby but in at the field section i am getting the same value not the subtracted value.

event.set('[d]', (event.get('[b]').to_f) - (event.get('[a]').to_f))
a = 5, b =4

expected output
d = 1

actual output
d =5,
d =4

You need to provide more information, because

input { generator { count => 1 lines => [ '' ] } }

output { stdout { codec => rubydebug { metadata => false } } }
filter {
   mutate { add_field => { "[a]" => "4" "[b]" => "5" } }
    ruby { code => 'event.set("[d]", (event.get("[b]").to_f) - (event.get("[a]").to_f))' }
}

produces

         "d" => 1.0,

I tried this but still i am getting b = 5 and a = -4

Here's my config file

input {
file {
path => "C:/data/*.txt"
start_position => "beginning"
}
}

filter {
grok{
match => {
"message"=> ["%{YEAR:year}-%{MONTHNUM:month}-%{INT:day}\s%{HOUR:hour}:%{MINUTE:minute}:%{SECOND:second}\s%{WORD:event_type}\s%{DATA:Transaction_Number}\s%{LOGLEVEL:LOGLEVEL}\s\s+%{JAVACLASS:error_file}\s%{DATA:hash_type}TransactionId\s-\s%{NUMBER:TransactionId:INT}+,+\sTransactionReferenceId\s-\s%{NUMBER:TransactionReferenceId:INT}+]+%{GREEDYDATA:msgbody}"]
}
}
mutate {
add_field => { "date" => "%{year}-%{month}-%{day} %{hour}:%{minute}:%{second}"
}
}
mutate{
convert=>
{"[hour]" => "integer"
"[minute]" => "integer"
"[second]" => "integer" }
}
}
filter {
json {
source => "msgbody"
}
}
filter{
if [messageType] == "CReq" {
mutate{
add_field => {
"MsgType" => "%{messageType}"
"Creq_sec" => "%{second}"
}
convert=>
{"[Creq_sec]" => "integer"
}
}
}
else if [messageType] == "CRes" {
mutate{
add_field => {
"MsgType" => "%{messageType}"
"Cres_sec" => "%{second}"
}
convert=>
{"[Cres_sec]" => "integer"
}
}
}
else if [messageType] == "AReq" {
mutate{
add_field => {
"MsgType" => "%{messageType}"
"Areq_sec" => "%{second}"
}
}
}
else if [messageType] == "ARes" {
mutate{
add_field => {
"MsgType" => "%{messageType}"
"Ares_sec" => "%{second}"
}
}
}
else if [messageType] == "RReq" {
mutate{
add_field => {
"MsgType" => "%{messageType}"
"Rreq_sec" => "%{second}"
}
convert=>
{"[Rreq_sec]" => "integer"
}
}
}
else if [messageType] == "RRes" {
mutate{
add_field => {
"MsgType" => "%{messageType}"
"Rres_sec" => "%{second}"
}
convert=>
{"[Rres_sec]" => "integer"
}
}
}
else if [messageType] == "WS OTP Request" {
mutate{
add_field => {
"MsgType" => "%{messageType}"
}
}
}
else if [messageType] == "WS OTP Responce" {
mutate{
add_field => {
"MsgType" => "%{messageType}"
}
}
}
}
filter{
if [MsgType] == "AReq" {
mutate{
add_field => {
"AReq_Transaction_id" => "%{TransactionId}"
}
}
}
if [MsgType] == "ARes" {
mutate{
add_field => {
"ARes_Transaction_id" => "%{TransactionId}"
}
}
}
if [MsgType] == "CReq" {
mutate{
add_field => {
"CReq_Transaction_id" => "%{TransactionId}"
}
}
}
if [MsgType] == "CRes" {
mutate{
add_field => {
"CRes_Transaction_id" => "%{TransactionId}"
}
}
}
if [MsgType] == "RReq" {
mutate{
add_field => {
"RReq_Transaction_id" => "%{TransactionId}"
}
}
}
if [MsgType] == "RRes" {
mutate{
add_field => {
"RRes_Transaction_id" => "%{TransactionId}"
}
convert=>
{"[RRes_Transaction_Id]" => "integer"
}
}
}
}
filter {
mutate {
copy => {
"AReq_Transaction_id" => "AReq_Transaction_Id"
"ARes_Transaction_id" => "ARes_Transaction_Id"
"RReq_Transaction_id" => "RReq_Transaction_Id"
"RRes_Transaction_id" => "RRes_Transaction_Id"
"Areq_sec" => "Areq_Sec"
"Ares_sec" => "Ares_Sec"
"Rreq_sec" => "Rreq_Sec"
"Rres_sec" => "Rres_Sec"
}
}
}
filter{
mutate{
convert=>
{
"[AReq_Transaction_Id]" => "string"
"[ARes_Transaction_Id]" => "string"
"[RReq_Transaction_Id]" => "string"
"[RRes_Transaction_Id]" => "string"
"[Areq_Sec]" => "integer"
"[Ares_Sec]" => "integer"
"[Rreq_Sec]" => "float"
"[Rres_Sec]" => "float"
}
}
}

filter {
ruby {
code =>'
a = event.get("[Areq_Sec]").to_f
b = event.get("[Ares_Sec]").to_f
c = b-a;
event.set("[req_sec]", c)
'
}
}

filter{
mutate{
remove_field => ["message","@version","event","@timestamp","original","host","log","tags","day","month","year","time"]
}
}

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

Can you format your post to use the Preformatted text option? The </> button, it makes it much more easier to read.

Also, can you share a sample of your message so your pipeline could be replicated?

From what you shared, it seems that you have some logic wrong in it.

Your ruby code is doing this:

filter {
    ruby {
        code =>'
        a = event.get("[Areq_Sec]").to_f
        b = event.get("[Ares_Sec]").to_f
        c = b-a;
        event.set("[req_sec]", c)
        '
    }
}

It is subtracting the fields Areq_Sec and Ares_Sec.

But from your pipeline those fields are not present in the same message:

else if [messageType] == "AReq" {
    mutate{
        add_field => {
            "MsgType" => "%{messageType}"
            "Areq_sec" => "%{second}"
        }
    }
}
else if [messageType] == "ARes" {
    mutate{
        add_field => {
            "MsgType" => "%{messageType}"
            "Ares_sec" => "%{second}"
        }
    }
}

So, when you have a message with messageType equals to AReq, you will have the field Areq_Sec, but you will not have the field Ares_Sec, and when the messageType is ARes, you will have Ares_Sec, but not Areq_Sec.

Your ruby code will always have one of the terms equals to zero.

Can you provide more context about your message and what you want to achieve?

1 Like

I am getting the values perfectly for Areq_Sec and Ares_Sec. The problem I am facing is while doing the airthmetic operation using the ruby filter. It's not giving me the desired output.

For example :-
Its giving me the output like
Areq_Sec = 4, Ares_Sec = 5
c = b - a
desired output = 1

actual output
req_sec = 5 and req_sec = -4

Your ruby filter seems to be trying to calculate the difference between Areq_Sec and Ares_Seq. I guess these are timings or timestamps for requests and responses, and you want to find how long a request took.

There are multiple issues here.

The ruby filter tries to subtract [Areq_Sec] from [Ares_Sec] to find the difference between the timing of the request and response. However, those fields are in different events, and unless you configure a filter that combines them, each event is independent. If a field does not exist then the event.get will return nil and .to_f will return zero. This is why your two events get 0-4 (-4) and 5-0 (5).

In your third filter section, for each [messageType] you try to do mutate+convert as well as mutate+add_field. You cannot convert a field that you add in the same mutate. The order of mutate operations is documented, but nobody tells you that event decoration (add_field/tag, remove_field/tag), if done, is always done last.

Doing the [Areq_sec] to [Areq_Sec] copy and convert has no obvious purpose. You are doing a .to_f in the ruby filter, so it is not required in logstash (but I understand that the systems you are stashing data in may require it).

If your messages all have a transaction id then it should be fairly simple to do an aggregate filter that merges these field for log entries that refer to the same request.

I tried with the aggregate filter but I am unable to find the desired output. There's a problem while using the aggregate filter. A single transaction_id contains multiple request and response. I want to calculate the request and response for two events like Areq and Ares. In aggregate it will calculate the seconds for the whole request and response for that particular transaction_id. Same with the elapsed filter

If you use pipeline.workers 1 and pipline.ordered it may be possible to do that, but without seeing the log file or a very detailed specification of it by you we cannot guess how.

2023-02-22 03:58:04 MUT 795521455 INFO AuditLogService ---- [TransactionId - 2305315306634431865, TransactionReferenceId - 2305315306634431865]{"messageType":"AReq"}
2023-02-22 03:58:05 MUT 795522299 INFO AuditLogService ---- [TransactionId - 2305315306634431865, TransactionReferenceId - 2305315306634431865]{"messageType":"ARes"}
2023-02-22 04:00:11 MUT 795649016 INFO AuditLogService ---- [TransactionId - 2305315306634431865, TransactionReferenceId - 2305315306634431865]{"messageType":"RReq"}
2023-02-22 04:00:13 MUT 795650422 INFO AuditLogService ---- [TransactionId - 2305315306634431865, TransactionReferenceId - 2305315306634431865]{"messageType":"RRes"}

This is the log file for the above given configuration. The messageType will be different for that particular transaction id.

You could try this. Note that when doing a numeric conversion in grok the suffix to the field name has to be ":int", not ":INT". You must set pipeline.workers to 1 and pipeline.ordered must evaluate to true in order to use aggregate.

    grok{
        pattern_definitions => { "customDate" => "%{YEAR}-%{MONTHNUM}-%{INT}\s%{HOUR}:%{MINUTE}:%{SECOND}\s%{WORD}" }
        match => { "message"=> "%{customDate:[@metadata][ts]}\s%{DATA:Transaction_Number}\s%{LOGLEVEL:LOGLEVEL}\s+%{JAVACLASS:error_file}\s%{DATA:hash_type}TransactionId\s-\s%{NUMBER:TransactionId:int}+,+\sTransactionReferenceId\s-\s%{NUMBER:TransactionReferenceId:int}+]+%{GREEDYDATA:[@metadata][msgbody]}" }
    }
    mutate { gsub => [ "[@metadata][ts]", "MUT", "Etc/GMT-4" ] }
    date { match => [ "[@metadata][ts]", "YYYY-MM-dd HH:mm:ss ZZZ" ] }
    json { source => "[@metadata][msgbody]" }
    aggregate {
        task_id => "%{TransactionId}"
        code => '
            begin
                type = event.get("messageType")
                # type1 will be A/C/R/WS OPT
                type1 = type.gsub(/Re[qs].*/, "").strip
                # type2 will be an array containg Req or Res
                type2 = type.match(/Re[qs]/)
                if type2[0] == "Req"
                    map[type1] = event.get("@timestamp").to_f
                else
                    event.set("req_sec", event.get("@timestamp").to_f - map[type1])
                end
            rescue
            end
        '
    }

Thank you @Badger! It worked

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.