[GH-ISSUE #1514] Periphery log retrieval can leave stale docker compose logs processes and saturate dockerd CPU #29932

New Issue

GiteaMirror · 2026-07-16T03:38:06-05:00

GiteaMirror commented

2026-07-16 03:38:06 -05:00

Originally created by @Mevas on GitHub (Jul 5, 2026).
Original GitHub issue: https://github.com/moghtech/komodo/issues/1514

Summary

On a Komodo v2.2.0 Periphery host, stale docker compose ... logs --tail 100 subprocesses lived for days/weeks and caused Docker daemon CPU saturation through many active json-file log readers.

This looks related to the subprocess timeout / Pending keepalive mechanism discussed in #1392, but the concrete failure mode is different: the hung command is log retrieval, and the blast radius is high dockerd CPU from Docker ReadLogs / follow.nextPos goroutines.

Environment

Komodo Periphery image: ghcr.io/moghtech/komodo-periphery:2.2.0
Docker logging driver: default json-file
Host type: Docker Compose stacks managed by Komodo Periphery
Periphery connection mode: Periphery connected to Core over websocket

What happened

The host was stuck at very high CPU. Initial suspicion was container healthchecks / monitoring, but profiling showed the dominant CPU was dockerd, not Periphery or cAdvisor-style monitoring.

Several stale Periphery-descended log commands were still running, for example:

docker compose -p stack-a logs --tail 100
docker compose -p stack-a logs --tail 100 --timestamps
docker compose -p stack-b logs --tail 100
docker compose -p stack-b logs --tail 100 --timestamps
docker compose -p stack-c logs --tail 100
docker compose -p stack-c logs --tail 100 --timestamps

Some of these processes had been alive for about 42 days.

After killing the stale log processes, dockerd CPU dropped immediately from roughly 675-700% process CPU to roughly 58% process CPU, and host load began falling.

Docker daemon evidence

perf on dockerd showed the hot path in Docker json-file log reading:

github.com/moby/moby/v2/daemon/logger/jsonfilelog.getTailReader
github.com/moby/moby/v2/daemon/logger/loggerutils.tailFiles
github.com/moby/moby/v2/daemon/logger/loggerutils.(*LogFile).readLogsLocked
github.com/moby/moby/v2/daemon/logger/loggerutils.(*LogFile).ReadLogs
syscall.pread

strace -c showed heavy log file reads:

pread64: 26985 calls in ~8s
openat: 996 calls
futex: heavy lock contention

Docker pprof showed many active log reader goroutines:

goroutines: ~1667
ReadLogs: 151
follow.nextPos: 144

After killing the stale docker compose ... logs --tail 100 processes, the high-CPU condition stopped.

Why I think this is a Komodo/Periphery issue

Current main still appears to shell out for stack log retrieval:

let command = format!(
  "{docker_compose} -p {project} logs --tail {tail}{timestamps} {}",
  services.join(" ")
);
Ok(
  run_komodo_standard_command("Get Stack Log", None, command)
    .await,
)

The command runner uses cmd.output().await with no wall-clock timeout:

cmd
  .args(&lexed[1..])
  .kill_on_drop(true)
  .stdin(Stdio::null())
  .stdout(Stdio::piped())
  .stderr(Stdio::piped());

CommandOutput::from(cmd.output().await)

This means a docker compose logs --tail ... command that hangs can keep its Periphery resolver future alive indefinitely.

This seems to be the same architectural mechanism as #1392:

Periphery sends Pending every 5 seconds while the request is in progress.
Core treats Pending as progress and keeps waiting.
The effective RPC timeout becomes unbounded.
kill_on_drop(true) does not help if the resolver future is never dropped.

Expected behavior

One-shot log retrieval commands like docker compose logs --tail 100 and docker logs --tail ... should have a bounded wall-clock timeout. If Docker or the Compose plugin hangs, Periphery should kill the subprocess and return a failed log response instead of keeping the request alive forever.

Ideally the timeout should kill the process group, not only the direct child, because docker compose can spawn subprocesses.

Actual behavior

Stale log retrieval subprocesses can survive for days/weeks. In this case, they kept Docker log readers active and caused multi-core dockerd CPU usage.

Suggested fix

A low-risk targeted fix would be to add timeout-aware command helpers and use them for log retrieval endpoints:

GetComposeLog
GetComposeLogSearch
GetContainerLog
GetContainerLogSearch

For example, log retrieval could have a 15-30 second wall-clock timeout, while deploy/build/pull paths keep their existing behavior or get a separate configurable long timeout.

I would avoid a short global timeout on every run_standard_command / run_shell_command call because those helpers are also used for legitimate long-running operations like compose up, pulls, builds, prune operations, and post-deploy hooks.

Related but not identical: #1392 describes the same no-timeout / Pending keepalive mechanism with a hung docker compose ls subprocess. This issue is specifically about docker compose logs --tail 100 leaving Docker log readers active and saturating dockerd CPU.

Originally created by @Mevas on GitHub (Jul 5, 2026). Original GitHub issue: https://github.com/moghtech/komodo/issues/1514 ## Summary On a Komodo v2.2.0 Periphery host, stale `docker compose ... logs --tail 100` subprocesses lived for days/weeks and caused Docker daemon CPU saturation through many active `json-file` log readers. This looks related to the subprocess timeout / `Pending` keepalive mechanism discussed in #1392, but the concrete failure mode is different: the hung command is log retrieval, and the blast radius is high `dockerd` CPU from Docker `ReadLogs` / `follow.nextPos` goroutines. ## Environment - Komodo Periphery image: `ghcr.io/moghtech/komodo-periphery:2.2.0` - Docker logging driver: default `json-file` - Host type: Docker Compose stacks managed by Komodo Periphery - Periphery connection mode: Periphery connected to Core over websocket ## What happened The host was stuck at very high CPU. Initial suspicion was container healthchecks / monitoring, but profiling showed the dominant CPU was `dockerd`, not Periphery or cAdvisor-style monitoring. Several stale Periphery-descended log commands were still running, for example: ```text docker compose -p stack-a logs --tail 100 docker compose -p stack-a logs --tail 100 --timestamps docker compose -p stack-b logs --tail 100 docker compose -p stack-b logs --tail 100 --timestamps docker compose -p stack-c logs --tail 100 docker compose -p stack-c logs --tail 100 --timestamps ``` Some of these processes had been alive for about `42 days`. After killing the stale log processes, `dockerd` CPU dropped immediately from roughly `675-700%` process CPU to roughly `58%` process CPU, and host load began falling. ## Docker daemon evidence `perf` on `dockerd` showed the hot path in Docker json-file log reading: ```text github.com/moby/moby/v2/daemon/logger/jsonfilelog.getTailReader github.com/moby/moby/v2/daemon/logger/loggerutils.tailFiles github.com/moby/moby/v2/daemon/logger/loggerutils.(*LogFile).readLogsLocked github.com/moby/moby/v2/daemon/logger/loggerutils.(*LogFile).ReadLogs syscall.pread ``` `strace -c` showed heavy log file reads: ```text pread64: 26985 calls in ~8s openat: 996 calls futex: heavy lock contention ``` Docker pprof showed many active log reader goroutines: ```text goroutines: ~1667 ReadLogs: 151 follow.nextPos: 144 ``` After killing the stale `docker compose ... logs --tail 100` processes, the high-CPU condition stopped. ## Why I think this is a Komodo/Periphery issue Current `main` still appears to shell out for stack log retrieval: ```rust let command = format!( "{docker_compose} -p {project} logs --tail {tail}{timestamps} {}", services.join(" ") ); Ok( run_komodo_standard_command("Get Stack Log", None, command) .await, ) ``` The command runner uses `cmd.output().await` with no wall-clock timeout: ```rust cmd .args(&lexed[1..]) .kill_on_drop(true) .stdin(Stdio::null()) .stdout(Stdio::piped()) .stderr(Stdio::piped()); CommandOutput::from(cmd.output().await) ``` This means a `docker compose logs --tail ...` command that hangs can keep its Periphery resolver future alive indefinitely. This seems to be the same architectural mechanism as #1392: - Periphery sends `Pending` every 5 seconds while the request is in progress. - Core treats `Pending` as progress and keeps waiting. - The effective RPC timeout becomes unbounded. - `kill_on_drop(true)` does not help if the resolver future is never dropped. ## Expected behavior One-shot log retrieval commands like `docker compose logs --tail 100` and `docker logs --tail ...` should have a bounded wall-clock timeout. If Docker or the Compose plugin hangs, Periphery should kill the subprocess and return a failed log response instead of keeping the request alive forever. Ideally the timeout should kill the process group, not only the direct child, because `docker compose` can spawn subprocesses. ## Actual behavior Stale log retrieval subprocesses can survive for days/weeks. In this case, they kept Docker log readers active and caused multi-core `dockerd` CPU usage. ## Suggested fix A low-risk targeted fix would be to add timeout-aware command helpers and use them for log retrieval endpoints: - `GetComposeLog` - `GetComposeLogSearch` - `GetContainerLog` - `GetContainerLogSearch` For example, log retrieval could have a 15-30 second wall-clock timeout, while deploy/build/pull paths keep their existing behavior or get a separate configurable long timeout. I would avoid a short global timeout on every `run_standard_command` / `run_shell_command` call because those helpers are also used for legitimate long-running operations like compose up, pulls, builds, prune operations, and post-deploy hooks. ## Related issue Related but not identical: #1392 describes the same no-timeout / `Pending` keepalive mechanism with a hung `docker compose ls` subprocess. This issue is specifically about `docker compose logs --tail 100` leaving Docker log readers active and saturating `dockerd` CPU.

GiteaMirror commented

2026-07-16 03:38:07 -05:00

@mbecker20 commented on GitHub (Jul 5, 2026):

Do you pass init: true to periphery container? This allows the sub-processes to be properly reaped. Needed on both core and periphery containers.

services:
  periphery:
    image: ghcr.io/moghtech/komodo-periphery:2
    init: true # Important
    (...)

@mbecker20 commented on GitHub (Jul 5, 2026): Do you pass init: true to periphery container? This allows the sub-processes to be properly reaped. Needed on both core and periphery containers. ```yaml services: periphery: image: ghcr.io/moghtech/komodo-periphery:2 init: true # Important (...) ```

GiteaMirror commented

2026-07-16 03:38:07 -05:00

@Mevas commented on GitHub (Jul 11, 2026):

Yes, checked and I do have init: true for both of them:

core:
  image: ghcr.io/moghtech/komodo-core:2.2.0
  init: true

periphery:
  image: ghcr.io/moghtech/komodo-periphery:2.2.0
  init: true

@Mevas commented on GitHub (Jul 11, 2026): Yes, checked and I do have `init: true` for both of them: ```yaml core: image: ghcr.io/moghtech/komodo-core:2.2.0 init: true periphery: image: ghcr.io/moghtech/komodo-periphery:2.2.0 init: true ```

Sign in to join this conversation.

Branches Tags

1 Participants

Notifications

Due Date

No due date set.

Dependencies

No dependencies set.

Reference: github-starred/komodo#29932