Time Latency calculation from log files for an application transaction across time lines

[thejaspavithran]

Hi,

I have a set of logs in the following format

---

2011-10-17 14:16:11,117 [main] : DEBUG - <Application Id [461620] Transaction Id [574783]> A: Sending data to B
2011-10-17 14:16:13,602 [main] : DEBUG - <Application Id [461620] Transaction Id [2488188]> B: Received Data from A.
2011-10-17 14:16:13,602 [main] : DEBUG - <Application Id [461620] Transaction Id [2488188]> B: Inserting Data from A.
2011-10-17 14:16:14,586 [main] : DEBUG - <Application Id [461620] Transaction Id [2488188]> B: Inserted Data into B DB.
2011-10-17 14:16:14,586 [main] : DEBUG - <Application Id [461620] Transaction Id [8787378]> B: Sending data to Credit Agencies.
2011-10-17 14:16:23,242 [main] : DEBUG - <Application Id [461620] Transaction Id [8787378]> B: Received Confirmation from Credit Agencies.
2011-10-17 14:16:23,914 [main] : DEBUG - <Application Id [461620] Transaction Id [574783]> A: Committing the transaction. "

---

I would want to calculate the time latency for a particular transaction of A from stating time "2011-10-17 14:16:11,117 " to end time "2011-10-17 14:16:23,914"

By this i would want to show
1. which transactions of an application Id, took longer time to execute, and if so..
2. i would have to dig deeper to find, which sub-transaction caused the issue.

Any inputs is greatly welcome.

Regards
Thejas

[Ayn]

If you have the application ID and transaction ID extracted as fields (let's call them "application_id" and "transaction_id"), the rest should be fairly straightforward. Use transaction:

<yourbasesearch> | transaction application_id transaction_id

transaction will output the field duration which shows the time difference between the first and last event of the transaction. So, if you want to find transactions that took a long time to execute, you would do:

<yourbasesearch> | transaction application_id transaction_id | sort - duration

This will give you the longest transaction first.

[thejaspavithran]

Thank you.But, I would want to show the difference in the start & end time [latency] of a txn and of all txns, sorted by the txn that takes the maximum time to execute. [Table]

source="somesource" | transaction app_id trans_id | sort - duration | stats
max(timestamp) as latest
min(timestamp) as earliest by app_id | eval latency=(latest-earliest)

But somehow the latency does not get calculated / or is coming as blank.

Do i need to do some timestamp conversion - if so what would that be ?

Note: timestamp = field extracted value of "2011-10-17 14:16:13,602"

Regards
Thejas