topic Re: appendcols subsearch skewing timestamps in some circumstances in Splunk Search

appendcols subsearch skewing timestamps in some circumstances

benhooper — Wed, 11 Nov 2020 11:09:15 GMT

I'm working with a system where each event has its own creation timestamp (always the same) and modification timestamp.

Currently, I want to get the most recent resolved event to establish the latest modification time and then get the earliest resolved event in order to establish the actual resolve time which I've achieved with the following search query:

It can be hard to visualise this so I've illustrated it below:

From the above screenshot, you can see that the incident with ID 1735 was initially resolved on 2020/11/06 at 11:56:27 but was modified twice, once at 11:57:54 and again at 15:02:42.

When the search only includes one post-resolution modification, this is exactly what's reported which can be seen in the following screenshot

However, the strange thing is that, when there's a second post-resolution modification, the timestamps get skewed into the future - resolve_time is supposed to remain as 2020/11/06 11:56:27.351 but gets changed to 2020/11/06 14:52:13.822. This can be seen in the following screenshot:

Through testing, I have:

Verified that the two searches work exactly as intended when copy and pasted into standalone searches.
Found that all timestamps (_time, creation_time, and modification_time) within the appendcols subsearch are skewed.

Even more bizarrely, the timestamps that are outputted aren't mentioned anywhere else. It's almost as if they're a result of some kind of search-time calculation.

Why is this happening?

Re: appendcols subsearch skewing timestamps in some circumstances

richgalloway — Wed, 11 Nov 2020 16:07:30 GMT

Be careful when using appendcols. The results of the subsearch are added to the results of the main search without regard to context. In other words, the first result of the subsearch is appended to the first result of the main search no matter what.

In the query here, the main search results are sorted in descending order by time whereas the subsearch is sorted in ascending order by time. That would appear to be inviting an erroneous appending of a field.

When the number and sequence of events is not guaranteed to be the same in both the main and sub searches, don't use appendcols. Try append, instead, and use stats to merge to two result sets.

Re: appendcols subsearch skewing timestamps in some circumstances

benhooper — Wed, 11 Nov 2020 16:39:29 GMT

Hi @richgalloway ,

Thanks for the response.

Yes, but I believe I countered the differing sort orders with the reverse?

I tried that but the resolve_time column is simply blank, unfortunately.

Re: appendcols subsearch skewing timestamps in some circumstances

richgalloway — Wed, 11 Nov 2020 18:52:21 GMT

Yes, the reverse should account for the different sort orders. Still, one must be very careful about the exact results of the subsearch when using appendcols.

I believe I see the error in my previous query. Please try this revision.

index=<index name> | where match(status, "resolved") | stats earliest(resolve_time) as resolve_time, latest(resolve_time) as modification_time, first(status) as status, first(creation_time) as creation_time by incident_id | eval modification_time = if(resolve_time == modification_time, "Unchanged", modification_time) | table incident_id, status, creation_time, resolve_time, modification_time

Re: appendcols subsearch skewing timestamps in some circumstances

benhooper — Thu, 12 Nov 2020 09:04:39 GMT

Hi @richgalloway ,

Thanks again but, unfortunately, a similar problem - the resolve_time and modification_time columns are blank.

Thanks.

Re: appendcols subsearch skewing timestamps in some circumstances

richgalloway — Thu, 12 Nov 2020 14:03:42 GMT

I'm not seeing where my mistake is. When you look at the Events tab, do you see the resolve_time field?

Re: appendcols subsearch skewing timestamps in some circumstances

benhooper — Thu, 12 Nov 2020 14:58:38 GMT

Hi @richgalloway ,

My apologies. I had a lot going on this morning so I ran your query without checking it properly.

The field resolve_time doesn't exist in the original events which explains what I was seeing so I've replaced both instances of (resolve_time) with (modification_time) and it appears to working perfectly and it's significantly simpler! Thank you very much!

I'm still confused why my search was acting that way in those circumstances but at least I have a solution now.

Thanks again!

Re: appendcols subsearch skewing timestamps in some circumstances

richgalloway — Thu, 12 Nov 2020 15:37:21 GMT

If your problem is resolved, then please click the "Accept as Solution" button to help future readers.