Skip to content

Parallel process-check-result requests for non-existing objects degrade Icinga 2 performance and cause overdue checks #10875

Description

@DamianoChini

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

  1. 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

Image

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions