Splunk Search

... | append [ | makeresults ] makes the search time explode

rikinet
Path Finder

I have a dashboard with multiple line charts showing values over time. I want all charts to have the same fixed time (X) axis range, so I can compare the graphs visually. Something like the fixedrange option in the timechart command. However, I use a simple "| table _time, y1, y2, yN" instead of timechart, because I want the real timestamps in the graph, not some approximation due to timechart's notorious binning.

To mimic the fixedrange behavior, I append a hidden graph with just two coordinate points (t_min|0) and (t_max|0):

 

...
| table _time, y1, y2, y3, ..., yN

| append [
  | makeresults
  | addinfo
  | eval x=mvappend(info_min_time, info_max_time)
  | mvexpand x
  | rename x as _time
  | eval _t=0
  | table _time, _t
]

 


This appended search appears very cheap to me - it alone runs in less than 0.5 seconds. But now I realized that it makes the overall search dramatically slower, about x10 in time. The number of scanned events explodes.

This even happens when I reduce to:

 

| append maxout=1 [ | makeresults count=1 ]

 


What's going on here? I would have expected the main search to run exactly as fast as before, and the only toll should be the time required to add one more line with a timestamp to the end of the finalized table, no?

Labels (1)
0 Karma
1 Solution

rikinet
Path Finder

I found the solution. In the end, it boiled down to a stupid mistake in a defined macro.

My search really looked like this:

`my_search(param1, param2)`
| `fixedrange`


...which expanded to the following snippet from my original question:

```from macro "my_search":```
...
| table _time, y1, y2, y3, ..., yN


```from macro "fixedrange":```
| append [
  | makeresults
  | addinfo
  | eval x=mvappend(info_min_time, info_max_time)
  | mvexpand x
  | rename x as _time
  | eval _t=0
  | table _time, _t
]

 
But `my_search` was defined like this:

| search index=... sourcetype=... param1=... param2=...

 
Note the leading pipe, which shouldn't have been there!

Now, the search optimization produced different results, depending on whether the 2nd macro was applied or not.

Case A (fast):

`my_search(param1, param2)`

... produced:

| search (sourcetype=... param1=... param2=...)
| search index=...
| ...


Case B (slow):

`my_search(param1, param2)`
| `fixedrange`

... produced:

| search
| search (index=... sourcetype=... param1=... param2=...)
| ...

 

... and obviously the first search term in case B was causing the headache, although the final result set was identical in both cases.

Ouch!

View solution in original post

PickleRick
SplunkTrust
SplunkTrust

That does indeed seem strange. Is this the last part of the search? Do the search dashboard and search log show anything significantly changing after you add this append command?

0 Karma

gcusello
SplunkTrust
SplunkTrust

Hi @rikinet ,

in addition to the perfect solution from @bowesmana , you could test the Horizon Chart add-on (https://splunkbase.splunk.com/app/3117) that gives you the requested parallel visualization.

Ciao.

Giuseppe

0 Karma

bowesmana
SplunkTrust
SplunkTrust

Not sure why that is happening - does search log show anything

Have you tried using appendpipe rather than append - that will run after the initial search, not before

 

| appendpipe [
  | stats count 
  | addinfo
  | eval x=mvappend(info_min_time, info_max_time)
  | mvexpand x
  | rename x as _time
  | eval _t=0
  | table _time, _t
  ]

 

0 Karma

rikinet
Path Finder

I found the solution. In the end, it boiled down to a stupid mistake in a defined macro.

My search really looked like this:

`my_search(param1, param2)`
| `fixedrange`


...which expanded to the following snippet from my original question:

```from macro "my_search":```
...
| table _time, y1, y2, y3, ..., yN


```from macro "fixedrange":```
| append [
  | makeresults
  | addinfo
  | eval x=mvappend(info_min_time, info_max_time)
  | mvexpand x
  | rename x as _time
  | eval _t=0
  | table _time, _t
]

 
But `my_search` was defined like this:

| search index=... sourcetype=... param1=... param2=...

 
Note the leading pipe, which shouldn't have been there!

Now, the search optimization produced different results, depending on whether the 2nd macro was applied or not.

Case A (fast):

`my_search(param1, param2)`

... produced:

| search (sourcetype=... param1=... param2=...)
| search index=...
| ...


Case B (slow):

`my_search(param1, param2)`
| `fixedrange`

... produced:

| search
| search (index=... sourcetype=... param1=... param2=...)
| ...

 

... and obviously the first search term in case B was causing the headache, although the final result set was identical in both cases.

Ouch!

bowesmana
SplunkTrust
SplunkTrust

Thanks for closing the loop

0 Karma
Get Updates on the Splunk Community!

How to Get Started with Splunk Data Management Pipeline Builders (Edge Processor & ...

If you want to gain full control over your growing data volumes, check out Splunk’s Data Management pipeline ...

Out of the Box to Up And Running - Streamlined Observability for Your Cloud ...

  Tech Talk Streamlined Observability for Your Cloud Environment Register    Out of the Box to Up And Running ...

Splunk Smartness with Brandon Sternfield | Episode 3

Hello and welcome to another episode of "Splunk Smartness," the interview series where we explore the power of ...