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!

Earn a $35 Gift Card for Answering our Splunk Admins & App Developer Survey

Survey for Splunk Admins and App Developers is open now! | Earn a $35 gift card!      Hello there,  Splunk ...

Continuing Innovation & New Integrations Unlock Full Stack Observability For Your ...

You’ve probably heard the latest about AppDynamics joining the Splunk Observability portfolio, deepening our ...

Monitoring Amazon Elastic Kubernetes Service (EKS)

As we’ve seen, integrating Kubernetes environments with Splunk Observability Cloud is a quick and easy way to ...