topic Re: Splunk index Timestamp half an hour out compared with log4j timestamp (Australia/Adelaide timezone is +9.5) in Getting Data In

Splunk index Timestamp half an hour out compared with log4j timestamp (Australia/Adelaide timezone is +9.5)

baerrach — Mon, 25 Jul 2011 02:27:00 GMT

My input from log4j looks like

2011-07-28 15:45:25,402  INFO  ...

And splunk is indexing it as

28/07/2011 16:15:25.402

i.e 30 minutes out, which is normal when systems don't handle half hour timezones like Australia/Adelaide.

I've tried configuring Splunk-4.2.2\etc\system\local\props.conf with

[sourcetype::log4j]
TZ = Australia/Adelaide

But its not doing what I expect.

CST stands for central standard time (which Australia supports too) and not the US CST.

Edit 1

It got worse in the afternoon

27/07/2011 05:53:05.360  2011-07-26 14:53:05,360

You can see that the minutes, seconds and milliseconds are correct.
The hour is now 13 hours out which pushes it into the next day.
And that is odd since 2011-07-26 14:53:05,360 + 9.5 = 2011-07-26 23:53:05,360 and not 27/07/2011 05:53:05.360

Edit 2

I removed the TZ in the props.conf and the timestamps are back to being 30 minutes out.
Looks like attempting to fix the problem by specifying the the TZ didn't work and made things worse.

Edit 3

Stupid image upload doesn't work try here: http://www.freeimagehosting.net/e0238

Re: Splunk index Timestamp half an hour out compared with log4j timestamp (Australia/Adelaide timezone is +9.5)

msorenson — Wed, 12 Oct 2011 17:15:24 GMT

It's probably because I was doing something wrong, but I've only had success in forcing the timezone by setting it per host.

Re: Splunk index Timestamp half an hour out compared with log4j timestamp (Australia/Adelaide timezone is +9.5)

baerrach — Thu, 13 Oct 2011 00:04:20 GMT

Can you provide explicit details on how you did this via host please?

Re: Splunk index Timestamp half an hour out compared with log4j timestamp (Australia/Adelaide timezone is +9.5)

msorenson — Thu, 13 Oct 2011 15:00:40 GMT

Actually I belive your stanza is wrong. According to the props.conf.spec, stanzas for sourcetypes only include the actual sourcetype value. Note the section on the precidence order and setting priorities. Precidence order between source > host > sourcetype is observed first. Priorities are observed second.

http://docs.splunk.com/Documentation/Splunk/latest/admin/propsconf

http://en.wikipedia.org/wiki/List_of_zoneinfo_timezones

So...
[log4j]
TZ = Australia/Adelaide

Re: Splunk index Timestamp half an hour out compared with log4j timestamp (Australia/Adelaide timezone is +9.5)

baerrach — Thu, 13 Oct 2011 23:27:52 GMT

Hmm, After following up on this post, I notice that my props file now has [log4j] as the stanza, because I was implementing

# Force log4j to only make events that start with log4j pattern, not based on newlines
# See http://splunk-base.splunk.com/answers/3682/need-to-customize-log4j-sourcetype

And I had commented out the TZ value.
Which probably means I've tried it before.
But who knows, will give it another try.

Re: Splunk index Timestamp half an hour out compared with log4j timestamp (Australia/Adelaide timezone is +9.5)

msorenson — Thu, 13 Oct 2011 23:39:29 GMT

I've found it pretty difficult to use [] to do anything. My guess is that its precidence is so low that something is bound to go first.

Try defining the TZ within a statement relative to source or host.

[source::...<psuedo PCRE>...]
TZ = Australia/Adelaide

[host::<someHost>]
TZ = Australia/Adelaide

Re: Splunk index Timestamp half an hour out compared with log4j timestamp (Australia/Adelaide timezone is +9.5)

baerrach — Fri, 14 Oct 2011 00:24:28 GMT

This didn't work

14/10/2011 11:22:27.959 (what splunk lists as the time in the search)
2011-10-14 10:52:27,959 (what log4j logs)

Re: Splunk index Timestamp half an hour out compared with log4j timestamp (Australia/Adelaide timezone is +9.5)

msorenson — Fri, 14 Oct 2011 02:12:26 GMT

Think the "," delimiting the fraction of a second is causing the problem? Not sure why Splunk would trip on that. You could try what gkanapathy suggested for a more extreme case (http://splunk-base.splunk.com/answers/6413/timestamp-problem-propsconf), but changed to the following.

<datetime>
   <define name="_mydatetimeformat" extract="year, month, day, hour, minute, second">
       <text><![CDATA[^.*(20[\d]{2})\-(0[1-9]|1[0-2])\-([0-3][0-9])\s+([01][0-9]|2[0-4]):([0-5][0-9]):([0-5][0-9])]]></text>
   </define>
   <timePatterns>
       <use name="_mydatetimeformat"/>
   </timePatterns>
   <datePatterns>
       <use name="_mydatetimeformat"/>
   </datePatterns> 
</datetime>

Where your props.conf will look something like:

[log4j]
DATETIME_CONFIG = /etc/apps/myapp/local/mycustomdatetime.xml
TZ = Australia/Adelaide

...or...

You can try specifying the a valid time format using TIME_FORMAT. I don't know if my example will work or not.

[log4j]
TIME_PREFIX = <regex to match up to date | ommit if date/time is a front of event>
TIME_FORMAT = %Y-%m-%d %T
TZ = Australia/Adelaide

A Google search for strptime resolved this site among others (http://pubs.opengroup.org/onlinepubs/007904975/functions/strptime.html)

...or...

Change the log4j's configuraton to not use the comma to delimit the sub-second.

Re: Splunk index Timestamp half an hour out compared with log4j timestamp (Australia/Adelaide timezone is +9.5)

baerrach — Fri, 14 Oct 2011 03:38:59 GMT

http://docs.splunk.com/Documentation/Splunk/latest/admin/propsconf says

For settings that are specified in multiple categories of matching [] stanzas,
[host::] settings override [] settings. Additionally,
[source::] settings override both [host::] and
[] settings.

Attempting

[source::*]
# Attempt to fix messageDate in wrong timezone
TZ = Australia/Adelaide

...

Nope still out by half hour.

Re: Splunk index Timestamp half an hour out compared with log4j timestamp (Australia/Adelaide timezone is +9.5)

baerrach — Fri, 14 Oct 2011 03:56:21 GMT

I think I need that precision.

From http://docs.splunk.com/Documentation/Splunk/latest/Data/TrainSplunktorecognizeatimestamp running

splunk train dates

And providing these log files snippets returns:

From:   2011-10-14 10:52:26,853 INFO  {}
Parsed: Fri Oct 14 10:52:26 2011
UTC Time:       1318551746
Time Region:    11-24
Date Region:    0-10
Subseconds:     0.853

So splunk can get the correct values, I dont know what it's doing when it displays it in the timestamp pick list to be half an hours out.

Re: Splunk index Timestamp half an hour out compared with log4j timestamp (Australia/Adelaide timezone is +9.5)

baerrach — Fri, 14 Oct 2011 04:01:12 GMT

I'm going to assume for know that this is a display bug and there is nothing I can do.

As you can see from the comment threads below, Splunk is able to parse my dates just fine. It's only in the timestamp in the field pick list on screen that is wrong.