Getting Data In

Timeout on multiline parsing?

PickleRick
SplunkTrust
SplunkTrust

Hello.

I'm trying to understand something.

I have a monitor input reading a file from a tk10x logger (a part of OpenGTS). It logs some data beginning with a line containing "Recv:" string and following that with some data parsed by the receiver from a network-received frame.

I have therefore a sourcetype defined with:

[opengts-events]
BREAK_ONLY_BEFORE = Recv:
BREAK_ONLY_BEFORE_DATE = true
DATETIME_CONFIG =
LINE_BREAKER = ([\r\n]+)
NO_BINARY_CHECK = true
SHOULD_LINEMERGE = true
category = Custom
disabled = false
pulldown_type = 1

(then come some extracts but they are not important here).

To be honest, I'm not sure why I have BREAK_ONLY_BEFORE_DATE set (I configured the sourcetype from the webui). But for now the sourcetype looks like that.

With this setup I'd expect the input to split only on lines containing "Recv:" string. And for most of the time it does so. But also there are some breaks in other places.

For example, this excerpt from log:

(event data from few hours earlier)
[INFO_|03/03 00:19:33|ServerSocketThread$ServerSessionThread.handleClientSession:2895] (ClientSession_000) Remote client port: /1.2.3.4:15352 [to /1.2.3.4:31272]
[INFO_|03/03 00:19:33|AbstractClientPacketHandler.printSessionStart:273] Begin TCP session (ClientSession_000): 1.2.3.4
[INFO_|03/03 00:19:33|TrackClientPacketHandler.getHandlePacket:451] Recv: ##,imei:12345678,A
[INFO_|03/03 00:19:33|TrackClientPacketHandler.getHandlePacket:461] TK103-2 Header: ##,imei:12345678,A
[INFO_|03/03 00:19:33|TrackClientPacketHandler.getHandlePacket:478] Logon ACK: LOAD
[INFO_|03/03 00:19:33|ServerSocketThread$ServerSessionThread.handleClientSession:3004] (ClientSession_000) TCP Resp Asc: LOAD
(next event starting with line containing Recv:)

This log gets split properly at the line containing "Recv: ##,imei:12345678,A", but:

1. First two lines are getting extracted as an event separate from the earlier data even though it doesn't start with a line including "Recv:" (as I wrote, the last data written before that was from few hours earlier). Why? Does the input monitor just have some timeout that it hits and therefore flushes the buffer?

2. If I sort the events by _time in search, I get the "later" event (the last four lines from the excerpt shown above) shown earlier than the one consiting of the first two lines. Strange.

 

Labels (2)
Tags (1)
0 Karma
Got questions? Get answers!

Join the Splunk Community Slack to learn, troubleshoot, and make connections with fellow Splunk practitioners in real time!

Meet up IRL or virtually!

Join Splunk User Groups to connect and learn in-person by region or remotely by topic or industry.

Get Updates on the Splunk Community!

Splunk Community Badges!

  Hey everyone! Ready to earn some serious bragging rights in the community? Along with our existing badges ...

How to find the worst searches in your Splunk environment and how to fix them

Everyone knows Splunk is a powerful platform for running searches and doing data analytics. Your ...

Share Your Feedback: On Admin Config Service (ACS)!

Help Us Build a Better Admin Config Service Experience (ACS)   We Want Your Feedback on Admin Config Service ...