Splunk Search
Highlighted

Transaction to Find Duration

SplunkTrust
SplunkTrust

I have a simple web service with a request and response called DeliverySchedule. The request and response have a unique identifier called a GUID which are in pairs. I'm trying to find the duration (response time) between the response and request.

Here's my search which is returning some correct durations but also listing 0 for more than 400 events . I'm also missing a lot of events

index=unleashed  "deliveryschedule"   | transaction GUID startswith="Request" endswith="Reply" | timechart avg(duration)

GUID = "33efb817-1948-4c8f-bdf4-4111aa1941cc" in this case. We will only have 2 matching GUID's which are attached to the req/resp. They will be different for each req/resp. I also did a field extraction called 'GUID' to capture the GUID between the pipes..

REQUEST

DEBUG 2015-05-13 15:31:40,590
 fterReceiveRequest - Request Record : |33efb817-1948-4c8f-bdf4-4111aa1941cc |
 <GetDeliverySchedule xmlns="http://tempuri.org/">
  <request>
    <DeliveryType /DotCom_Delivery">A</DeliveryType>
    <EndDate/DotCom_Delivery">2015-05-15</EndDate>
    <Region_StoreNo/DotCom_Delivery">970</Region_StoreNo>
    <Region_zip/DotCom_Delivery">11111</Region_zip>
    <StartDate/DotCom_Delivery">2015-05-13</StartDate>
  </request>
</GetDeliverySchedule>

RESPONSE

DEBUG 2015-05-13 15:31:41,276        BeforeSendReply    - Response Record : |33efb817-1948-4c8f-bdf4-4111aa1941cc |
 <GetDeliveryScheduleResponse xmlns="http://tempuri.org/">
  <GetDeliveryScheduleResult xmlns:a="http://schemas.datacontract.org/2004/07/DotCom_Delivery" xmlns:i="http://www.w3.org/2001/XMLSchema-instance">
    <a:DeliveryCalendar>
      <a:Ranges>
        <a:DeliveryRange i:type="a:DeliveryDate">
          <a:IsAvailableForDelivery>false</a:IsAvailableForDelivery>
          <a:Date>2015-05-13T00:00:00-04:00</a:Date>
        </a:DeliveryRange>
        <a:DeliveryRange i:type="a:DeliveryDate">
          <a:IsAvailableForDelivery>false</a:IsAvailableForDelivery>
          <a:Date>2015-05-14T00:00:00-04:00</a:Date>
        </a:DeliveryRange>
</a:Ranges>
      <a:TypeOfCalendar>DayType</a:TypeOfCalendar>
      <a:ZoneId>110</a:ZoneId>
    </a:DeliveryCalendar>
    <a:StatusCode>200</a:StatusCode>
    <a:StatusMessage>OK</a:StatusMessage>
  </GetDeliveryScheduleResult>
</GetDeliveryScheduleResponse>
0 Karma
Highlighted

Re: Transaction to Find Duration

SplunkTrust
SplunkTrust

Shouldn't it be endswith="Response"?

0 Karma
Highlighted

Re: Transaction to Find Duration

SplunkTrust
SplunkTrust

Thanks for the response. I tried a lot of different strings for startswith="" and endswith="" with no luck.

The one I'm currently trying is startswith="fterReceiveRequest" endswith="BeforeSendReply"and still returning 400+ values with duration = 0..

It's working correctly for some events but for 400+ of them, its returning duration=0. I even went to some of the events which have duration=0 and took the difference between the response and request and it's typically in the 200-300ms range, no events have duration = 0 from what I've seen.

The example I posted above is an event which has duration = 0

0 Karma
Highlighted

Re: Transaction to Find Duration

SplunkTrust
SplunkTrust

So... Request and Response are linked together correctly by the transaction, but the duration field is zero instead of zero point something?

0 Karma
Highlighted

Re: Transaction to Find Duration

SplunkTrust
SplunkTrust

Yes correct. Transaction is working as expected by grouping the request and response into the same event which have a matching guid. The duration for most is absolute 0. For the on one's that return a valid duration, they are equal to like 0.336 and 0.386.. we rarely have response times over a second. After i fix this issue ill change it from seconds to ms

0 Karma
Highlighted

Re: Transaction to Find Duration

SplunkTrust
SplunkTrust

Both _time fields are extracted correctly?

0 Karma
Highlighted

Re: Transaction to Find Duration

SplunkTrust
SplunkTrust

Not sure. Can you elaborate on that?

0 Karma
Highlighted

Re: Transaction to Find Duration

SplunkTrust
SplunkTrust

Looking at the events without |transaction, does the timestamp to the left of the raw event appear correctly including subseconds?

0 Karma
Highlighted

Re: Transaction to Find Duration

SplunkTrust
SplunkTrust

Yes it does. All the timestamps are correct

0 Karma
Highlighted

Re: Transaction to Find Duration

Esteemed Legend

Transaction does a ton of things that you don't appear to need. Have you tried something like this:

index=unleashed  "deliveryschedule"  | stats earliest(_time) AS firstTime latest(_time) AS lastTime by GUID | eval duration=lastTime-firstTime | timechart avg(duration)

View solution in original post