Comparing search head hardware changes and their impact on Splunk platform search performance

CPU configuration

The migration was occurring from the 2.70 Ghz to the 3.90 Ghz processors; everything else is used for comparison purposes only.

• Intel(R) Xeon(R) Platinum 8168 CPU @ 2.70GHz — old servers
• Intel(R) Xeon(R) Gold 6250 CPU @ 3.90GHz — server new-003
• Intel(R) Xeon(R) Gold 6154 CPU @ 3.00GHz — monitoring server (VM)
• Intel(R) Xeon(R) Gold 6444Y @ 3.6Ghz — other SHC

The newer 3.90 Ghz processor has fewer total cores, and this proved to be a challenge. This image shows the percent CPU per server:

The load balancer unintentionally assigned too many users to the new‑003 server. When there were more than 100 users on this search head, it started to hit the CPU limits and caused general chaos (concurrency quotas reached, slower searches). The Splunk platform search performance comparison section was set up to ignore the time periods where 100% CPU was in use, as that changes the results.

I/O performance

To determine IOStats through the introspection data, run this search:

index=_introspection sourcetype=splunk_resource_usage component=IOStats host IN (...)
| eval avg_total_ms = 'data.avg_total_ms' 
| where avg_total_ms>0
| timechart minspan=60s partial=f limit=99 span=2h perc95(avg_total_ms) BY host

This image shows the Splunk platform introspection data average service times:

The first finding is that while the new-003 server has faster CPUs, it has slower I/O compared to the previous hardware. This finding was a surprise. Note that the old servers mount the drives as NVMe (/dev/nvme0n1), while the new servers have the drive mounted as an "sd" drive (/dev/sdc).

How do you test scheduled searches?

A few options were tried for testing scheduled searches. The first was the remote_searches.log:

index=_internal `indexerhosts` source="/opt/splunk/var/log/splunk/remote_searches.log" "StreamedSearch - Streamed search connection closed" OR "StreamedSearch - Streamed search search starting" 
| rex "(starting|closed): search_id=(?P<search_id>[^,]+)" 
| search NOT search_id=*RemoteStorageRetrieveBuckets*
| stats range(_time) AS runtime, last(_raw) AS _raw BY search_id, host
| stats max(runtime) AS slowest_time, last(_raw) AS raw_query BY search_id

This alternative measures the indexing tier execution time of searches. Subsearches are found this way, and searches including subsearches will not include the time involved in running subsearches (which is different from how the _audit log records total_run_time). However, this isn't the fastest way to find the data — _introspection sourcetype=search_telemetry or index=_audit records this data in an easier-to-use format.

This query runs on the indexing tier, but it is quite inefficient. It queries each indexer to find the slowest runtime, and includes the raw data for troubleshooting whether the correct results are being found. This finds any subsearch executing on the indexing tier and appears to be extremely close to what the introspection data shows.

This source was not used, as it only provided phase 0 runtimes and the main target was the phase 1 or search head level runtimes.

The Splunk platform query-based approach

Because dashboard searches can change the time period searched over, only scheduled searches were included to simplify the query. Because the information on the scheduled searches exists in the audit.log, the data was queried from the audit.log to confirm which scheduled search was being worked with.

The introspection data was then queried for the performance information related to the phase 0 and phase 1 runtimes, excluding any queries running for less than 2 seconds.

This approach started simple, but because a large variation was found between results, more and more stats were added. A few different methods were also created to classify the searches:

• The "type" of search — for example, whether it
  • runs a search that relies on an external system such as a database or LDAP
  • runs a metadata, stats, or eventcount command
  • is local to the search head (for example, loadjob, inputlookup, or rest, which might or might not be local depending on the splunk_server argument)
  • looks like a standard search involving the indexing tier (for example, search, multisearch, set, union, or from)
• Classification based on "runtime" to group searches together, with the expectation that searches with a longer runtime provide a more consistent performance difference.
• The standard deviation and average response time were also determined. This allows for a rough percentage of how much a search runtime varies on each hardware type.

The query

| multisearch 
    [ search index=_introspection sourcetype=search_telemetry `searchheadhosts` perf.search_runtime_secs>2 search_id=scheduler*
        | eval hour=strftime(_time, "%H"), minute=strftime(_time, "%M"), dayofweek=strftime(_time, "%a") 
    | rename desc.app AS app
    | fields phases.phase_0.elapsed_time_aggregations.max, phases.phase_1.elapsed_time_aggregations.max, host, search_id app ] 
    [ search index=_audit `searchheadhosts` info=completed total_run_time>2 search_id="'scheduler*" has_error_warn=false fully_completed_search=true 
    | eval hour=strftime(_time, "%H"), minute=strftime(_time, "%M"), dayofweek=strftime(_time, "%a") 
    | eval search_id=trim(search_id,"\'")
    | rex ", savedsearch_name=\"(?P<savedsearch_name>.*?)\", search_startup_time"
    | rex "(?s), search='(?P<search>.*)\]$" 
    | rex field=search mode=sed "s/\n/ /g" 
    | eval search=if(substr(search,len(search),len(search)-1)=="'",substr(search,0,len(search)-1),search)
    | rex field=search "^(\s*\|\s*)?\s*(?P<command>\S+)" 
    | rex field=search "(\||^)\s*(?P<subsearch>(append|union|multisearch|set|appendcols|appendpipe|join|map))"
    | eval subsearch=if(isnotnull(subsearch),"true","false")
    | eval search_type=case(command="ldapsearch" OR command="runaql" OR command="dbxquery","remote_server",command="tstats" OR command="metadata" OR command="eventcount","metadata",command="makeresults" OR command="inputlookup" OR command="rest" OR command="loadjob" OR command="noop" OR command="stats","local",match(command,"^trackme"),"customcommand",command="multisearch" OR command="union" OR command="savedsearch" OR command="datamodel" OR command="from" OR command="set","search",command="`","search",1=1,command)
    | fields total_run_time, savedsearch_name, search_id, result_count, event_count, scan_count, search_type, app subsearch ] 
| eval type="new"
| selfjoin search_id app
| table _time, phases.phase_0.elapsed_time_aggregations.max, phases.phase_1.elapsed_time_aggregations.max, host, savedsearch_name, total_run_time, result_count, event_count, scan_count search_type app subsearch
| bin _time span=24h 
| stats count, avg(phases.phase_1.elapsed_time_aggregations.max) AS avg_sh_time, avg(phases.phase_0.elapsed_time_aggregations.max) AS avg_indexer_time, avg(total_run_time) AS total_run_time, avg(scan_count) AS scan_count, avg(event_count) AS event_count, avg(result_count) AS result_count, values(subsearch) AS subsearch, stdev(phases.phase_1.elapsed_time_aggregations.max) AS phase_1_stdev, stdev(phases.phase_0.elapsed_time_aggregations.max) AS phase_0_stdev by savedsearch_name, type, _time, search_type, app
| eval phase_1_diff=round(phase_1_stdev/avg_sh_time,3), phase_0_diff=round(phase_0_stdev/avg_indexer_time,3)
| eventstats perc95(phase_1_diff) AS phase_1_diff, perc95(phase_0_perc) AS phase_0_diff, avg(phase_0_diff) AS avg_phase_0_diff, avg(phase_1_diff) AS avg_phase_1_diff by savedsearch_name, search_type, app
| eval day=strftime(_time, "%a") 
| eval hour=strftime(_time, "%H")
| sort 0 savedsearch_name type
| streamstats window=1 global=f current=f reset_on_change=true values(avg_sh_time) AS avg_new_sh_time, values(avg_indexer_time) AS avg_new_indexer_time, values(scan_count) AS prev_scan_count, values(event_count) AS prev_event_count, values(result_count) AS prev_result_count by savedsearch_name
| eval shc_diff=((avg_sh_time/avg_new_sh_time)-1)*100, indexer_diff=((avg_indexer_time/avg_new_indexer_time)-1)*100
| eval ratio=(100/avg_sh_time)*avg_indexer_time
| foreach avg* phase_* ratio shc_diff total_run_time [eval <<FIELD>>=round('<<FIELD>>',2)]
| rangemap field=avg_sh_time 1-3=1-3 4-6=4-6 7-10=7-10 11-30=11-30 31-60=31-60 61-120=61-120 121-300=121-300 301-600=301-600 default=over600

This search was also tried on hourly data, but only a fraction of the overall scheduled searches run hourly and the results overall didn't look that different.

The above search itself is very slow. To gather 7 days of data, it took 81.659 seconds on the slowest indexer, and 407 seconds in total for the search head to complete the query. This resulted in 25,257 stats.

To run this over 30 days took 2,242 seconds and produced 108,776 stats; the phase 0 failed due to errors and reported 0.03 seconds in the introspection data.

Variance between scheduled search runtimes

The initial expectation was that as the runtimes extended beyond the 30–60 second mark, more consistency would be seen from the runtimes. This image shows the phase 1 (search head) runtimes as a percentage difference between runs on the same type of hardware, split by runtime:

This image shows the phase 0 (indexer) runtimes as a percentage difference between runs, split by runtime:

This did not prove to be the case, and the phase 0 runtimes were also highly variable at the indexing tier. Breaking down by commands was also tried, in case the variance came from external systems such as databases or LDAP. This image shows the phase 1 (search head) runtimes as a percentage difference between runs on the same type of hardware, split by search type:

This image shows the phase 0 (indexer) runtimes as a percentage difference between runs, split by search type:

A longer comparison period was also tested — 30 days instead of 7 days — in case more data was needed for consistency, as this compares 1 day to the week(s) before. This image shows the phase 1 (search head) runtimes as a percentage difference between runs on the same type of hardware, split by runtime:

This image shows the phase 0 (indexer) runtimes as a percentage difference between runs on the same type of hardware, split by search runtime:

This image shows the phase 1 (search head) runtimes as a percentage difference between runs on the same type of hardware, split by search type:

The 30 day comparison versus the 7 day comparison wasn't that different; clearly the runtimes of scheduled searches vary more than expected. There were even scheduled searches varying by taking twice as long as a previous runtime in some cases.

Performance increases for the new hardware compared to the old hardware

To exclude the outliers, anything greater than 100 or less than -100 in terms of the performance difference was excluded, as this would move the averages too much. Only searches that appeared to vary less than 30% in their phase 1 runtimes were then included. There might be a better way to do the comparison, but this was sufficient for this purpose. This image shows the average scheduled search performance by search type over 7 days of data (the number is the % improvement compared to the old servers):

This image shows the average scheduled search performance by search runtime over 7 days of data (the number is the % improvement compared to the old servers):

This image shows the average difference between new and old search heads based on 7 days of scheduled search data, with long phase 1 times, broken down by runtime:

The 95th percentile shows that some searches are getting a significant benefit from the new hardware. This image shows the 95th percentile scheduled search performance by search type over 7 days of data (the number is the % improvement compared to the old servers):

This image shows the 95th percentile scheduled search performance by search runtime over 7 days of data (the number is the % improvement compared to the old servers):

This image shows the 95th percentile scheduled search performance by search runtime over 7 days of data, with long phase 1 runtimes (the number is the % improvement compared to the old servers):

The 30 day version took 2,242 seconds and produced 108,776 stats; the phase 0 failed due to errors and reported 0.03 seconds. This image shows the average scheduled search performance by type over 30 days of data (the number is the % improvement compared to the old servers):

This image shows the average scheduled search performance by runtime over 30 days of data (the number is the % improvement compared to the old servers):

This image shows the average difference between new and old search heads based on 30 days of scheduled search data, with long phase 1 times, broken down by runtime (the number is the % improvement compared to the old servers):

The 95th percentile shows that some searches are getting a significant benefit from the new hardware. This image shows the 95th percentile scheduled search performance by range over 30 days of data (the number is the % improvement compared to the old servers):

This image shows the 95th percentile scheduled search performance by type over 30 days of data (the number is the % improvement compared to the old servers):

This image shows the 95th percentile scheduled search performance by type over 30 days of data, with long phase 1 runtimes (the number is the % improvement compared to the old servers):