Splunk Search
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
Ask a Question
Solved! Jump to solution

calculate send response duration

indeed_2000
Motivator
‎11-02-2021 01:14 AM

Hi

I have log like below need to extract "Send&Receive duration" and "send that has not respond".

 

this is send
2021-07-15 00:00:01,800 INFO CUST.InAB-ServerApp-1234567 [MyService] Packet Processed: A[50] B[0000211]

this is send
2021-07-15 00:00:01,893 INFO ABCD.DaQW-ParityGQQ-1231234 [MyService] Packet Processed: A[60] B[0000465]

this is send

2021-07-15 00:00:01,894 INFO MNBV.ZaQW-ChatCXZ-1478523 [MyService] Packet Processed: A[70] B[0000369]

this is recieve
2021-07-15 00:00:11,719 INFO CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567 [MyService] Normal Packet Received: A[55] B[0000211]

this is recieve
2021-07-15 00:00:11,720 INFO EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234 [MyService] Normal Packet Received: A[65] B[0000456]

   

 

 

here is what happen:

step1: find send id 

CUST.InAB-ServerApp-1234567

ABCD.DaQW-ParityGQQ-1231234

MNBV.ZaQW-ChatCXZ-1478523

 

step2: find response id 

CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567 

EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234

 

FYI: related events structure like this:

Send: CUST.InAB-ServerApp-1234567

Recieve: CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567

 

 

step3: check this condition  A+5 AND B=B to match related send receive.

2021-07-15 00:00:01,800 INFO CUST.InAB-ServerApp-1234567 [MyService] Packet Processed: A[50] B[0000211]

2021-07-15 00:00:11,719 INFO CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567 [MyService] Normal Packet Received: A[55] B[0000211]

 

 

step4: finally show id that not have receive, and duration of each send&receive

 

expected Output:

id                                                                                                                                                                                 status

MNBV.ZaQW-ChatCXZ-1478523                                                                                                   no receive

CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567                               9,919

EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234                            9,826

 

Any idea?

Thanks

Labels (5)
0 Karma
Reply
1 Solution
Solved! Jump to solution
Solution

tread_splunk
Splunk Employee
Splunk Employee
‎11-04-2021 06:19 AM

@indeed_2000 

Its not very pretty.  And requires extensive testing.

 

| makeresults
| eval temp="2021-07-15 00:00:01,800 INFO CUST.InAB-ServerApp-1234567 [MyService] Normal Packet Received: A[50] B[0000211]
2021-07-15 00:00:01,800 INFO CUST.InAB-ServerApp-1234567 [MyService] Packet Processed: A[50] B[0000211]
2021-07-15 00:00:11,719 INFO CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567 [MyService] Normal Packet Received: A[55] B[0000211]
2021-07-15 00:00:11,719 INFO CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567 [MyService] Packet Processed: A[55] B[0000211]
2021-07-15 00:00:01,894 INFO MNBV.ZaQW-ChatCXZ-1478523 [MyService] Normal Packet Received: A[70] B[0000369]
2021-07-15 00:00:01,894 INFO MNBV.ZaQW-ChatCXZ-1478523 [MyService] Packet Processed: A[70] B[0000369]
2021-07-15 00:00:01,893 INFO ABCD.DaQW-ParityGQQ-1231234 [MyService] Normal Packet Received: A[60] B[0000465]
2021-07-15 00:00:01,893 INFO ABCD.DaQW-ParityGQQ-1231234 [MyService] Packet Processed: A[60] B[0000456]
2021-07-15 00:00:11,720 INFO EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234 [MyService] Normal Packet Received: A[65] B[0000456]
2021-07-15 00:00:11,720 INFO EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234 [MyService] Packet Processed: A[65] B[0000456]
"
| makemv tokenizer="(.*)\n" temp
| mvexpand temp
| rex field=temp "^(?<timestamp>.{23}) INFO (?<customer>.*) \[MyService\] (?<status>.*): A\[(?<Acode>.*)\] B\[(?<Bcode>.*)\]"
| fields - temp
| rex field=customer "_(?<customer2>.*)"
| eval customer2=coalesce(customer2,customer), customer=if(customer=customer2,null(),customer)
| eval sendTime=if(status="Packet Processed",strptime(timestamp,"%Y-%m-%d %H:%M:%S,%3Q"),null()), receiveTime=if(status="Normal Packet Received",strptime(timestamp,"%Y-%m-%d %H:%M:%S,%3Q"),null())
| eval AcodeSend=if(status="Packet Processed",Acode,null()),BcodeSend=if(status="Packet Processed",Bcode,null()),AcodeReceive=if(status="Normal Packet Received",Acode,null()),BcodeReceive=if(status="Normal Packet Received",Bcode,null())
| eval AcodeReceiveLookFor=AcodeSend+5,acr=coalesce(AcodeReceive,AcodeReceiveLookFor)
| fields - Acode _time timestamp status AcodeReceiveLookFor
| stats values(*) as *,count by customer2,acr,Bcode
| eval duration=receiveTime-sendTime , customer=coalesce(customer,customer2)
| eval status=case(isnull(AcodeSend),"No Send",isnull(AcodeReceive),"No receive")
| eventstats max(duration) as duration by customer2
| where count=2 OR (status="No receive" AND isnull(duration))
| eval status=coalesce(status,duration)
| table customer status

View solution in original post

Tags (1)
Reply
Solved! Jump to solution

tread_splunk
Splunk Employee
Splunk Employee
‎11-02-2021 08:29 AM

Most of this is fabricating data.

| makeresults 
| eval temp="2021-07-15 00:00:01,800 INFO CUST.InAB-ServerApp-1234567 [MyService] Packet Processed: A[50] B[0000211]
2021-07-15 00:00:01,893 INFO ABCD.DaQW-ParityGQQ-1231234 [MyService] Packet Processed: A[60] B[0000465]
2021-07-15 00:00:01,894 INFO MNBV.ZaQW-ChatCXZ-1478523 [MyService] Packet Processed: A[70] B[0000369]
2021-07-15 00:00:11,719 INFO CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567 [MyService] Normal Packet Received: A[55] B[0000211]
2021-07-15 00:00:11,720 INFO EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234 [MyService] Normal Packet Received: A[65] B[0000456]
" 
| makemv tokenizer="(.*)\n" temp 
| mvexpand temp 
| rex field=temp "^(?<timestamp>.{23}) INFO (?<customer>.*) \[MyService\] (?<status>.*): (?<Acode>.*) (?<Bcode>.*)" 
| fields - temp 
| rex field=customer "_(?<customer2>.*)" 
| eval customer=coalesce(customer2,customer) 
| fields - customer2 
| eval startTime=if(status="Packet Processed",strptime(timestamp,"%Y-%m-%d %H:%M:%S,%3Q"),null()) 
| eval endTime=if(status="Normal Packet Received",strptime(timestamp,"%Y-%m-%d %H:%M:%S,%3Q"),null()) 
| stats values(startTime) as startTime, values(endTime) as endTime by customer 
| eval status=endTime-startTime 
| fields - startTime, endTime 
| fillnull value="no receive" status
0 Karma
Reply
Solved! Jump to solution

indeed_2000
Motivator
‎11-02-2021 09:13 AM

Thanks for answer,

here is the output:

MNBV.ZaQW-ChatCXZ-14785239.827000
CUST.InAB-ServerApp-12345679.919000
MNBV.ZaQW-ChatCXZ-1478523no receive

 

here is the expected output:

MNBV.ZaQW-ChatCXZ-1478523no receive
CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-12345679,919
EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234  9,826

 

FYI:step3 missed, not check condition.

 

any idea?

 Thanks 

0 Karma
Reply
Solved! Jump to solution

tread_splunk
Splunk Employee
Splunk Employee
‎11-02-2021 01:50 PM

@indeed_2000

| makeresults 
| eval temp="2021-07-15 00:00:01,800 INFO CUST.InAB-ServerApp-1234567 [MyService] Packet Processed: A[50] B[0000211]
2021-07-15 00:00:01,893 INFO ABCD.DaQW-ParityGQQ-1231234 [MyService] Packet Processed: A[60] B[0000465]
2021-07-15 00:00:01,894 INFO MNBV.ZaQW-ChatCXZ-1478523 [MyService] Packet Processed: A[70] B[0000369]
2021-07-15 00:00:11,719 INFO CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567 [MyService] Normal Packet Received: A[55] B[0000211]
2021-07-15 00:00:11,720 INFO EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234 [MyService] Normal Packet Received: A[65] B[0000465]
" 
| makemv tokenizer="(.*)\n" temp 
| mvexpand temp 
| rex field=temp "^(?<timestamp>.{23}) INFO (?<customer>.*) \[MyService\] (?<status>.*): A\[(?<Acode>.*)\] B\[(?<Bcode>.*)\]" 
| fields - temp 
| rex field=customer "_(?<customer2>.*)" 
| eval customer2=coalesce(customer2,customer), customer=if(customer=customer2,null(),customer) 
| eval startTime=if(status="Packet Processed",strptime(timestamp,"%Y-%m-%d %H:%M:%S,%3Q"),null()), endTime=if(status="Normal Packet Received",strptime(timestamp,"%Y-%m-%d %H:%M:%S,%3Q"),null()) 
| eval AcodeStart=if(status="Packet Processed",Acode,null()),BcodeStart=if(status="Packet Processed",Bcode,null()),AcodeFinish=if(status="Normal Packet Received",Acode,null()),BcodeFinish=if(status="Normal Packet Received",Bcode,null()) 
| fields - Acode Bcode _time timestamp status 
| stats values(*) as * by customer2 
| eval status=endTime-startTime , customer=coalesce(customer,customer2) 
| fields - startTime, endTime 
| fillnull value="no receive" status 
| where isnull(AcodeFinish) OR (AcodeFinish=AcodeStart+5 AND BcodeStart=BcodeFinish) 
| table customer status
0 Karma
Reply
Solved! Jump to solution

indeed_2000
Motivator
‎11-03-2021 03:42 AM

I try it on small part of log it work perfect but on a large scale I have issue.

here is the line that cause of issue:

 

actually duration between green lines show on table. 

red lines show there is no "receive", because not have second line with condition that I mention A=A+5 AND B=B 

---------------------------------------

this is recieve
2021-07-15 00:00:01,800 INFO CUST.InAB-ServerApp-1234567 [MyService] Normal Packet Received: A[50] B[0000211]

this is send

2021-07-15 00:00:01,800 INFO CUST.InAB-ServerApp-1234567 [MyService] Packet Processed: A[50] B[0000211]

 

this is recieve
2021-07-15 00:00:11,719 INFO CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567 [MyService] Normal Packet Received: A[55] B[0000211]

this is send
2021-07-15 00:00:11,719 INFO CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567 [MyService] Packet Processed: A[55] B[0000211]

----------------------------------------

this is recieve

2021-07-15 00:00:01,894 INFO MNBV.ZaQW-ChatCXZ-1478523 [MyService] Normal Packet Received: A[70] B[0000369]

this is send

2021-07-15 00:00:01,894 INFO MNBV.ZaQW-ChatCXZ-1478523 [MyService] Packet Processed: A[70] B[0000369]

----------------------------------------

this is recieve
2021-07-15 00:00:01,893 INFO ABCD.DaQW-ParityGQQ-1231234 [MyService] Normal Packet Received: A[60] B[0000465]

this is send
2021-07-15 00:00:01,893 INFO ABCD.DaQW-ParityGQQ-1231234 [MyService] Packet Processed: A[60] B[0000465]

this is recieve

2021-07-15 00:00:11,720 INFO EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234 [MyService] Normal Packet Received: A[65] B[0000465]

this is send

2021-07-15 00:00:11,720 INFO EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234 [MyService] Packet Processed: A[65] B[0000465]

 

here is the expected output:

MNBV.ZaQW-ChatCXZ-1478523no receive
CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-12345679,919
EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234  9,826

 

 

 

Any idea?

Thanks

0 Karma
Reply
Solved! Jump to solution

tread_splunk
Splunk Employee
Splunk Employee
‎11-04-2021 02:34 AM

@indeed_2000 

Why is ...

ABCD.DaQW-ParityGQQ-1231234no receive

 

...in the output?

0 Karma
Reply
Solved! Jump to solution

indeed_2000
Motivator
‎11-04-2021 02:59 AM

For more clarification Here is flow:

1-receive request from a source

2-processed request and send to another node

3-receive response from that node

4-send response to source


Need to extract duration between step 2 and 3

sometimes  node doesn’t send response, then step 3,4 missed and flow is incomplete.

 

FYI: you may confused with step 1,2 or 3,4 (send and receive) keyword, but in simple way 1,2 means request received and send to node. 3,4 means receive response and send to source. 

any idea?

 Thanks 

 

0 Karma
Reply
Solved! Jump to solution

tread_splunk
Splunk Employee
Splunk Employee
‎11-04-2021 04:20 AM

@indeed_2000 

Still not sure why...

ABCD.DaQW-ParityGQQ-1231234

no receive

 

...is in the result.  Shouldn't it be the red one? i.e...

2021-07-15 00:00:01,894 INFO MNBV.ZaQW-ChatCXZ-1478523 [MyService] Packet Processed: A[70] B[0000369]

Reply
Solved! Jump to solution

indeed_2000
Motivator
‎11-04-2021 04:59 AM

Sorry it’s typo,  modify that too.

0 Karma
Reply
Solved! Jump to solution
Solution

tread_splunk
Splunk Employee
Splunk Employee
‎11-04-2021 06:19 AM

@indeed_2000 

Its not very pretty.  And requires extensive testing.

 

| makeresults
| eval temp="2021-07-15 00:00:01,800 INFO CUST.InAB-ServerApp-1234567 [MyService] Normal Packet Received: A[50] B[0000211]
2021-07-15 00:00:01,800 INFO CUST.InAB-ServerApp-1234567 [MyService] Packet Processed: A[50] B[0000211]
2021-07-15 00:00:11,719 INFO CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567 [MyService] Normal Packet Received: A[55] B[0000211]
2021-07-15 00:00:11,719 INFO CUST.VqPO-Oracle7-9876543_CUST.InAB-ServerApp-1234567 [MyService] Packet Processed: A[55] B[0000211]
2021-07-15 00:00:01,894 INFO MNBV.ZaQW-ChatCXZ-1478523 [MyService] Normal Packet Received: A[70] B[0000369]
2021-07-15 00:00:01,894 INFO MNBV.ZaQW-ChatCXZ-1478523 [MyService] Packet Processed: A[70] B[0000369]
2021-07-15 00:00:01,893 INFO ABCD.DaQW-ParityGQQ-1231234 [MyService] Normal Packet Received: A[60] B[0000465]
2021-07-15 00:00:01,893 INFO ABCD.DaQW-ParityGQQ-1231234 [MyService] Packet Processed: A[60] B[0000456]
2021-07-15 00:00:11,720 INFO EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234 [MyService] Normal Packet Received: A[65] B[0000456]
2021-07-15 00:00:11,720 INFO EFGH.GaXZ-Carry2-3456789_ABCD.DaQW-ParityGQQ-1231234 [MyService] Packet Processed: A[65] B[0000456]
"
| makemv tokenizer="(.*)\n" temp
| mvexpand temp
| rex field=temp "^(?<timestamp>.{23}) INFO (?<customer>.*) \[MyService\] (?<status>.*): A\[(?<Acode>.*)\] B\[(?<Bcode>.*)\]"
| fields - temp
| rex field=customer "_(?<customer2>.*)"
| eval customer2=coalesce(customer2,customer), customer=if(customer=customer2,null(),customer)
| eval sendTime=if(status="Packet Processed",strptime(timestamp,"%Y-%m-%d %H:%M:%S,%3Q"),null()), receiveTime=if(status="Normal Packet Received",strptime(timestamp,"%Y-%m-%d %H:%M:%S,%3Q"),null())
| eval AcodeSend=if(status="Packet Processed",Acode,null()),BcodeSend=if(status="Packet Processed",Bcode,null()),AcodeReceive=if(status="Normal Packet Received",Acode,null()),BcodeReceive=if(status="Normal Packet Received",Bcode,null())
| eval AcodeReceiveLookFor=AcodeSend+5,acr=coalesce(AcodeReceive,AcodeReceiveLookFor)
| fields - Acode _time timestamp status AcodeReceiveLookFor
| stats values(*) as *,count by customer2,acr,Bcode
| eval duration=receiveTime-sendTime , customer=coalesce(customer,customer2)
| eval status=case(isnull(AcodeSend),"No Send",isnull(AcodeReceive),"No receive")
| eventstats max(duration) as duration by customer2
| where count=2 OR (status="No receive" AND isnull(duration))
| eval status=coalesce(status,duration)
| table customer status
Tags (1)
Reply
Solved! Jump to solution

tread_splunk
Splunk Employee
Splunk Employee
‎11-03-2021 06:47 AM

@indeed_2000 

Your second green pair have different B codes. 465 vs 456.  This is a typo, correct?

Reply
Solved! Jump to solution

indeed_2000
Motivator
‎11-03-2021 06:50 AM

you right, it is a typo, I've edit it.

0 Karma
Reply
Get Updates on the Splunk Community!

Announcing Scheduled Export GA for Dashboard Studio

We're excited to announce the general availability of Scheduled Export for Dashboard Studio. Starting in ...

Extending Observability Content to Splunk Cloud

Watch Now!   In this Extending Observability Content to Splunk Cloud Tech Talk, you'll see how to leverage ...

More Control Over Your Monitoring Costs with Archived Metrics GA in US-AWS!

What if there was a way you could keep all the metrics data you need while saving on storage costs?This is now ...