Skip to content

100% CPU caused by futex spin loop in coordinator process (CLOCK_MONOTONIC vs FUTEX_CLOCK_REALTIME mismatch) #358

Description

@jsolevpt

Description

The elastic-otel-php v1.3.1 agent causes 100% CPU usage on the Apache parent process when enabled. The root cause is a futex spin loop where a CLOCK_MONOTONIC timestamp is passed
to a FUTEX_CLOCK_REALTIME futex wait, causing the timeout to always be in the past and the futex to return immediately in an infinite loop.

Environment

  • OS: Debian (ECS EC2 container)
  • PHP: 8.4.14
  • Web server: Apache 2.4 (prefork)
  • Agent version: elastic-otel-php 1.3.1
  • Platform: AWS ECS (EC2 launch type), eu-west-1

Steps to reproduce

  1. Install elastic-otel-php v1.3.1 via the .deb package
  2. Set elastic_otel.enabled = true in the custom ini
  3. Configure OTEL env vars (OTEL_EXPORTER_OTLP_ENDPOINT, OTEL_EXPORTER_OTLP_HEADERS, OTEL_SERVICE_NAME)
  4. Start Apache
  5. Observe CPU immediately climbing to 100%

Diagnosis

The Apache parent process (root, PID 1 or respawned parent) spawns 2 threads instead of the usual 1. The extra thread is created by the agent.

strace output (5 seconds)

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
100.00    0.681069          12     56052     28026 futex
------ ----------- ----------- --------- --------- ----------------

56,052 futex calls in 5 seconds (~11,000/s), with 50% errors (ETIMEDOUT).

Detailed futex trace

futex(0x7fdaf9b80030, FUTEX_WAKE, 1)    = 0
futex(0x7fdaf9b80078, FUTEX_WAIT_BITSET|FUTEX_CLOCK_REALTIME, 0, {tv_sec=259728, tv_nsec=533946847}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
futex(0x7fdaf9b80030, FUTEX_WAKE, 1)    = 0
futex(0x7fdaf9b80078, FUTEX_WAIT_BITSET|FUTEX_CLOCK_REALTIME, 0, {tv_sec=259728, tv_nsec=534094452}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
(repeats indefinitely)

Clock values at the time of the trace

Clock Value Meaning
CLOCK_REALTIME 1,774,510,115 Unix timestamp (March 26, 2026)
CLOCK_MONOTONIC 260,414 Host uptime (~3 days)
Futex tv_sec 259,728 CLOCK_MONOTONIC value

The futex is called with FUTEX_CLOCK_REALTIME flag, which interprets the timeout as an absolute CLOCK_REALTIME timestamp. However, the value passed (~259,728) corresponds to
CLOCK_MONOTONIC (host uptime), not CLOCK_REALTIME (~1.77 billion). Since 259,728 seconds after epoch is January 4, 1970, the timeout is always in the past, so the futex returns
ETIMEDOUT immediately every time.

Suspected root cause

In prod/native/libcommon/code/coordinator/CoordinatorProcess.cpp, the coordinator loop uses:

commandQueue_->timed_receive(buffer, maxMqPayloadSize, receivedSize,
    priority, std::chrono::steady_clock::now() + std::chrono::milliseconds(10));

This passes a steady_clock (monotonic) timestamp to Boost.Interprocess timed_receive(), which internally uses a futex with FUTEX_CLOCK_REALTIME. This is a known class of bugs
in Boost.Interprocess (see boostorg/interprocess#237).

Configuration attempts (none worked)

Setting Result
ELASTIC_OTEL_ASYNC_TRANSPORT=false Still 100% CPU
OTEL_PHP_AUTOLOAD_ENABLED=false Still 100% CPU
elastic_otel.inferred_spans_enabled=false (php.ini) Still 100% CPU
OTEL_TRACES_SAMPLER=traceidratio + OTEL_PHP_DETECTORS=none Still 100% CPU
elastic_otel.enabled=false (php.ini) CPU drops to ~0% (only workaround)

Workaround

Setting elastic_otel.enabled = false in the custom ini file is the only way to prevent the CPU spike while keeping the .deb package installed.

Metadata

Metadata

Assignees

Labels

bugSomething isn't working

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions