How to alert using _indextime for window instead of _time

[stroud_bc]

I have a number of hourly correlation searches which trigger on Office 365 API events for use cases such as suspicious authentication attempts, file downloads, etc.

The problem I run into is that the event latency (difference between _time and _indextime) for the Office 365 API spans from an hour or so to 5-12 hours, sometimes up to an entire day, in a very irregular pattern, and our correlation searches often miss events entirely since they are indexed so long after they occur. I would prefer to be able to alert on them based on when they were written to disk. I don't care how long ago the event occurred as much as I do the fact that it did!

Current Behavior: An event occurs at 1:15 but is not indexed until 2:15. The 2:00 search misses the event because it hadn't been indexed yet, while the 3:00 misses the search because it is "more than an hour ago"

Known (but not at all preferred solution): Extend my alerting window backward
Downside: Requires either a less-frequent schedule (if setting the window to last 4 hours and only running the search every 4 hours) or many duplicate alerts (if setting the window to last 4 hours and letting the search continue to run every hour).

Preferred Solution: Use _indextime instead of _time for alert window
I was quite sure that I read about a way to configure an alert or a search to use _indextime instead of _time to determine which events fall within its' time window. If I'm crazy, tell me, but the ideal behavior would be as follows:

Desired Behavior: An event occurs at 1:15 but is not indexed until 2:15. The 2:00 search misses the event because it hadn't been indexed yet, while the 3:00 catches the event because the _indextime is within the alerting window of the last hour.

Many thanks!

[aberkow · Accepted solution]

We do something similar for a commit trigger alert. To first verify this is the behavior, try running this search:

index=whatever
| eval LogTime=_time
| eval indexTime=_indextime
| eval _time=_indextime
| table _time, LogTime, indexTime

This plays a little seat change with the values to extract LogTime and indexTime, and then overwrites the _time field with _indextime. If you're confident that you want to alert on _indextime instead of _time, use the third line of the search to do that (you might want a
case or if statement to only do this in certain cases) but I think this should get you the desired result.

Does this help?

[triest]

Before putting something like this in production, I would set _index_earliest.  That way you can still filter the events fairly early just to the ones that are of interest to you.  So you might search a week's worth of logs, but then _index_earliest limits it to those index within the last hour before the evals run.

[stroud_bc]

Does the saved search respect this switcheroo? I guess I assumed the events were selected based on timestamp prior to the execution of the actual search. What is the order of execution there?

If it does, then this certainly does help 🙂

[stroud_bc]

Works like a charm-- thanks!

I do wish there were a way to toggle which field was used by the actual timestamp parser. This works for my O365 authentication events, but could become very resource intensive if applied on all of my searches, since the search window is so much longer. Ah well.

[aberkow]

Hmm...you could do an extraction at index time but that might be even more expensive and is outside my expertise, but could be worth a different question.

Glad I could help! Please accept the answer if you get a chance.

[aberkow]

You're right that it will pull events in based on their actual timestamp, that being said, you can have a longer alert window (however long the difference is b/w timestamp and indextime) and then alert with a filter. For example, something like a 2 hour lookback, but still run the alert every 5, 10 or whatever timeframe you want, and filter down to that timeframe:

search from above...
| where _time>relative_time(now(), "-5m@m")

This will just alert you on when index time occurred in the past 5 minutes, regardless of what logs you pulled in. There isn't a great solution otherwise if you're running into an issue where index time and log time are very different that I know of. Does this make sense?