topic Re: Substituting _time with an extracted time field changing behavior unexpectedly in Getting Data In

Substituting _time with an extracted time field changing behavior unexpectedly

aholzer — Fri, 11 Apr 2014 14:58:10 GMT

Details:

The data is coming in from syslog and the time that I want to base my searches off of is in fact the "localtime" contained inside the message (the actual time the event occurred on the se rver) rather than the timestamp of the syslog message itself
My end goal is to catch events that occur within 1second of each other as long as the "channel" is the same and the sourcetypes differ.
I test that my logic works for two events that I've identified as matching (the two sample events provided), but when I expand my timerange, then my results are drastically changed and I don't get expected results such as the transaction of the two events I've identified.

I have the following 2 sample events:

sourcetype A
2014-04-11T04:00:15.270885-04:00 -  Alert - string1 - severity[Alert] source[string3] ip[-] description[description1] details[] reason[EventSet] localtime[2014/04/11 04:00:02.0 EDT] time[2014/04/11 08:00:02.0 UTC] count[1] value[x] 
sourcetype B
2014-04-11T04:00:03.312903-04:00 -  Alert Clear - string2 - severity[Alert] source[string3] ip[-] description[description2] details[] reason[EventReset] localtime[2014/04/11 04:00:03.0 EDT] time[2014/04/11 08:00:03.0 UTC] count[1] value[x]

The important information is the "localtime", which is being extracted into a field of the same name, and the "source", which is being extracted into a field named channel. So I can abbreviate the data as follows:

event1: _time="2014-04-11T04:00:15.270885-04:00", sourcetype=A, channel=mysource1, localtime="2014/04/11 04:00:02.0 EDT"
event2: _time="2014-04-11T04:00:03.312903-04:00", sourcetype=B, channel=mysource1, localtime="2014/04/11 04:00:03.0 EDT"

If I run the below search I get the 2 results listed above:

index=myindex earliest=@d+4h latest=@d+4h+1m ((sourcetype=A "string1") OR ((sourcetype=B OR sourcetype=C) "string2")) (channel="string3" OR channel=string4) | eval localtime=strptime(localtime, "%Y/%m/%d %H:%M:%S.0 %Z")

But if I add the below eval statement, I only get event1 in my results, even though the values in _time still fall within the earliest-latest range:

index=myindex earliest=@d+4h latest=@d+4h+1m ((sourcetype=A "string1") OR ((sourcetype=B OR sourcetype=C) "string2")) (channel="string3" OR channel=string4) | eval localtime=strptime(localtime, "%Y/%m/%d %H:%M:%S.0 %Z") | eval _time = localtime

Something that makes this even odder is that if I run the above search with a transaction in it, both events get caught as I'd expect in my transaction:

index=myindex earliest=@d+4h latest=@d+4h+1m ((sourcetype=A "string1") OR ((sourcetype=B OR sourcetype=C) "string2")) (channel="string3" OR channel="string4") | eval localtime=strptime(localtime, "%Y/%m/%d %H:%M:%S.0 %Z") | eval _time = localtime | transaction channel maxpause=2s

This is the behavior I'm looking for in the end, but sadly the story doesn't end here. If I now use the above search, and increase latest to @d+4h+10m, then the transaction is lost...

index=remyindex earliest=@d+4h latest=@d+4h+10m ((sourcetype=A "string1") OR ((sourcetype=B OR sourcetype=C) "string2")) (channel="string3" OR channel="string4") | eval localtime=strptime(localtime, "%Y/%m/%d %H:%M:%S.0 %Z") | eval _time = localtime | transaction channel maxpause=2s

Any help would be greatly appreciated.

Re: Substituting _time with an extracted time field changing behavior unexpectedly

marcoscala — Mon, 28 Sep 2020 16:22:16 GMT

Aholzer,
if the real timestam of the event you get is stored in the 'localtime' field, my suggestion is to customize timestamp recognition and set _time to that timestamp instead of the syslog timestamp.

You can do it setting the correct TIME_PREFIX and TIME_FORMAT
TIME_PREFIX=localtime[

Marco

Re: Substituting _time with an extracted time field changing behavior unexpectedly

somesoni2 — Fri, 11 Apr 2014 15:43:05 GMT

Try instead of eval, use rename. (|rename localtime as _time)

Re: Substituting _time with an extracted time field changing behavior unexpectedly

aholzer — Fri, 11 Apr 2014 15:43:14 GMT

Let me test that. I don't think that it will solve everything though. I'll report back after I make the change.

Re: Substituting _time with an extracted time field changing behavior unexpectedly

marcoscala — Fri, 11 Apr 2014 15:46:57 GMT

to be honest I'm quite busy and couldn't check carefully your searches if there's some other mistakes. Sometimes, bwt, _time field gives problem with substitutions or other operation. That's why I suggested a cleaner approach from the beginning, with the correct time extraction.

Let me know!

Marco

Re: Substituting _time with an extracted time field changing behavior unexpectedly

aholzer — Fri, 11 Apr 2014 15:49:41 GMT

I appreciate it. Doing what you suggest is a good idea and will eliminate at least one point of failure. The server is restarting now, I'll need to wait to get some data before I can test if it's been fixed or not. Again, thanks for your input

Re: Substituting _time with an extracted time field changing behavior unexpectedly

aholzer — Fri, 11 Apr 2014 19:30:48 GMT

Marco,

From preliminary testing it would seem that this did the trick. I found a couple of events that I should be catching under my logic (after the time change), I've tested with a short and a wide timerange, and in both cases the events come up in a transaction.

Thanks!

Re: Substituting _time with an extracted time field changing behavior unexpectedly

marcoscala — Sat, 12 Apr 2014 06:19:14 GMT

Glad it worked! Please don't forget to mark the question answered!

And happy Splunking!
Marco