To determine the start time from one log record and end time from another log record which have the same key.

[paismm123]

The key is docKey for each of the three records. I need the start time from log having action=UPLOAD and end time from log having action=NOTIFY. Once we get the two times , we have to subtract the two times to get the total time taken for the process from begin process to end.

The logs are:

<06-05-2018 04:53:46 PM EDT> < INFO> [DefaultMessageListenerContainer-14] AspectLogging:39 - [action=NOTIFY, DOCTYPE=INVOICE_PDF, status=C, docKey=814742506620_052718_45527429.pdf, startTime=2018-06-05 16:53:46.396 EDT, endTime=2018-06-05 16:53:46.409 EDT, totalTime=13]
host = rtlvpsaw02.labcorp.com CFP source = /opt/ibm/logs/applogs/cfpds-invoice-rpt-ecs-upload-srvc.log sourcetype = DS-InvRpt-log

<06-05-2018 04:53:46 PM EDT> < INFO> [DefaultMessageListenerContainer-14] AspectLogging:39 - [action=LPID, DOCTYPE=INVOICE_PDF, status=C, docKey=814742506620_052718_45527429.pdf, lpid=9291437470834759, accountNumber=29032270, requestTime=2018-06-05 16:53:46.397 EDT, responseTime=10]
host = rtlvpsaw02.labcorp.com CFP source = /opt/ibm/logs/applogs/cfpds-invoice-rpt-ecs-upload-srvc.log sourcetype = DS-InvRpt-log

<06-05-2018 04:53:46 PM EDT> < INFO> [DefaultMessageListenerContainer-4] AspectLogging:39 - [action=UPLOAD, DOCTYPE=INVOICE_PDF, status=C, docKey=814742506620_052718_45527429.pdf, uploadStartTime=1528232025750, uploadTime=638, startTime=2018-06-05 16:53:45.750 EDT, endTime=2018-06-05 16:53:46.394 EDT, totalTime=644]
host = rtlvpsaw01.labcorp.com CFP source = /opt/ibm/logs/applogs/cfpds-invoice-rpt-ecs-upload-srvc.log sourcetype = DS-InvRpt-log

[cpetterborg]

Since you want the startTime of the first event and the endTime of the last event, this is the way I would do it:

<YOUR_BASE_SEARCH>
| transaction docKey 
| stats min(startTime) as start, max(endTime) as end
| eval d=strptime(end, "%F %T.%N %Z")-strptime(start, "%F %T.%N %Z")

I tried it using your data, and the answer that resulted was 0.659000. It just combines all of the events with the same docKey. Your example data is in the reverse order that I would have expected, so I'm not sure if that was intentional or not, so I didn't account for multiple potential UPLOAD and NOTIFY events for the same docKey. If the events are in the opposite order that they really would come in, then you could add startswith=UPLOAD to the transaction command in order to separate the sets of events at the transaction level.

[martin_mueller]

How about this?

index=foo sourcetype=bar (action=UPLOAD OR action=NOTIFY) | stats values(action) as actions range(_time) as duration by docKey | search action=UPLOAD action=NOTIFY

That will get you all docKey values that have both UPLOAD and NOTIFY events, and compute the time span between the first and last event as the duration.