Splunk Search

Transaction incorrectly grouping results

baerrach
Path Finder

Splunk command:

host="Fleet34" product=MCA AND NOT category=environment | transaction startswith="product=MCA action=start" keeporphans=true keepevicted=true 

I'm trying to see when the app starts/stops that it does so cleanly.
You can see from the results there are starts without stops.

All the results look correct to me, except the last one.

The last result (#10) fails to close (i.e. was evicted) and has grouped multiple events in the one transaction when the startswith value matches multiple occurrences in the event list.

Results

# 1
2012-01-13 10:57:03,781 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
2012-01-13 10:57:56,328 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=stop
[duration=52.547, eventcount=2, closed_txn=1]

# 2
2012-01-13 09:39:27,828 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
2012-01-13 10:20:31,093 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=stop
[duration=2463.265, eventcount=2, closed_txn=1]

# 3
2012-01-12 16:58:58,218 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
[duration=0, eventcount=1, closed_txn=1]

# 4
2012-01-12 15:30:15,406 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
2012-01-12 16:56:59,000 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=stop
[duration=5203.594, eventcount=2, closed_txn=1]

# 5
2012-01-12 15:28:19,281 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
2012-01-12 15:28:50,484 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=stop
[duration=31.203, eventcount=2, closed_txn=1]

# 6 
2012-01-12 15:23:47,828 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
[duration=0, eventcount=1, closed_txn=1]

# 7
2012-01-11 23:25:25,390 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
[duration=0, eventcount=1, closed_txn=1]

# 8
2012-01-11 23:19:48,843 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
[duration=0, eventcount=1, closed_txn=1]

# 9
2012-01-11 16:07:36,406 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
[duration=0, eventcount=1, closed_txn=1]

# 10
2012-01-11 09:12:52,171 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
2012-01-11 09:19:29,187 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=stop
2012-01-11 09:21:14,062 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
2012-01-11 09:21:53,312 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=stop
2012-01-11 11:39:01,984 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
2012-01-11 11:40:08,296 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=stop
2012-01-11 11:41:43,859 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
2012-01-11 11:43:16,181 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=stop
2012-01-11 11:43:24,072 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
2012-01-11 12:21:30,197 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=stop
2012-01-11 15:14:06,375 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
2012-01-11 15:17:57,796 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
2012-01-11 15:27:51,078 INFO  au.gov.sa.police.mcp.client.application.Application {} [main] - product=MCA action=start
[duration=22498.907, eventcount=13, closed_txn=0]

I can't find anything in the job debug information to help me trouble shoot this.
Suggestions welcome.

[update]

Thanks for the suggestion.

startswith=(product="MCA" AND action="start")

This produces the same clumping.
I've also tried endswith but that doesn't make a difference.

endswith=(product="MCA" action="stop")

(and other variations with quotes)

Its difficult to tell what is valid here.
The transaction documentation http://docs.splunk.com/Documentation/Splunk/latest/SearchReference/Transaction says:

endswith=filter-string
    Description: A search or eval filtering expression which if satisfied by an event marks the end of a transaction.
...
filter-string
    Syntax: search-expression | (quoted-search-expression) | eval(eval-expression) 

But it is difficult to tell from this informal grammar what a multiple field search expression looks like. I suspect that I'm not doing that correctly.

Tags (1)
0 Karma
1 Solution

baerrach
Path Finder

The answer is that multi field criteria appears to require using eval.
The following correctly groups the transactions.

host="Fleet34" product=MCA AND NOT category=environment | transaction startswith=eval(product="MCA" AND action="start") keeporphans=true keepevicted=true 

Note: endswith is not needed. But still works if you do add it. i.e.

endswith=eval(product="MCA" AND action="stop") 

View solution in original post

baerrach
Path Finder

The answer is that multi field criteria appears to require using eval.
The following correctly groups the transactions.

host="Fleet34" product=MCA AND NOT category=environment | transaction startswith=eval(product="MCA" AND action="start") keeporphans=true keepevicted=true 

Note: endswith is not needed. But still works if you do add it. i.e.

endswith=eval(product="MCA" AND action="stop") 

View solution in original post

baerrach
Path Finder

Interestingly, when I changed the Splunk command

from

host="Fleet34" product=MCA AND NOT category=environment | transaction startswith="product=MCA action=start" keeporphans=true keepevicted=true

to

host="Fleet34" product=MCA AND NOT category=environment | transaction startswith=start endswith=stop keeporphans=true keepevicted=true

The results do what they are meant to.

However when I attempt to group more events together the broad search term "start" now matches across multiple fields and starts transactions where I dont want them.

dwaddle
SplunkTrust
SplunkTrust

I was going to suggest an endswith rule, or changing your startswith to an eval expression similar to:

startswith=(product="MCA" AND action="start")

Which may work just as well...

0 Karma
.conf21 Now Fully Virtual!
Register for FREE Today!

We've made .conf21 totally virtual and totally FREE! Our completely online experience will run from 10/19 through 10/20 with some additional events, too!