TIME_FORMAT issue with 10:21:00 and 06:10:21

[vijayakumarkb]

I have a time format issue with Splunk logs . events are not coming correctly against the correct timestamp. in props.conf i have 

SHOULD_LINEMERGE = false
TIME_PREFIX = \[
TIME_FORMAT = %d/%b/%Y:%H:%M:%S %Z
MAX_TIMESTAMP_LOOKAHEAD = 26

but the issue is both 26/Aug/2020:10:21:00 and 26/Aug/2020:06:10:21(logs below) are coming under the time 26/Aug/2020:10:21:00.

Below are the logs 

dateTime="[26/Aug/2020:10:21:00 +0000]" remoteUser="-" firstLine="POST /api/1 HTTP/1.1" httpStatus=200; bytesSent=120 - responseTime=127

dateTime="[26/Aug/2020:06:10:21 +0000]" remoteUser="-" firstLine="POST /api/2 HTTP/1.1" httpStatus=200; bytesSent=1512 - responseTime=14

so when doing timechart span=1s i am getting wrong results

why the time matching not working correctly?

Any help

[isoutamo]

Can you put your props.conf and example data inside code block or otherwise as plain text so we don't need to guess where is line breaks etc ;-?

r. Ismo

[vijayakumarkb]

formatted, sorry for that

[isoutamo · Accepted solution]

Hi

some changes based on your data:

DATETIME_CONFIG =
LINE_BREAKER = ([\r\n]+)
MAX_TIMESTAMP_LOOKAHEAD = 50
NO_BINARY_CHECK = true
TIME_FORMAT = %d/%b/%Y:%H:%M:%S %z
TIME_PREFIX = dateTime="\[

Those should fix the situation.

r. Ismo

[vijayakumarkb]

it didnt fix the issue

this issue is only coming at second is 00. all other times it is fine.

Splunk Time zone is PST and host log file date is GMT

Wrong
04:25:00.000
dateTime="[26/Aug/2020:00:11:25 +0000]" firstLine="POST /api HTTP/1.1" httpStatus=200; bytesSent=1458 - responseTime=9

Correct 
04:43:29.000
dateTime="[26/Aug/2020:11:43:29 +0000]" firstLine="POST /api HTTP/1.1" httpStatus=200; bytesSent=1450 - responseTime=239

[isoutamo]

Now I'm little bite confused what you issue really is?

Splunk stores always events as GMT time to server. Then it shows to you as your local zone is configured on you Splunk GUI settings.

Maybe this explains it in more detailed level.

https://community.splunk.com/t5/Dashboards-Visualizations/quot-Event-timezone-quot-compared-to-quot-...

+0000 means that event's timezone is GMT.

PST is equal to UTC-0800 on summertime and UTC-0700 on normal time.

And here is those time format variables: https://docs.splunk.com/Documentation/Splunk/8.0.5/SearchReference/Commontimeformatvariables

When I change my TZ to PST on Splunk GUI I will get:

dateTime=[26/Aug/2020:00:11:25 +0000]
_time: 2020-08-25T17:11:25.000-07:00

dateTime=[26/Aug/2020:11:43:29 +0000]
_time: 2020-08-26T04:43:29.000-07:00

And when I change TZ to GMT then it shows

dateTime=[26/Aug/2020:00:11:25 +0000]
_time: 2020-08-26T00:11:25.000+00:00

dateTime=[26/Aug/2020:11:43:29 +0000]
_time: 2020-08-26T11:43:29.000+00:00

 r. Ismo

[vijayakumarkb]

My issue is

26/Aug/2020:05:12:08 +0000 logs(in host) are coming under 26/08/2020 05:08:00.000 in splunk

26/Aug/2020:00:11:25 +0000 logs(in host) are coming under 26/08/2020 04:25:00.000 in splunk

so i think 

08 +0000 is matching with time 05:08:00.000

:25 +0000 is matching with time 25:00.000

and showing wrong results. 

this is is happening only on :00 seconds, eg : 04:25:00.000, 04:26:00.000, 04:27:00.000 etc

[vijayakumarkb]

My issue is

[vijayakumarkb]

ClientIP="00.00.00.00" remotehost="00.00.00.00" acceptHeader="-" dateTime="[26/Aug/2020:04:13:19 +0000]" remoteUser="-"  firstLine="POST /api/1"

this is the full log, i put 

MAX_TIMESTAMP_LOOKAHEAD = 200

stil it didnt work

[isoutamo]

And you have this:

TIME_FORMAT = %d/%b/%Y:%H:%M:%S %z
TIME_PREFIX = dateTime="\[

And it is "%z" not "%Z" 

As %Z means "PST", "GMT" etc.

and %z is "+0000", "-0700" etc. 

[vijayakumarkb]

yes i have small z

%z

[isoutamo]

Just testing this with: (cat foo3.out)

ClientIP="00.00.00.00" remotehost="00.00.00.00" acceptHeader="-" dateTime="[26/Aug/2020:05:12:08 +0000]" firstLine="POST /api HTTP/1.1" httpStatus=200; bytesSent=1450 - responseTime=239
ClientIP="00.00.00.00" remotehost="00.00.00.00" acceptHeader="-" dateTime="[26/Aug/2020:00:11:25 +0000]" firstLine="POST /api HTTP/1.1" httpStatus=200; bytesSent=1450 - responseTime=239

inputs.conf

[monitor:///path/to/file/foo3.out]
disabled = false
host = host_name
index = main
sourcetype = foo3

 props.conf

[foo3]
DATETIME_CONFIG =
LINE_BREAKER = ([\r\n]+)
NO_BINARY_CHECK = true
TIME_FORMAT = %d/%b/%Y:%H:%M:%S %z
TIME_PREFIX = dateTime="\[
category = Custom
pulldown_type = true

And events are in splunk just like they should with correct _time.

Where you are testing these? I'm using local workstation with 8.0.5 installed locally.

Index main and app search.

And for testing purpose I have set my User -> Preferences: TZ as Pacific Time (GMT-08:00)

And btool shows:

splunk btool inputs list monitor:///path/to/file/foo3.out
[monitor:///path/to/file/foo3.out]
_rcvbuf = 1572864
disabled = false
host = host_name
index = main
sourcetype = foo3

splunk btool props list foo3
[foo3]
ADD_EXTRA_TIME_FIELDS = True
ANNOTATE_PUNCT = True
AUTO_KV_JSON = true
BREAK_ONLY_BEFORE =
BREAK_ONLY_BEFORE_DATE = True
CHARSET = UTF-8
DATETIME_CONFIG =
DEPTH_LIMIT = 1000
HEADER_MODE =
LEARN_MODEL = true
LEARN_SOURCETYPE = true
LINE_BREAKER = ([\r\n]+)
LINE_BREAKER_LOOKBEHIND = 100
MATCH_LIMIT = 100000
MAX_DAYS_AGO = 2000
MAX_DAYS_HENCE = 2
MAX_DIFF_SECS_AGO = 3600
MAX_DIFF_SECS_HENCE = 604800
MAX_EVENTS = 256
MAX_TIMESTAMP_LOOKAHEAD = 128
MUST_BREAK_AFTER =
MUST_NOT_BREAK_AFTER =
MUST_NOT_BREAK_BEFORE =
NO_BINARY_CHECK = true
SEGMENTATION = indexing
SEGMENTATION-all = full
SEGMENTATION-inner = inner
SEGMENTATION-outer = outer
SEGMENTATION-raw = none
SEGMENTATION-standard = standard
SHOULD_LINEMERGE = True
TIME_FORMAT = %d/%b/%Y:%H:%M:%S %z
TIME_PREFIX = dateTime="\[
TRANSFORMS =
TRUNCATE = 10000
category = Custom
detect_trailing_nulls = false
maxDist = 100
priority =
pulldown_type = true
sourcetype =

Let's hope that these helps you.

r. Ismo

[vijayakumarkb]

Hi, 

looks like the issue is solved, finally I used combination of something like below

[access_log]
SHOULD_LINEMERGE = false
NO_BINARY_CHECK = true
DATETIME_CONFIG =
MAX_TIMESTAMP_LOOKAHEAD = 150
TIME_FORMAT = %d/%b/%Y:%H:%M:%S %z
TIME_PREFIX = dateTime="\[

Thanks for all the help, I have never seen someone going this far to reproduce and find a solution like u did, outstanding...

[isoutamo]

Thanks, and nice to heard the we could solve your issue 😉

[vijayakumarkb]

26/Aug/2020:05:12:08 +0000 log is coming under 26/08/2020 05:08:00.000

[vijayakumarkb]

Thanks for the answer, let me try this, will update you.