Group events by unique ID then time from start to finish

[username_user]

Hi,

I have a need to time certain events in my logs. We have the log format as below. What I need to be able to do is sort the logs by id: (which is a completely unique field) and then time the events. EVENTSTATUS is the status of the log, and there is a start, middle, and end. So that we can see how long each event is taking. I think we need to use the duration function but i'm not sure how to complete this.

[01-Oct-2007 11:52:26.816][INF][EVENTSTATUS][ id:abc-00e081b79c4e event:info heading:info heading:info ] [01-Oct-2007 11:52:27.716][INF][EVENTSTATUS][ id:abc-00e081b79c4e event:info heading:info heading:info ] [01-Oct-2007 11:52:28.362][INF][EVENTSTATUS][ id:abc-00e081b79c4e event:info heading:info heading:info ] [01-Oct-2007 11:52:29.232][INF][EVENTSTATUS][ id:abc-00e081b79c4e event:info heading:info heading:info ]

[ftk · Accepted solution]

You likely need to use the transaction command which will give you a duration field for each whole event.

I assume that EVENTSTATUS is something indicating that the event started and stopped -- in this case I will use "started" and "stopped" but you can replace the placeholders with your relevant data (your sanitized log doesn't give any clues as to what the identifiers are). I also assume that the id: field is extracted, and we will use it to build a transaction.

For transaction you basically tie together a number of events based on a common identifier (in this case id) and give "searches" to define the start and end of a transaction. In your example I would do it as such:

your search terms | transaction id startswith="started" endswith="stopped"

This basically takes the results of "your search terms", ties them together by id, with each transaction starting with a substring of "started" and ending with a substring of "stopped". Of course you will have to adjust this to your particular logs. After running the transaction command you will receive a duration field for each transaction detailing the time it took from start to finish.

[gkanapathy · Accepted solution]

Much better than transaction in this case is just:

... | stats 
        max(_time) as last
        min(_time) as first
      by idfield
    | eval duration = last-first

or

... | stats range(_time) as duration by idfield

Assuming of course that you get idfield extracted from each event. Seem to me that

... | rex "\[id:(?<idfield>\S+)" | ...

should do it.

[username_user]

I got the regex working exactly as you have put it. The transaction is working fine, in fact its quite good to be able to specify a start and end event, as we sometimes want to time different things.

[ftk · Accepted solution]

You likely need to use the transaction command which will give you a duration field for each whole event.

I assume that EVENTSTATUS is something indicating that the event started and stopped -- in this case I will use "started" and "stopped" but you can replace the placeholders with your relevant data (your sanitized log doesn't give any clues as to what the identifiers are). I also assume that the id: field is extracted, and we will use it to build a transaction.

For transaction you basically tie together a number of events based on a common identifier (in this case id) and give "searches" to define the start and end of a transaction. In your example I would do it as such:

your search terms | transaction id startswith="started" endswith="stopped"

This basically takes the results of "your search terms", ties them together by id, with each transaction starting with a substring of "started" and ending with a substring of "stopped". Of course you will have to adjust this to your particular logs. After running the transaction command you will receive a duration field for each transaction detailing the time it took from start to finish.

[username_user]

finally worked it out. thanks.

[username_user]

OK. I'm getting a little closer, but i'm not having much luck with my field extraction. Our id: is a UUID so i'm trying to do the following as an inline field extraction.
id:=^((?-i:0x)?[A-Fa-f0-9]{32}| [A-Fa-f0-9]{8}-[A-Fa-f0-9]{4}-[A-Fa-f0-9]{4}-[A-Fa-f0-9]{4}-[A-Fa-f0-9]{12}| {[A-Fa-f0-9]{8}-[A-Fa-f0-9]{4}-[A-Fa-f0-9]{4}-[A-Fa-f0-9]{4}-[A-Fa-f0-9]{12}})$

without much luck. any help?

[username_user]

Hi ftk,

Thank you for the quick response. I have tried this but when I pass my search results into the transaction command I get 0 results.

source="monitor.log" | transaction id startswith="BEGIN" endswith="COMPLETE"

This returns 0 results.
Am I doing something wrong? Do I need to use an index as per this page? or setup id a s a field or something?

http://www.splunk.com/base/Documentation/4.1.5/AppManagement/Buildatransaction

I'm lost as to how this is supposed to work.

I appreciate your assistance!