Intermittent very slow autocomplete and metric requests against Checkmk 2.4.0p22, causing Grafana 502 after 30s timeout

[dio99]

What happened?

We are seeing intermittent performance problems with the official Checkmk Grafana data source.

The datasource works, but some requests sometimes become extremely slow and Grafana returns 502 Bad Gateway after its internal 30s proxy timeout.

This affects mainly:

• autocomplete endpoints
• metric query endpoints used by Explore / dashboards

The issue is intermittent:

• sometimes the same requests complete in ~0.2s to ~2s
• sometimes they take 30s+
• in a few cases we have seen request durations in the Checkmk Apache access log around 34s, 40s, 52s, 121s, and even ~593-600s

Environment

• Grafana: 12.3.2
• Checkmk: 2.4.0p22
• Checkmk datasource plugin: 4.1.0
• Deployment: Kubernetes
• Datasource URL: internal Checkmk service behind Kubernetes service
  • http://checkmk.monitoring.svc.k8s.local:5000/checkmk

Symptoms

Grafana logs show repeated errors like:

Proxy request failed err="net/http: timeout awaiting response headers"
Request Completed ... status=502 ... duration=30.0s


Affected endpoints include for example:

/rest/check_mk/api/1.0/objects/autocomplete/sites
/rest/check_mk/api/1.0/objects/autocomplete/monitored_hostname
/rest/check_mk/api/1.0/objects/autocomplete/monitored_service_description
/rest/check_mk/api/1.0/objects/autocomplete/available_graphs
/rest/check_mk/api/1.0/objects/autocomplete/monitored_metrics
/rest/check_mk/api/1.0/domain-types/metric/actions/get/invoke
In Grafana UI this shows up as:

autocomplete dropdowns loading very slowly or failing
Explore failing to list services / graphs / metrics
occasional dashboard query failures with 502
Example Grafana log lines
logger=data-proxy-log ... path=/api/datasources/proxy/uid/<uid>/rest/check_mk/api/1.0/objects/autocomplete/available_graphs ... level=error msg="Proxy request failed" err="net/http: timeout awaiting response headers"
logger=context ... method=POST path=/api/datasources/proxy/uid/<uid>/rest/check_mk/api/1.0/objects/autocomplete/available_graphs status=502 ... duration=30.011s
The same pattern appears for:

monitored_service_description
monitored_hostname
sites
monitored_metrics
domain-types/metric/actions/get/invoke
Example Checkmk Apache access-log evidence
The corresponding requests do reach Checkmk and often return HTTP 200, but can take extremely long.

Examples from the Checkmk Apache access log:

POST /checkmk/check_mk/api/1.0/objects/autocomplete/available_graphs HTTP/1.1" 200 ... 600889560
POST /checkmk/check_mk/api/1.0/objects/autocomplete/available_graphs HTTP/1.1" 200 ... 593351897
POST /checkmk/check_mk/api/1.0/objects/autocomplete/monitored_service_description HTTP/1.1" 200 ... 593382752
The final field in the log appears to be request duration in microseconds, so the above looks like ~600s / ~593s.

We also saw earlier examples around:

~34s
~40s
~52s
~121s
At other times, the exact same endpoints complete quickly, for example:

~0.3s
~0.5s
~2.1s
What we checked
We first suspected Apache worker starvation in Checkmk.

Checkmk site Apache is running with:

prefork
mod_wsgi
mod_status enabled
ExtendedStatus On
We checked server-status during troubleshooting and did not see worker exhaustion:

BusyWorkers: 1
IdleWorkers: 4
So at least in the captured state, this did not look like Apache was fully saturated.

We also tuned the site Apache slightly:

higher prefork spare workers
lower KeepAliveTimeout
This seems to have improved things somewhat, but did not clearly eliminate the underlying issue.

Current hypothesis
The issue looks less like a transport/proxy problem and more like certain datasource requests becoming very expensive on the Checkmk side, especially:

available_graphs
monitored_service_description
domain-types/metric/actions/get/invoke
Possibly the plugin is generating requests that become very expensive depending on the selected host/service/graph context.

Can you advise on
Is this a known performance issue with plugin 4.1.0 against Checkmk 2.4.0p22?
Are there known expensive autocomplete paths or query patterns in the datasource?
Is there a recommended way to limit or disable the most expensive autocomplete calls?
Are there plugin settings or query patterns we should avoid in Explore?
Would you like us to collect debug traces for specific request bodies?

[BenediktSeidl]

Thanks for your detailed report.

This plugin should not do anything out of the ordinary. So I would assume you see similar behavior when using the Checkmk user interface. Have you experienced this?

Do you have access to the official Checkmk support? Can you reduce your case to the endpoint domain-types/metric/actions/get/invoke and check if a simple query (Graph "Time usage by phase", Service "Check_MK", Last 24 hours) also results in huge variance in runtime duration? This way we could completely eliminate the role of this plugin, as this is an official supported REST-API endpoint.

Sorry that I don't have a easy solution for your problem and only point in different directions. I'm really curious to find out what causes your problems. Currently I can not imagine that the Grafana plugin is the culprit, but lets find out together :-)

[BenediktSeidl]

Can you also provide part of ~/var/log/apache/access_log that shows some slow requests?

[dio99]

sorry for slow... has been little to much at work ans sick :) but cant provide the logs now
we had to limit the query in for the user in grafana so we just listed some of all sources :)

nope we are using the RAW version so no support.. if i do som more test later on i can provide some of the logs from apache :)