Describe the bug
Summary
When a large number of process-check-result actions are sent in parallel for non-existing objects, the Icinga 2 engine becomes very slow and existing monitored objects can go into Overdue state.
This scenario happened on a production system where a passive monitoring integration sent process-check-result actions to Icinga2 targeting objects that were deleted from Icinga2 a few moments before, causing then the other existing Icinga2 objects to go in Overdue state.
We did not verify, but the same problem may be present in other Icinga 2 API endpoints.
Root cause investigation details
process-check-result requests for non-existing objects appear to trigger and exception, which in turn triggers the generation of diagnostic information, regardless on whether the verbose parameter is set to true. Based on our investigation, the code calls DiagnosticInformation, which internally internally triggers the invokation of dladdr(). That in turn contends on the glibc loader lock _dl_load_lock.
With thousands of such requests in parallel over a sustained period, requests begin blocking each other. Response times increase, and eventually the Icinga 2 engine appears to stop scheduling checks in time, causing regular objects to become overdue.
This behavior does not occur when process-check-result is sent for existing objects, because diagnostic information is not generated in that case.
Observed behavior
Sending many process-check-result requests in parallel for non-existing objects causes:
- very slow API responses taking tens of seconds, in many cases more than 60 seconds
- check scheduling delays
- monitored objects going into Overdue state
Sending the same amount of requests for existing objects does not show the same problem.
Investigation details
From our analysis, requests for non-existing objects trigger diagnostic handling that calls DiagnosticInformation. Inside that path, dladdr() is called many times per request, which appears to contend on _dl_load_lock.
Observing the latencies of the function dladdr() via eBPF, we observed that dladdr() took even more than 64 ms to execute (most likely waiting on _dl_loak_lock).
This may explain why many parallel invalid process-check-result requests can degrade the performance of whole engine.
To Reproduce
- Send 10k
process-check-result requests in parallel targeting non-existing objects over a continued period of time, for example with payload:
"type": "Service",
"service": f'myhost!non-existing-service',
"exit_status": 0,
"plugin_output": f"Test check result"
}
The following script can alternatively be used to reproduce the problem (the script sends 50k requests in total, with a limit of 10k parallel requests in-flight):
python3.9 /reproduce.py --host 'http://localhost:5665' --user root --password <pwd> --total 50000 --parallel 10000
#!/usr/bin/env python3
"""
icinga2_flood.py
Sends a fixed total number of passive process-check-results to Icinga2,
keeping a fixed number of requests in-flight at all times.
Uses asyncio + aiohttp for maximum concurrency without spawning OS threads.
Tested on Python 3.9+.
Usage:
python3 icinga2_flood.py --host https://icinga2.example.com:5665 \
--user root --password icinga \
--total 50000 --parallel 10000
"""
import argparse
import asyncio
import random
import string
import ssl
import time
import aiohttp
# ---------------------------------------------------------------------------
# Helpers
# ---------------------------------------------------------------------------
def random_name(prefix: str, length: int = 8) -> str:
"""Generate a random name that is very unlikely to exist in Icinga2."""
suffix = "".join(random.choices(string.ascii_lowercase + string.digits, k=length))
return f"{prefix}-nonexistent-{suffix}"
def build_payload(host_name: str, service_name: str) -> dict:
"""Build a process-check-result payload."""
exit_status = random.choice([0, 1, 2, 3])
status_text = {0: "OK", 1: "WARNING", 2: "CRITICAL", 3: "UNKNOWN"}[exit_status]
return {
"type": "Service",
"service": f'{host_name}!{service_name}',
"exit_status": exit_status,
"plugin_output": f"Synthetic check result: {status_text}"
}
async def send_check_result(
session: aiohttp.ClientSession,
base_url: str,
host_name: str,
service_name: str,
) -> dict:
"""POST a single process-check-result to the Icinga2 API."""
url = f"{base_url}/v1/actions/process-check-result"
headers = {
"Accept": "application/json",
"X-HTTP-Method-Override": "POST",
}
payload = build_payload(host_name, service_name)
start = time.monotonic()
try:
async with session.post(url, json=payload, headers=headers, timeout=aiohttp.ClientTimeout(total=60)) as resp:
body = await resp.text()
duration = time.monotonic() - start
return {
"host": host_name,
"service": service_name,
"status_code": resp.status,
"body": body,
"duration": duration,
}
except Exception as exc:
duration = time.monotonic() - start
return {
"host": host_name,
"service": service_name,
"status_code": None,
"error": f"{type(exc).__name__}: {exc}" if str(exc) else type(exc).__name__,
"duration": duration,
}
# ---------------------------------------------------------------------------
# Main loop
# ---------------------------------------------------------------------------
async def run_flood(base_url: str, user: str, password: str, total: int, parallel: int, target_host: str, target_service: str, verify_ssl: bool):
test_start = time.monotonic()
print(
f"Sending {total} requests to {base_url}\n"
f"Max in-flight: {parallel}\n"
"Press Ctrl+C to stop.\n"
)
ssl_ctx = ssl.create_default_context() if verify_ssl else False
connector = aiohttp.TCPConnector(
ssl=ssl_ctx,
limit=0,
ttl_dns_cache=300,
)
auth = aiohttp.BasicAuth(user, password)
semaphore = asyncio.Semaphore(parallel)
sent = 0
successes = 0
errors = 0
durations = []
async def bounded_send(host: str, svc: str) -> None:
nonlocal successes, errors, sent
async with semaphore:
r = await send_check_result(session, base_url, host, svc)
durations.append(r["duration"])
sent += 1
if "error" in r:
errors += 1
else:
successes += 1
async def print_progress() -> None:
while sent < total:
await asyncio.sleep(5)
if durations:
avg = sum(durations) / len(durations)
mn = min(durations)
mx = max(durations)
sorted_d = sorted(durations)
p95 = sorted_d[int(0.95 * len(sorted_d))]
host_display = f" (host: {target_host})" if target_host else " (random hosts)"
svc_display = f" (service: {target_service})" if target_service else " (random services)"
print(f"Progress: {sent}/{total} sent ({successes} ok, {errors} errors){host_display}{svc_display} — min: {mn:.3f}s, avg: {avg:.3f}s, p95: {p95:.3f}s, max: {mx:.3f}s")
async with aiohttp.ClientSession(connector=connector, auth=auth) as session:
progress_task = asyncio.create_task(print_progress())
tasks = [
asyncio.create_task(bounded_send(
target_host if target_host else random_name("host"),
target_service if target_service else random_name("svc")
))
for _ in range(total)
]
await asyncio.gather(*tasks)
progress_task.cancel()
if durations:
test_duration = time.monotonic() - test_start
avg_duration = sum(durations) / len(durations)
min_duration = min(durations)
max_duration = max(durations)
sorted_durations = sorted(durations)
p95_duration = sorted_durations[int(0.95 * len(sorted_durations))]
print(f"\nTotal test duration: {test_duration:.3f}s")
print(f"Done: {successes} ok, {errors} errors out of {total} total requests.")
print(f"Request duration — min: {min_duration:.3f}s, max: {max_duration:.3f}s, avg: {avg_duration:.3f}s, p95: {p95_duration:.3f}s")
else:
test_duration = time.monotonic() - test_start
print(f"\nTotal test duration: {test_duration:.3f}s")
print(f"Done: {successes} ok, {errors} errors out of {total} total requests.")
# ---------------------------------------------------------------------------
# Entry point
# ---------------------------------------------------------------------------
def main():
parser = argparse.ArgumentParser(description="Icinga2 process-check-result flood script")
parser.add_argument("--host", required=True, help="Icinga2 base URL, e.g. https://icinga.example.com:5665")
parser.add_argument("--user", required=True, help="API username")
parser.add_argument("--password", required=True, help="API password")
parser.add_argument("--total", type=int, default=50000, help="Total number of requests to send (default: 100)")
parser.add_argument("--parallel", type=int, default=10000, help="Max requests in-flight at the same time (default: 50)")
parser.add_argument("--target-host", type=str, default=None, help="Target host name (if not set, random hosts are used)")
parser.add_argument("--target-service", type=str, default=None, help="Target service name (if not set, random services are used)")
parser.add_argument("--no-verify-ssl", action="store_true", help="Disable TLS certificate verification")
args = parser.parse_args()
asyncio.run(run_flood(
base_url = args.host.rstrip("/"),
user = args.user,
password = args.password,
total = args.total,
parallel = args.parallel,
target_host = args.target_host,
target_service = args.target_service,
verify_ssl = not args.no_verify_ssl,
))
if __name__ == "__main__":
main()
Possible fix
A possible fix may be to not include the stack trace in the DiagnosticInformation, by setting DiagnosticInformation(ex, false)); here. On our test environment this change fixed the problem.
Another possible fix may be to produce the DiagnosticInformation only when the verbose API parameter is set to true, since the DiagnosticInformation is not returned anyway in the response in case the verbosity is not requested.
Expected behavior
Requests for non-existing objects should fail quickly and should not be able to significantly degrade the scheduler or cause unrelated checks to go overdue.
Screenshots
Your Environment
Include as many relevant details about the environment you experienced the problem in
- Version used (
icinga2 --version): r2.15.1-1
- Operating System and version: Red Hat Enterprise Linux 8.10
- Enabled features (
icinga2 feature list): api checker icingadb influxdb livestatus mainlog notification
Describe the bug
Summary
When a large number of process-check-result actions are sent in parallel for non-existing objects, the Icinga 2 engine becomes very slow and existing monitored objects can go into Overdue state.
This scenario happened on a production system where a passive monitoring integration sent
process-check-resultactions to Icinga2 targeting objects that were deleted from Icinga2 a few moments before, causing then the other existing Icinga2 objects to go in Overdue state.We did not verify, but the same problem may be present in other Icinga 2 API endpoints.
Root cause investigation details
process-check-resultrequests for non-existing objects appear to trigger and exception, which in turn triggers the generation of diagnostic information, regardless on whether theverboseparameter is set totrue. Based on our investigation, the code calls DiagnosticInformation, which internally internally triggers the invokation ofdladdr(). That in turn contends on the glibc loader lock_dl_load_lock.With thousands of such requests in parallel over a sustained period, requests begin blocking each other. Response times increase, and eventually the Icinga 2 engine appears to stop scheduling checks in time, causing regular objects to become overdue.
This behavior does not occur when
process-check-resultis sent for existing objects, because diagnostic information is not generated in that case.Observed behavior
Sending many process-check-result requests in parallel for non-existing objects causes:
Sending the same amount of requests for existing objects does not show the same problem.
Investigation details
From our analysis, requests for non-existing objects trigger diagnostic handling that calls DiagnosticInformation. Inside that path, dladdr() is called many times per request, which appears to contend on
_dl_load_lock.Observing the latencies of the function
dladdr()via eBPF, we observed thatdladdr()took even more than 64 ms to execute (most likely waiting on_dl_loak_lock).This may explain why many parallel invalid
process-check-resultrequests can degrade the performance of whole engine.To Reproduce
process-check-resultrequests in parallel targeting non-existing objects over a continued period of time, for example with payload:The following script can alternatively be used to reproduce the problem (the script sends 50k requests in total, with a limit of 10k parallel requests in-flight):
python3.9 /reproduce.py --host 'http://localhost:5665' --user root --password <pwd> --total 50000 --parallel 10000Possible fix
A possible fix may be to not include the stack trace in the DiagnosticInformation, by setting
DiagnosticInformation(ex, false));here. On our test environment this change fixed the problem.Another possible fix may be to produce the DiagnosticInformation only when the
verboseAPI parameter is set totrue, since the DiagnosticInformation is not returned anyway in the response in case the verbosity is not requested.Expected behavior
Requests for non-existing objects should fail quickly and should not be able to significantly degrade the scheduler or cause unrelated checks to go overdue.
Screenshots
Your Environment
Include as many relevant details about the environment you experienced the problem in
icinga2 --version):r2.15.1-1icinga2 feature list):api checker icingadb influxdb livestatus mainlog notification