Why are multiple timestamps in the same log message causing an issue with Splunk event time?

[sarathdsc]

We have our application logs which are being monitored using a universal forwarder and below is the sample message , where same log messages will have multiple dates for better tracing.

The Issue is, sporadically, time stamps in the actual JSON "dateCreated" and "shipDate" are considered as start of the Splunk events instead of the actual time of the event occurred . i.e below sample message in the Splunk search is shown with "_time" filed as "2018-12-03T12:00:00" instead of "2018-12-03T15:06:42".

2018-12-03T15:06:42,298 [[my-application].endpointsFlow.stage1.4150] INFO com.xxx.yyy.zzz - Processing Mesage
 Message:{
  "dateCreated": "2018-12-03T12:00:00Z",
  "shipDate": "2018-12-03T12:00:00Z",
   "XXX" :"YYYY"
  }

We tried to explicit set the below configuration in prop.conf , however this doesnt have any effect on the behavior.

[test:app]
REPORT-app = test-app, test-app2
BREAK_ONLY_BEFORE=^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2},\d{3}
MAX_TIMESTAMP_LOOKAHEAD = 25

Any pointer would be really helpful , thanks in advance.

[prakash007]

I hope one of this should work, if not you need to check if there is a space at the beginning of each event..

[test:app]
NO_BINARY_CHECK = true
BREAK_ONLY_BEFORE = ^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2},\d{3}
TIME_PREFIX = ^
TIME_FORMAT = %Y-%m-%dT%H:%M:%S,%3N
MAX_TIMESTAMP_LOOKAHEAD = 25

[test:app]
NO_BINARY_CHECK = true
SHOULD_LINEMERGE = false
LINE_BREAKER = ([\r\n]+)(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2},\d{3})
TIME_PREFIX = ^
TIME_FORMAT = %Y-%m-%dT%H:%M:%S,%3N
MAX_TIMESTAMP_LOOKAHEAD = 25

[richgalloway]

Try adding TIME_PREFIX = ^ to props.conf.

[sarathdsc]

Thanks for quick reply, Sure , will try that.
So in our case there is a possibility that "MAX_TIMESTAMP_LOOKAHEAD" fall back doesn't have any effect as indexer started looking for "empty String" location (TIME_PREFIX default )+ max 25 character ahead for timestamp which could be anywhere in the payload?Am i reading this right?

fyi ..Below search is still returning so many results

search * | where timestartpos>=25 | top  timestartpos

[sarathdsc]

This does not help us , we still have the same time format issues event after adding TIME_PREFIX = ^

Below are the current configurations. Is there any possibly that any other property/configuration some where else causes these properties not to take effect.

BREAK_ONLY_BEFORE=^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2},\d{3}
MAX_TIMESTAMP_LOOKAHEAD = 25
TIME_PREFIX = ^

 search * | where timestartpos>=25 | top  timestartpos , still returns so many results