strftime format for event breaks not working

[noveix]

Event breaks based on strftime format for weblogic log events that are not being parsed correctly. e.g. It seems to be interpreting '1432711901' as a timestamp in the following logs.
Weird thing is this is happening intermittently, parsing some correctly but not all.

my props.conf entry on the indexer is
[app_wls]
MAX_TIMESTAMP_LOOKAHEAD = 30
NO_BINARY_CHECK=1
TIME_FORMAT=%b %d, %Y %I:%M:%S %p
TIME_PREFIX = ^

Raw logs for a single event is as follows :

Mar 25, 2014 4:22:01 PM au.com.mydomain.common.logging.LoggerTrace warn
WARNING: Unable to configure audit log meta data. Param not of type Request. Is a: au.com.mydomain.common.configdata
.GetConfigDataRequest
1432711901 [[ACTIVE] ExecuteThread: '9' for queue: 'weblogic.kernel.Default (self-tuning)'] WARN org.springframewor
k.web.context.request.FacesRequestAttributes - Could not register destruction callback [org.springframework.beans.f
actory.support.DisposableBeanAdapter@1d9774a] for attribute 'basicDateTimeConverter' because FacesRequestAttributes
does not support such callbacks
1432711904 [[ACTIVE] ExecuteThread: '9' for queue: 'weblogic.kernel.Default (self-tuning)'] WARN org.springframewor
k.web.context.request.FacesRequestAttributes - Could not register destruction callback [org.springframework.beans.f
actory.support.DisposableBeanAdapter@ff86e9] for attribute 'basicDateConverter' because FacesRequestAttributes does
not support such callbacks
1432712079 [[ACTIVE] ExecuteThread: '11' for queue: 'weblogic.kernel.Default (self-tuning)'] WARN org.springframewo
rk.web.context.request.FacesRequestAttributes - Could not register destruction callback [org.springframework.beans.
factory.support.DisposableBeanAdapter@15d7a3d] for attribute 'transRefValidator' because FacesRequestAttributes does
not support such callbacks
1432712079 [[ACTIVE] ExecuteThread: '11' for queue: 'weblogic.kernel.Default (self-tuning)'] WARN org.springframewo
rk.web.context.request.FacesRequestAttributes - Could not register destruction callback [org.springframework.beans.
factory.support.DisposableBeanAdapter@45316] for attribute 'transRefConverter' because FacesRequestAttributes does n
ot support such callbacks
1432712080 [[ACTIVE] ExecuteThread: '11' for queue: 'weblogic.kernel.Default (self-tuning)'] WARN org.springframewo
rk.web.context.request.FacesRequestAttributes - Could not register destruction callback [org.springframework.beans.
factory.support.DisposableBeanAdapter@f6f2c2] for attribute 'decimalPlacesValidator' because FacesRequestAttributes
does not support such callbacks
1432712081 [[ACTIVE] ExecuteThread: '11' for queue: 'weblogic.kernel.Default (self-tuning)'] WARN org.springframewo
rk.web.context.request.FacesRequestAttributes - Could not register destruction callback [org.springframework.beans.
factory.support.DisposableBeanAdapter@bbac62] for attribute 'minMaxDecimalValidator' because FacesRequestAttributes
does not support such callbacks
1432712086 [[ACTIVE] ExecuteThread: '11' for queue: 'weblogic.kernel.Default (self-tuning)'] WARN org.springframewo
rk.web.context.request.FacesRequestAttributes - Could not register destruction callback [org.springframework.beans.
factory.support.DisposableBeanAdapter@c085f6] for attribute 'paymentInvestigationTypeConverter' because FacesRequest
Attributes does not support such callbacks
1432712086 [[ACTIVE] ExecuteThread: '11' for queue: 'weblogic.kernel.Default (self-tuning)'] WARN org.springframewo
rk.web.context.request.FacesRequestAttributes - Could not register destruction callback [org.springframework.beans.
factory.support.DisposableBeanAdapter@16bcb2d] for attribute 'paymentInvestigationStatusConverter' because FacesRequ
estAttributes does not support such callbacks
1432712087 [[ACTIVE] ExecuteThread: '11' for queue: 'weblogic.kernel.Default (self-tuning)'] WARN org.springframewo
rk.web.context.request.FacesRequestAttributes - Could not register destruction callback [org.springframework.beans.
factory.support.DisposableBeanAdapter@3d3019] for attribute 'simpleDateConverter' because FacesRequestAttributes doe
s not support such callbacksI

[noveix]

more info .. seems to be when there is a line break within the logs then the log entries are not grouped into a single event

so the following breaks, however if there was not line breaks then its recognised as a single event

Mar 25, 2014 4:22:01 PM au.com.mydomain.common.logging.LoggerTrace warn
WARNING: Unable to configure audit log meta data. Param not of type Request. Is a: au.com.mydomain.common.configdata
.GetConfigDataRequest

1432711901 [[ACTIVE] ExecuteThread: '9' for queue: 'weblogic.kernel.Default (self-tuning)'] WARN org.springframewor
k.web.context.request.FacesRequestAttributes - Could not register destruction callback [org.springframework.beans.f
actory.support.DisposableBeanAdapter@1d9774a] for attribute 'basicDateTimeConverter' because FacesRequestAttributes
does not support such callbacks

[kristian_kolb]

Could it be that your event breaks work fine at 10,11 or 12 o'clock?

Then the problem might be in your TIME_FORMAT, and most of the times these things happen (improper event breaking) is when splunk fails to parse timestamps.

You define your TIME_FORMAT with %I for the hour portion (uppercase "i"), which means that values from 01 .. 12 are valid.

I believe that changing to %l (lowercase "L") instead might do the trick, since this means hours from 1 .. 12, i.e. without the leading zero.

see www.strftime.net

Hope this helps,

/K

PS. The reason that numbers like 1432712121 get parsed as timestamps, is that splunk, when failing to detect a proper timestamp according to your configuration may revert to default auto-detecting behaviour, and a numeric string of this size and value can be interpreted as an epoch timestamp (around May 27 2015).

[kristian_kolb]

OK, just to verfy - you know that BREAK_ONLY/MUST_NOT_BREAK etc only are valid with SHOULD_LINEMERGE = true.

And conversely - LINE_BREAKER is only honoured with SHOULD_LINEMERGE = false.

And you are sure that the sourcetype is correct, i.e. so that the settings are applied at all. And that they are in the correct place (indexer/heavy forwarder)

[noveix]

Hi Kristian
Tried the LINE_BREAKER ... it took out the match group, in my case, the Timestamp, anyway I tried the BREAK_ONLY_BEFORE as well, still no good. I have verified my REGEX and its definitely correct, however its not parsing as expected.

Thanks for your help with this, I think I will look at the Weblogic log setting to see if I can eliminate the extra newlines within the logs, this is the main cause of my issues.
Appreciate your help !!

[kristian_kolb]

Fixed a typo and some ambiguity regarding single/double digit dates.

/k

[kristian_kolb]

Still think it is timestamp-related. It almost always is. However, you may need to increase the value for MAX_EVENTS (in props) to accommodate events with more than 256 lines. Also, you could try to force the linebreaking behaviour with MUST_NOT_BREAK.../BREAK_ONLY... (also in props).

Another option is to set SHOULD_LINEMERGE = false, and use something like the following LINE_BREAKER regex;

LINE_BREAKER = ([\r\n]+)(?=[A-Z][a-z]{2}\s+\d+,\s+20\d\d\s+\d+:\d\d:\d\d\s+[AP]M)

Which means that it should only break before a line that contains timestamps formatted as yours.

/k

[noveix]

Hi Kristian

I tried
TIME_FORMAT=%b %d, %Y %l:%M:%S %p (lowercase 'L') and also

TIME_FORMAT=%b %d, %Y %r
still no luck ...