topic Re: Occasional error in converting time stamps in Getting Data In

Occasional error in converting time stamps

tristanmatthews — Thu, 17 Oct 2013 22:06:42 GMT

Hi,

I'm seeing a very weird behavior from splunk and wondering if anyone knows whats going on.

My input is a cvs file with unix time stamps, which splunk seems to be reading in properly

one of my time stamps is

1382037457.102446000

both in the csv file and as read by splunk

splunk gives an event time of:
10/19/13 6:38:12.700 AM

which seems weird sense this is from a live feed so it should have just happened. If i google a general unix time stamp converter I get:
10 / 17 / 13 @ 11:17:37am PST

which seems about right. This isn't happening all the time, on a different search I get ~ 116k events and see 205 or .2% with weird times. For those events the times

1381940863.218676000
1382044524.744784000

which convert to give times of

10 / 16 / 13 @ 8:27:43am PST
10 / 17 / 13 @ 1:15:24pm PST

but splunk give times of
10 / 17 / 13 @ 2:55:00.000 PM (PST)
10 / 17 / 13 @ 2:15:24.000 PM (PST)

so yeah, I'm more then a little confused.

Anyone know whats going on?

-Tristan

Re: Occasional error in converting time stamps

kristian_kolb — Thu, 17 Oct 2013 23:32:49 GMT

Have you tried setting the TIME_FORMAT attribute in props.conf?

[your source or sourcetype]
TIME_FORMAT = %s.%9N

http://docs.splunk.com/Documentation/Splunk/latest/Admin/Propsconf
http://wiki.splunk.com/Where_do_I_configure_my_Splunk_settings

UPDATE

For the incorrectly parsed events, look at the values for timestartpos and timeendpos - the are default fields that exist for all events with a timestamp, and tell you the offsets within an event between which the timestamp information was found. This will show if Splunk tried to read the wrong part of the event for timestamp information.

Also, look in the splunkd.log for DateParserVerbose messages, which may reveal some information regarding the parsing;

index=_internal sourcetype=splunkd DateParserVerbose

It may also be wise to set the proper attributes for TIME_PREFIX and MAX_TIMESTAMP_LOOKAHEAD

Post a few of the incorrectly parsed events (whole events), along with the time Splunk figured, as well as the relevant part of props.conf for the sourcetype.

Re: Occasional error in converting time stamps

BenAveling — Thu, 17 Oct 2013 23:55:42 GMT

This doesn't look like a timezone problem.

If it was, the calculation would be out by a round number of hours.

Consider:

perl -e "print scalar gmtime(1382037457.102446000)"

Thu Oct 17 19:17:37 2013

splunk gives

10/19/13 6:38:12.700 AM

perl -e "print scalar gmtime(1381940863.218676000)"

Wed Oct 16 16:27:43 2013

splunk gives

10/17/13 @ 2:55:00.000 PM (PST)

I'm wondering if splunk could be picking up the wrong number when it goes looking for seconds-past-epoch; either using a different number from the same event, or a number from a different event entirely.

You said this is from a .csv file. Is there any chance that any of your fields have embedded commas that are confusing it, or that the end of line is being mangled? Are you able to share the misbehaving lines?

Re: Occasional error in converting time stamps

tristanmatthews — Fri, 18 Oct 2013 22:55:27 GMT

Thanks Kristian,

So yeah I'm inheriting this system and it looks like they didn't set the source formate explicitly so I'm reindexing all the data (oh so much fun!). It looks like everything is ok so far, so I'm hoping that has fixed my problem, but I'll check those other fields once its fully done.