topic Re: Splunk search query: monitoring between specified log lines and getting count in Splunk Search

Splunk search query: monitoring between specified log lines and getting count

wm — Wed, 07 Aug 2024 13:45:18 GMT

Hi all!

I would like to create a no_msg_wait_time column here.

This is my existing splunk search query:

index=index source="D:\\Temp\\logs\\Logpath\\examplelog.log" | rex field=_raw "^(?<date>\d{4}-\d{2}-\d{2})\s+(?<timestamp>\d{2}:\d{2}:\d{2},\d{3})" | rex field=_raw "Done Bulk saving messages, Count=(?<count>\d+), used (?<db_bulk_write_time>\d+) ms" | where isnotnull(count) | eval event_time=strptime(date . " " . timestamp, "%Y-%m-%d %H:%M:%S,%3N") | sort 0 event_time | streamstats current=f last(event_time) as prev_event_time | eval processing_time=if(isnull(prev_event_time), 0, event_time - prev_event_time) | fields date, timestamp, processing_time, count, db_bulk_write_time | eval processing_time = processing_time * 1000 | table date, timestamp, processing_time, count, db_bulk_write_time, _raw

This is an example of the log lines

I would like to create a no_msg_wait_time column with the following results:
It would count how many No message to handle (noMessageHandleCounter=*), retry in 1000 ms there are between each "Done bulk saving messages" So if there are like 4 in between then no_msg_wait_time will be 4000ms, if there are none or zero of those in between than no_msg_wait_time will be 0ms.

So using my current example here:
2024-08-07 21:13:07,710 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:07,710 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=4), retry in 1000 ms
2024-08-07 21:13:08,742 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:08,742 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=5), retry in 1000 ms
2024-08-07 21:13:09,757 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:09,757 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=6), retry in 1000 ms
2024-08-07 21:13:10,773 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:10,773 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=7), retry in 1000 ms
2024-08-07 21:13:11,007 [15] INFO DistributorCommon.WMQClient [(null)] - Message Read from Queue, Message Length:4504
2024-08-07 21:13:11,132 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=1), retry in 10 ms.
2024-08-07 21:13:11,257 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=2), retry in 10 ms.
2024-08-07 21:13:11,382 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=3), retry in 10 ms.
2024-08-07 21:13:11,507 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=4), retry in 10 ms.
2024-08-07 21:13:11,632 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=5), retry in 10 ms.
2024-08-07 21:13:11,757 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=6), retry in 10 ms.
2024-08-07 21:13:11,882 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=7), retry in 10 ms.
2024-08-07 21:13:11,882 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 1
2024-08-07 21:13:11,882 [39] INFO DistributorCommon.WMQClient [(null)] - Processing messages, Count=1
2024-08-07 21:13:11,882 [39] INFO DistributorCommon.WMQClient [(null)] - Done Processing messages, Count=1, IsBufferedEvent=True
2024-08-07 21:13:11,882 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Bulk saving messages, Count=1
2024-08-07 21:13:12,007 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 113 ms
2024-08-07 21:13:12,007 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=8), retry in 10 ms.
2024-08-07 21:13:12,054 [39] INFO DistributorCommon.WMQClient [(null)] - Saved messages to DB, Q Manager to Commit (Remove messages from Queue)
2024-08-07 21:13:12,132 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=9), retry in 10 ms.
2024-08-07 21:13:12,179 [39] INFO DistributorCommon.WMQClient [(null)] - Clear Write Buffer
2024-08-07 21:13:12,257 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:12,398 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:12,528 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:12,778 [33] INFO DistributorCommon.WMQClient [(null)] - Message Read from Queue, Message Length:4668
2024-08-07 21:13:12,809 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 1
2024-08-07 21:13:12,809 [39] INFO DistributorCommon.WMQClient [(null)] - Processing messages, Count=1
2024-08-07 21:13:12,809 [39] INFO DistributorCommon.WMQClient [(null)] - Done Processing messages, Count=1, IsBufferedEvent=True
2024-08-07 21:13:12,809 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Bulk saving messages, Count=1
2024-08-07 21:13:12,825 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 24 ms
2024-08-07 21:13:12,841 [39] INFO DistributorCommon.WMQClient [(null)] - Saved messages to DB, Q Manager to Commit (Remove messages from Queue)
2024-08-07 21:13:12,934 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=1), retry in 10 ms.
2024-08-07 21:13:12,966 [39] INFO DistributorCommon.WMQClient [(null)] - Clear Write Buffer
2024-08-07 21:13:13,059 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=2), retry in 10 ms.
2024-08-07 21:13:13,059 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:13,184 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=3), retry in 10 ms.
2024-08-07 21:13:13,200 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:13,325 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=4), retry in 10 ms.
2024-08-07 21:13:13,341 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:13,466 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=5), retry in 10 ms.
2024-08-07 21:13:13,466 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:13,466 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=4), retry in 1000 ms
2024-08-07 21:13:13,591 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=6), retry in 10 ms.
2024-08-07 21:13:13,716 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=7), retry in 10 ms.
2024-08-07 21:13:13,841 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=8), retry in 10 ms.
2024-08-07 21:13:13,966 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=9), retry in 10 ms.
2024-08-07 21:13:14,481 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:14,481 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=5), retry in 1000 ms
2024-08-07 21:13:15,497 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:15,497 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=6), retry in 1000 ms
2024-08-07 21:13:15,731 [20] INFO DistributorCommon.WMQClient [(null)] - Message Read from Queue, Message Length:7648
2024-08-07 21:13:15,856 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=1), retry in 10 ms.
2024-08-07 21:13:15,981 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=2), retry in 10 ms.
2024-08-07 21:13:16,106 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=3), retry in 10 ms.
2024-08-07 21:13:16,231 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=4), retry in 10 ms.
2024-08-07 21:13:16,356 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=5), retry in 10 ms.
2024-08-07 21:13:16,481 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=6), retry in 10 ms.
2024-08-07 21:13:16,606 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=7), retry in 10 ms.
2024-08-07 21:13:16,606 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 1
2024-08-07 21:13:16,606 [39] INFO DistributorCommon.WMQClient [(null)] - Processing messages, Count=1
2024-08-07 21:13:16,606 [39] INFO DistributorCommon.WMQClient [(null)] - Done Processing messages, Count=1, IsBufferedEvent=True
2024-08-07 21:13:16,606 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Bulk saving messages, Count=1
2024-08-07 21:13:16,622 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 11 ms
2024-08-07 21:13:16,637 [39] INFO DistributorCommon.WMQClient [(null)] - Saved messages to DB, Q Manager to Commit (Remove messages from Queue)
2024-08-07 21:13:16,731 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=8), retry in 10 ms.
2024-08-07 21:13:16,762 [39] INFO DistributorCommon.WMQClient [(null)] - Clear Write Buffer
2024-08-07 21:13:16,856 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=9), retry in 10 ms.
2024-08-07 21:13:16,856 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:16,997 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:17,137 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:17,278 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:17,278 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=4), retry in 1000 ms
2024-08-07 21:13:18,294 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:18,294 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=5), retry in 1000 ms
2024-08-07 21:13:19,309 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0
2024-08-07 21:13:19,309 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=6), retry in 1000 ms
2024-08-07 21:13:19,544 [28] INFO DistributorCommon.WMQClient [(null)] - Message Read from Queue, Message Length:13568
2024-08-07 21:13:19,669 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=1), retry in 10 ms.
2024-08-07 21:13:19,794 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=2), retry in 10 ms.
2024-08-07 21:13:19,919 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=3), retry in 10 ms.
2024-08-07 21:13:20,044 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=4), retry in 10 ms.
2024-08-07 21:13:20,169 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=5), retry in 10 ms.
2024-08-07 21:13:20,294 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=6), retry in 10 ms.
2024-08-07 21:13:20,419 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=7), retry in 10 ms.
2024-08-07 21:13:20,419 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 1
2024-08-07 21:13:20,419 [39] INFO DistributorCommon.WMQClient [(null)] - Processing messages, Count=1
2024-08-07 21:13:20,419 [39] INFO DistributorCommon.WMQClient [(null)] - Done Processing messages, Count=1, IsBufferedEvent=True
2024-08-07 21:13:20,419 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Bulk saving messages, Count=1
2024-08-07 21:13:20,434 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 12 ms

And my current results are as follow (i manually added expected no_msg_wait_time)

date	timestamp	processing_time	count	db_bulk_write_time	no_msg_wait_time	_raw
2024-08-07	21:13:07,070	0.00 ms	1	13.00 ms	this one should be zero as i dont have one log line before to calculate (assume this is the start of log line)	2024-08-07 21:13:07,070 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 13 ms
	21:13:12,007	4,937.00 ms	1	113.00 ms	4000ms (as there are 4 no message to handle, ... 1000ms)	2024-08-07 21:13:12,007 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 113 ms
	21:13:12,825	818.00 ms	1	24.00 ms	3000ms	2024-08-07 21:13:12,825 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 24 ms
	21:13:16,622	3,797.00 ms	1	11.00 ms	10,000ms	2024-08-07 21:13:16,622 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 11 ms
	21:13:20,434	3,812.00 ms	1	12.00 ms	and so on so forth	2024-08-07 21:13:20,434 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 12 ms

Re: Splunk search query: monitoring between specified log lines and getting count

yuanliu — Thu, 08 Aug 2024 07:07:04 GMT

Maybe transaction? Something like

index=index source="D:\\Temp\\logs\\Logpath\\examplelog.log" | transaction startswith="Saved messages to DB" endswith="Done bulk saving messages" keepevicted=t | eval no_msg_wait_time = mvcount(noMessageHandleCounter) * 1000 | fillnull no_msg_wait_time | rename duration as processing_time | eval _raw = mvindex(split(_raw, " "), -1) | rex "Done Bulk saving .+ used (?<db_bulk_write_time>\w+)" | table _time processing_time Count db_bulk_write_time no_msg_wait_time _raw

Your sample event will give

_time	processing_time	Count	db_bulk_write_time	no_msg_wait_time	_raw
2024-08-07 21:13:16.637	3.797	1	12	3000	2024-08-07 21:13:20,434 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 12 ms
2024-08-07 21:13:12.841	3.781	1	11	3000	2024-08-07 21:13:16,622 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 11 ms
2024-08-07 21:13:12.054	0.771	1	24	0	2024-08-07 21:13:12,825 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 24 ms
2024-08-07 21:13:07.710	4.297	1	113	4000	2024-08-07 21:13:12,007 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 113 ms

I didn't break _time into separate fields but that can easily be done.

Here is an emulation for you to play with and compare with real data.

| makeresults | eval data = split("2024-08-07 21:13:07,710 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:07,710 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=4), retry in 1000 ms 2024-08-07 21:13:08,742 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:08,742 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=5), retry in 1000 ms 2024-08-07 21:13:09,757 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:09,757 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=6), retry in 1000 ms 2024-08-07 21:13:10,773 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:10,773 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=7), retry in 1000 ms 2024-08-07 21:13:11,007 [15] INFO DistributorCommon.WMQClient [(null)] - Message Read from Queue, Message Length:4504 2024-08-07 21:13:11,132 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=1), retry in 10 ms. 2024-08-07 21:13:11,257 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=2), retry in 10 ms. 2024-08-07 21:13:11,382 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=3), retry in 10 ms. 2024-08-07 21:13:11,507 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=4), retry in 10 ms. 2024-08-07 21:13:11,632 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=5), retry in 10 ms. 2024-08-07 21:13:11,757 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=6), retry in 10 ms. 2024-08-07 21:13:11,882 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=7), retry in 10 ms. 2024-08-07 21:13:11,882 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 1 2024-08-07 21:13:11,882 [39] INFO DistributorCommon.WMQClient [(null)] - Processing messages, Count=1 2024-08-07 21:13:11,882 [39] INFO DistributorCommon.WMQClient [(null)] - Done Processing messages, Count=1, IsBufferedEvent=True 2024-08-07 21:13:11,882 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Bulk saving messages, Count=1 2024-08-07 21:13:12,007 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 113 ms 2024-08-07 21:13:12,007 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=8), retry in 10 ms. 2024-08-07 21:13:12,054 [39] INFO DistributorCommon.WMQClient [(null)] - Saved messages to DB, Q Manager to Commit (Remove messages from Queue) 2024-08-07 21:13:12,132 [15] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=9), retry in 10 ms. 2024-08-07 21:13:12,179 [39] INFO DistributorCommon.WMQClient [(null)] - Clear Write Buffer 2024-08-07 21:13:12,257 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:12,398 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:12,528 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:12,778 [33] INFO DistributorCommon.WMQClient [(null)] - Message Read from Queue, Message Length:4668 2024-08-07 21:13:12,809 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 1 2024-08-07 21:13:12,809 [39] INFO DistributorCommon.WMQClient [(null)] - Processing messages, Count=1 2024-08-07 21:13:12,809 [39] INFO DistributorCommon.WMQClient [(null)] - Done Processing messages, Count=1, IsBufferedEvent=True 2024-08-07 21:13:12,809 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Bulk saving messages, Count=1 2024-08-07 21:13:12,825 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 24 ms 2024-08-07 21:13:12,841 [39] INFO DistributorCommon.WMQClient [(null)] - Saved messages to DB, Q Manager to Commit (Remove messages from Queue) 2024-08-07 21:13:12,934 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=1), retry in 10 ms. 2024-08-07 21:13:12,966 [39] INFO DistributorCommon.WMQClient [(null)] - Clear Write Buffer 2024-08-07 21:13:13,059 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=2), retry in 10 ms. 2024-08-07 21:13:13,059 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:13,184 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=3), retry in 10 ms. 2024-08-07 21:13:13,200 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:13,325 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=4), retry in 10 ms. 2024-08-07 21:13:13,341 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:13,466 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=5), retry in 10 ms. 2024-08-07 21:13:13,466 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:13,466 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=4), retry in 1000 ms 2024-08-07 21:13:13,591 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=6), retry in 10 ms. 2024-08-07 21:13:13,716 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=7), retry in 10 ms. 2024-08-07 21:13:13,841 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=8), retry in 10 ms. 2024-08-07 21:13:13,966 [33] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=9), retry in 10 ms. 2024-08-07 21:13:14,481 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:14,481 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=5), retry in 1000 ms 2024-08-07 21:13:15,497 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:15,497 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=6), retry in 1000 ms 2024-08-07 21:13:15,731 [20] INFO DistributorCommon.WMQClient [(null)] - Message Read from Queue, Message Length:7648 2024-08-07 21:13:15,856 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=1), retry in 10 ms. 2024-08-07 21:13:15,981 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=2), retry in 10 ms. 2024-08-07 21:13:16,106 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=3), retry in 10 ms. 2024-08-07 21:13:16,231 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=4), retry in 10 ms. 2024-08-07 21:13:16,356 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=5), retry in 10 ms. 2024-08-07 21:13:16,481 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=6), retry in 10 ms. 2024-08-07 21:13:16,606 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=7), retry in 10 ms. 2024-08-07 21:13:16,606 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 1 2024-08-07 21:13:16,606 [39] INFO DistributorCommon.WMQClient [(null)] - Processing messages, Count=1 2024-08-07 21:13:16,606 [39] INFO DistributorCommon.WMQClient [(null)] - Done Processing messages, Count=1, IsBufferedEvent=True 2024-08-07 21:13:16,606 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Bulk saving messages, Count=1 2024-08-07 21:13:16,622 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 11 ms 2024-08-07 21:13:16,637 [39] INFO DistributorCommon.WMQClient [(null)] - Saved messages to DB, Q Manager to Commit (Remove messages from Queue) 2024-08-07 21:13:16,731 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=8), retry in 10 ms. 2024-08-07 21:13:16,762 [39] INFO DistributorCommon.WMQClient [(null)] - Clear Write Buffer 2024-08-07 21:13:16,856 [20] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=9), retry in 10 ms. 2024-08-07 21:13:16,856 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:16,997 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:17,137 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:17,278 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:17,278 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=4), retry in 1000 ms 2024-08-07 21:13:18,294 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:18,294 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=5), retry in 1000 ms 2024-08-07 21:13:19,309 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0 2024-08-07 21:13:19,309 [39] INFO DistributorCommon.WMQClient [(null)] - No message to handle (noMessageHandleCounter=6), retry in 1000 ms 2024-08-07 21:13:19,544 [28] INFO DistributorCommon.WMQClient [(null)] - Message Read from Queue, Message Length:13568 2024-08-07 21:13:19,669 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=1), retry in 10 ms. 2024-08-07 21:13:19,794 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=2), retry in 10 ms. 2024-08-07 21:13:19,919 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=3), retry in 10 ms. 2024-08-07 21:13:20,044 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=4), retry in 10 ms. 2024-08-07 21:13:20,169 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=5), retry in 10 ms. 2024-08-07 21:13:20,294 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=6), retry in 10 ms. 2024-08-07 21:13:20,419 [28] INFO DistributorCommon.WMQClient [(null)] - No msg in the queue (NoMessageCounter=7), retry in 10 ms. 2024-08-07 21:13:20,419 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 1 2024-08-07 21:13:20,419 [39] INFO DistributorCommon.WMQClient [(null)] - Processing messages, Count=1 2024-08-07 21:13:20,419 [39] INFO DistributorCommon.WMQClient [(null)] - Done Processing messages, Count=1, IsBufferedEvent=True 2024-08-07 21:13:20,419 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Bulk saving messages, Count=1 2024-08-07 21:13:20,434 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 12 ms", " ") | mvexpand data | rename data as _raw | extract | eval _time = strptime(replace(_raw, "^(?<_time>\S+ \S+).+", "\1"), "%F %T,%3N") | sort - _time ``` the above emulates index=index source="D:\\Temp\\logs\\Logpath\\examplelog.log" ```

Re: Splunk search query: monitoring between specified log lines and getting count

wm — Sun, 11 Aug 2024 07:44:16 GMT

Thanks @yuanliu ! I willl try this promptly tomorrow and let you know of the results - will accept as solution if it works:)

Re: Splunk search query: monitoring between specified log lines and getting count

wm — Mon, 12 Aug 2024 02:58:51 GMT

I get and my first row count is empty 😞 _raw is weird too

_time processing_time Count db_bulk_write_time no_msg_wait_time _raw

2024-08-12 10:55:41.200	1.226		1000	.
2024-08-12 10:55:40.872	0.312	1	0	s
2024-08-12 10:55:37.122	3.75	1	3000	s
2024-08-12 10:55:36.809	0.313	1	0	s
2024-08-12 10:55:33.106	3.688	1	3000	s
2024-08-12 10:55:32.778	0.313	1	0	s
2024-08-12 10:55:29.028	3.75	1	3000	s
2024-08-12 10:55:28.700	0.328	1	0	s
2024-08-12 10:55:24.950	3.75	1	3000	s
2024-08-12 10:55:24.622	0.312	1	0	s
2024-08-12 10:55:21.888	2.734	1	2000	s
2024-08-12 10:55:20.122	1.766	1	1000	s

Re: Splunk search query: monitoring between specified log lines and getting count

wm — Mon, 12 Aug 2024 03:21:31 GMT

also in this case

2024-08-12 10:53:53.455	2.75	3		2000	s
2024-08-12 10:53:56.205	2.765

the 2nd row should be 2.75 instead

Re: Splunk search query: monitoring between specified log lines and getting count

yuanliu — Mon, 12 Aug 2024 03:23:50 GMT

The first row can easily be excluded because there is no Count. But the weird _raw signifies some unusual characteristics. Failure to extract db_bulk_write_time suggests the same. You need to post more realistic/representative data.

Re: Splunk search query: monitoring between specified log lines and getting count

wm — Mon, 12 Aug 2024 04:37:32 GMT

Thanks @yuanliu , let me organise my thoughts and query abit after the long weekend. cheers and appreciate the prompt reply and help ! 🙂

Re: Splunk search query: monitoring between specified log lines and getting count

wm — Wed, 14 Aug 2024 08:13:59 GMT

Hi @yuanliu , really appreciate your help and patience here.

My requirements had changed and this is my current search query

index=abc sourcetype = example_sourcetype | transaction startswith="Saved messages to DB" endswith="Done bulk saving messages" keepevicted=t | eval no_msg_wait_time = mvcount(noMessageHandleCounter) * 1000 | fillnull no_msg_wait_time | rename duration as processing_time | eval _raw = mvindex(split(_raw, " "), -1) | rex "Done Bulk saving .+ used (?<db_bulk_write_time>\w+)" | eval processing_time = processing_time * 1000 | eval mq_read_time = processing_time - db_bulk_write_time - no_msg_wait_time | where db_bulk_write_time > 0 | rename processing_time as "processing_time(ms)", db_bulk_write_time as "db_bulk_write_time(ms)", no_msg_wait_time as "no_msg_wait_time(ms)", mq_read_time as "mq_read_time(ms)" | table _time, processing_time(ms), db_bulk_write_time(ms), no_msg_wait_time(ms), mq_read_time(ms), Count, _raw

So now for processing_time(ms) column the calculation instead is starting from the 2 previous occurences of All Read threads finished flush the messages to Done bulk saving messages

So in the example below:
2024-08-12 10:02:20,542 will have a processing_time from 10:02:19,417 to 10:02:20,542.

2024-08-12 10:02:19,417 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 0

2024-08-12 10:02:20,526 [39] INFO DistributorCommon.WMQClient [(null)] - All Read threads finished flush the messages, total messages: 1
Count=1
2024-08-12 10:02:20,542 [39] INFO DistributorCommon.DBHandlerBase [(null)] - Done Bulk saving messages, Count=1, used 6 ms

How can I also create a time series graph on same graph where x axis is time and then y axis is a bar chart of count column + line chart of new processing_time(ms)

Re: Splunk search query: monitoring between specified log lines and getting count

wm — Fri, 16 Aug 2024 03:19:55 GMT

Hi @yuanliu , may I know what does keepevicted=t do and what happens if we dont use it?

Re: Splunk search query: monitoring between specified log lines and getting count

yuanliu — Fri, 16 Aug 2024 04:54:34 GMT

See transaction. Because the sample dataset is small, and they do not start at the top of a cycle, I wanted to show results from incomplete transactions. You need to analyze real data to see which options are right for your use case.