Why are my multi-line events getting split?

[tilbins]

I am trying to prevent my multi-line events from being broken into individual rows. My logs are similar to this:

2018-12-11 09:13:30.1832|170|DEBUG|Timer.MyTimerCallback => ScheduledEventManager.CheckForScheduledEvents => ScheduledEventManager.FireScheduledEvents|** 1 events processed in 0 seconds|
2018-12-11 09:16:22.1177|94|WARN|InternalDispatcher`1.Dispatch => LoggingInterceptor.ReaderExecuted => LoggingInterceptor.StopStopwatch|SQL Time Limit Exceeded!  
Query took 3122 ms, exceeding 3000 ms limit.  
SELECT 
    [UnionAll5].[PatientResponseId] AS [C1], 
    [UnionAll5].[PatientResponseId1] AS [C2], 
    [UnionAll5].[PatientResponseId2] AS [C3],
2018-12-11 09:16:30.1853|27|DEBUG|RuntimeMethodInfo.UnsafeInvokeInternal => RuntimeMethodHandle.InvokeMethod => EventManager.NotifySubscribers|NotifySubscribers Vivify.Platform.Events.PatientAlertDelayedEvent, inBackground False|
2018-12-11 09:16:30.1853|27|INFO|<>c__DisplayClass5_0`1.<NotifySubscribers>b__0 => EventManager.NotifySubscriber => EmailNotificationHandler.OnNext|Handle DelayedNotification: 1023|

Here is my props.conf:

[Log]
NO_BINARY_CHECK = true
category = Custom
description = CGP Application Logs
pulldown_type = 1
FIELD_DELIMITER = |
FIELD_NAMES = Timestamp,Thread,Level,Stack,Info,AddInfo
INDEXED_EXTRACTIONS = psv
disabled = false
SHOULD_LINEMERGE = false
TRUNCATE = 0
MAX_EVENTS = 40000
LINE_BREAKER = ([\r\n]+)([0-9]{4}-[0-9]{2}-[0-9]{2}) ([0-9]{2}:[0-9]{2}:[0-9]{2}.[0-9]{4})

The query that is getting split is actually much longer (~1600 lines).

[whrg · Accepted solution]

Hello @tilbins,

Check out Configure event line breaking.

The default behavior of Splunk is to 1) split lines based on newlines and carriage returns and then 2) merge the lines (if SHOULD_LINEMERGE=true) in events when Splunk encounters a date (BREAK_ONLY_BEFORE_DATE=true by default).

You are doing it differently by 1) splitting lines based on when Splunk encounters a date and then 2) not line merging. This is a different approach but can also work.

In your case I favor the first approach. When I upload your file in Settings / Add Data / Upload and set SHOULD_LINEMERGE=true then Splunk is already doing a fine job. (However, I recommend to set the time format manually instead of letting Splunk guess it.) Also, don't forget to set MAX_EVENTS.

[tilbins]

I started over from scratch and implemented it to these specifications. Here's what my props.conf looks like now:
DATETIME_CONFIG =
NO_BINARY_CHECK = true
TIME_FORMAT = %Y-%m-%d %H:%M:%S.%4N
TZ = America/Chicago
category = Custom
pulldown_type = 1
MAX_EVENTS = 2000
disabled = false

I still need to figure out the parsing, but my events are all back together now.

[prakash007]

hope this should work...MAX_EVENTS works only when SHOULD_LINEMERGE = true according to the docs..props.conf

[Log]
SHOULD_LINEMERGE = true
NO_BINARY_CHECK = true
TIME_FORMAT = %Y-%m-%d %H:%M:%S.%3N
TIME_PREFIX = ^
MAX_TIMESTAMP_LOOKAHEAD = 25
BREAK_ONLY_BEFORE = \d{4}\-\d{2}\-\d{2}\s\d{2}\:\d{2}\:\d{2}\.\d{4}
FIELD_DELIMITER = |
FIELD_NAMES = Timestamp,Thread,Level,Stack,Info,AddInfo
INDEXED_EXTRACTIONS = psv
MAX_EVENTS = 99999

[tilbins]

As a follow-up, used the transform.conf to setup the "|" delimiter:

DELIMS = "|"
FIELDS = TimeStamp,Thread,Level,Stack,Info,AddInfo

[tilbins]

Gave that a try and the multi-line events are still being broken into individual rows. I have played around pretty extensively with the props.conf trying different variations.

Even events like the following are getting broken into individual lines:
2018-12-11 01:01:42.2688|10|ERROR|d_0.MoveNext => ExceptionFilterAttribute.OnExceptionAsync => ExceptionHandlerFilterAttribute.OnException|Exception Caught|System.OperationCanceledException: The operation was canceled.
at System.Threading.CancellationToken.ThrowOperationCanceledException()
at System.Web.Http.Filters.ActionFilterAttribute.d5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Web.Http.Filters.ActionFilterAttribute.d0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Web.Http.Controllers.ActionFilterResult.d2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Web.Http.Filters.AuthorizationFilterAttribute.d2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Web.Http.Controllers.ExceptionFilterResult.d_0.MoveNext()

[prakash007]

That's weird, I tried both ways on my local based on your sample snippet in your question...
1. having splunk do the line-breaking..etc., it's working
2. adding props.conf, above props are working for me
Can you check if any other configs are overriding your extractions...
./splunk cmd btool props list --debug [sourcetype]