Splunk having issues with offsetting TZ for epochtime

[the_wolverine]

I'm trying to set a TZ for epoch time but Splunk is not accepting it. Is there an issue with offsetting using epoch time? I know that TZ offsetting will work with human readable time, but that requires the raw event which we remove (ultimately) from our CEF logs in Production.

Here is the sample event:

CEF:0|Unix|Unix||arcsight:9:2|session closed|Low| eventId=106371 rawEvent=<86>Jul 12 12:10:16 relay-uat crond[18480]: pam_unix(crond:session): session closed for user root\n categorySignificance=/Informational categoryBehavior=/Access/Stop categoryDeviceGroup=/Operating System catdt=Operating System categoryOutcome=/Success categoryObject=/Host/Application/Service art=1373656226102 deviceSeverity=info rt=1373631016000 dhost=relay-test dst=192.168.0.1 duser=root cs1=crond cs2=authpriv cs4=18480 flexString1=PST flexString2=Mail cs1Label=Module cs2Label=Facility cs4Label=PID cn1Label=File Descriptor c6a2Label=Source IPv6 Address c6a3Label=Destination IPv6 Address ahost=splunkforwarder1.corp.com agt=192.168.0.2 av=5.2.6.6434.0 atz=Etc/GMT+0 aid=SLKSJDFKDSFJSKKLDSF-UAaxTA== at=syslog dvchost=relay-uat dvc=192.168.0.3 dtz=PTZ deviceFacility=authpriv deviceProcessName=crond _cefVer=0.1

Using the following props:

[custom_sourcetype]
TZ=US/Pacific
TIME_PREFIX = \srt=
TIME_FORMAT = %s%3N
#TIME_PREFIX = rawEvent\=<\d+>
#TIME_FORMAT = %b %d %H:%M:%S

Using the "rt" value for TIME_PREFIX does NOT work. No offsetting is performed. However, using the rawEvent's human readable time works as expected. Basically, Arcsight takes the rawEvent time, creates a unixtime (UTC) and when Splunk receives the event, it is seen as UTC and completely wrong.

Trying to find out if this is a bug or (highly unlikely) a misconfiguration.

[the_wolverine · Accepted solution]

The answer is epoch time is UTC -- the sending host is sending the wrong epoch time if it has to be offset.

[sowings]

The only CEF references I could find (an example is here) don't say anything about the 'art' field; it might be vendor specific.

Given the 'rawEvent' field, this smells like syslog being sent through some intermediary agent which is then emitting CEF. The CEF agent is translating the raw time of the event, presumably with some understanding of the raw event's time zone. Since you indicate in your question that there's some US/Pacific time zone going on, I'd suspect that the art= field is the "correct' epoch time for the event, given that it translates to Jul 12 12:10:16 in PDT.

That being said, TIME_FORMAT with %s ignoring TZ sounds perfectly valid to me, as %s is UTC by definition.

Consider using either the rawEvent's time stamp, or the art= field, or skip the CEF agent altogether!

[sowings]

We're both right. I converted my epoch times to PDT, which is presently 7 hours behind GMT. I still assert that if his events are putatively in US/Pacific, art= is the right field.

[Gilberto_Castil]

I think you have the fields mixed up:

art=1373656226102 or Fri, 12 Jul 2013 19:10:26 GMT

and

rt=1373631016000 or Fri, 12 Jul 2013 12:10:16 GMT

which incidentally matches the record for

rawEvent=<86>Jul 12 12:10:16

Understanding that my indexer is in a EST (GMT-4) timezone, I would expect to see this record to show up with a local time of Fri, Jul 2013 08:10:16 EST (time_zone=0). And that is exactly what happens.

http://snag.gy/nJAWI.jpg

--
That is, of course, if rt is the right field to define time.

[sowings]

Seconded. Epoch time is epoch time is epoch time.

That record is NUTS. There's 'rt=' which is Jul 12 05:10:16 in PDT, but there's also 'art=' which translates to Jul 12 12:10:16. If that's how the data is natively stored--with two "epoch" times, seven hours apart--may /dev/null have mercy on your soul.

[kristian_kolb]

epoch is always in UTC, thus no timezone should be applied. It seems to be the error of ArcSight to assume that the human readable timestamp is also in UTC, which perhaps it is not.

The best (only?) way would be to use the human readable timestamp instead of the epoch.