Getting Data In

multiline event breaking issue

blee_i365
Explorer

My log file is like this:

StartEvent 01
some data 001
some data 002
some data 003
some data 004
EndEvent 01
StartEvent 02
some other data 001
some other data 002
some other data 003
some other data 004
EndEvent 02
...
...
...

In my props.conf, I have these values:

SHOULD_LINEMERGE = true
BREAK_ONLY_BEFORE = StartEvent \d\d

If my log file contains all the lines from "StartEvent 01" to "EndEvent 01" PRIOR TO Splunk seeing the file for the first time, then the lines are successfully indexed as multiline events as follows:

First event:

StartEvent 01
some data 001
some data 002
some data 003
some data 004
EndEvent 01

Second event:

StartEvent 02
some other data 001
some other data 002
some other data 003
some other data 004
EndEvent 02

However If my application is still in the process of writing to the log file, and Splunk indexes the file, then event-breaking is totally messed up. For example, my app would flush the following lines to the log at first:

StartEvent 01
some data 001
some data 002

and then couple minutes later these additional lines are appended:

some data 003
some data 003
EndEvent 01
StartEvent 02
some other data 001
some other data 002
some other data 003
some other data 004
EndEvent 02

In this case I would get these events instead:

First event:

StartEvent 01
some data 001
some data 002

Second event:

some data 003
some data 004
EndEvent 01

Third event:

StartEvent 02
some other data 001
some other data 002
some other data 003
some other data 004
EndEvent 02

The first and second events in this case should really have been combined as a single event, but during index time Splunk "closed" the first event prematurely because my app had stopped writing to the log temporarily.

I want to see only two multiline events regardless of when or what my app writes to the log file. Is this possible via configuration changes in Splunk?

henchrm
Explorer

I have exactly the same issue (using log4j with buffered io and immediate flush of false) Splunk (universal forwarder) is picking up some of the events before they have been fully logged (they can be truncated mid line before enough data accumulates and flushes the remainder of the event from the buffer to the file system). When the remaining log data is written and sent to the indexer, it is indexed as a separate event. (regardless of any SHOULD_LINEMERGE settings etc.)

My guess is that there is some sort of timeout for multi line events to complete?

0 Karma

jbsplunk
Splunk Employee
Splunk Employee

Inputs.conf has a setting which might be useful for the scenario of an application not writing to a log file for a period of time.

Inputs.conf.spec:

time_before_close = <integer>
* Modtime delta required before Splunk can close a file on EOF.
* Tells the system not to close files that have been updated in past <integer> seconds.
* Defaults to 3.

I ran into a similar situation with someone else recently where they thought line breaking wasn't the issue, but we found that under another config, things worked better. I'll give you what I did with that person in a manner I think is altered for your environment.

props.conf:

LINE_BREAKER = ([\r\n]+)StartEvent \d{2}
TRUNCATE = 0
MAX_EVENTS = 2560
SHOULD_LINEMERGE = false

This is, of course, assuming that the line breaking is properly configured.

jbsplunk
Splunk Employee
Splunk Employee

At this point, if you're an enterprise customer, I would suggest that you open a case with support, providing them a sample of the data. I still feel as though the problem is likely with line breaking, and would try to use LINE_BREAKER with SHOULD_LINEMERGE set to false. I edited the answer to what I would try.

0 Karma

blee_i365
Explorer

Thanks e82than. I did notice the missing slashes. They unfortunately didn't help in my case.

0 Karma

e82than
Communicator

jbsplunk: I quote this.

Maybe something at the first event is different? You could try something like this to start at the beginning of the line:

BREAK_ONLY_BEFORE = ^StartEvent \d\d

Missing slashes added for TS. The regex will fail if the syntactics is not called well.

0 Karma

blee_i365
Explorer

Hey jbsplunk, I have tried various ways to configure breaking. In all cases, if all the lines were already present before splunk sees the file, then all things are working nicely. This should indicate I have valid line/event breaking configs. Only new log that are still being written to in trunks have this problem.

0 Karma

jbsplunk
Splunk Employee
Splunk Employee

Maybe something at the first event is different? You could try something like this to start at the beginning of the line:

BREAK_ONLY_BEFORE = ^StartEvent \d\d

0 Karma

blee_i365
Explorer

It almost worked. Almost. Lines from the initial flush would always be indexed as one event regardless of the time_before_close config and line/event breaking configs. However if there are subsequent lines being flushed and appended to the same log, Splunk would then wait [time_before_close] seconds after each flush/write, before indexing any lines since the initial flush.

0 Karma

blee_i365
Explorer

Just happened to come across this param as well, and tested it. I set it to 600 seconds, more than enough in my case, however I still got the first event as a partial event. My event/line breaking configs in props.conf should be fine because if the log file already has the complete event lines, before splunk indexes it, then there are no problems.

0 Karma
Get Updates on the Splunk Community!

Index This | I am a number, but when you add ‘G’ to me, I go away. What number am I?

March 2024 Edition Hayyy Splunk Education Enthusiasts and the Eternally Curious!  We’re back with another ...

What’s New in Splunk App for PCI Compliance 5.3.1?

The Splunk App for PCI Compliance allows customers to extend the power of their existing Splunk solution with ...

Extending Observability Content to Splunk Cloud

Register to join us !   In this Extending Observability Content to Splunk Cloud Tech Talk, you'll see how to ...