Skip to content

fix(monitor): subscribe to events since before the initial listing - #14304

Open
ndeloof wants to merge 1 commit into
docker:mainfrom
ndeloof:monitor-since
Open

ndeloof wants to merge 1 commit into
docker:mainfrom
ndeloof:monitor-since

Conversation

@ndeloof

@ndeloof ndeloof commented Oct 8, 2026 •

Copy link
Copy Markdown
Contributor

Follows #14296 (merged). Independent of #14300 and #14302.

What this PR does, in one sentence

The container monitor now asks the engine for events since the daemon's time read before it lists the project's containers, so a container that starts and exits between the listing and the event subscription can no longer go unseen.

Context

monitor.Start lists the project's containers, then opens the event stream. Both are round trips, and the stream carried no since: an event emitted in between is delivered to nobody. For a container that starts and exits right then (echo hi), the die is lost, the monitor keeps tracking a container that is gone, and --abort-on-container-exit / --exit-code-from never fire. The exposure grows as the lifecycle converges on one plan (#14081): with Create and Start run back to back, the first ContainerStart follows the monitor's attachment much more closely than it used to.

What the PR brings

The subscription is requested since the daemon's own time, read from its system info (one extra round trip) before the listing, so the engine replays anything that happened after it. Events are stamped by the daemon, so its clock is the one that has to be used: a client clock that differs from it, as against a remote daemon, would miss part of the window or replay events from before the monitor started. There is deliberately no falling back on the client's clock: a daemon whose time can't be read (the call fails, or the time is empty or unparsable) makes the monitor fail with an explicit error (reading the daemon time to subscribe to container events: …), and so the command, rather than following with no sound starting point. compose logs --follow, which shares the monitor, returns that error. A caller that wants to know before it starts any container can read the time ahead of Start. The replay is idempotent by construction: the listing notifies nothing, so each replayed event is reported once, and the tracked set only ever gets an ID added again or removed again. Unit tests pin this against a fake event log that, like the engine, only hands unsubscribed events to a subscription asking for them with since, and stamps events with a clock of its own (set hours apart from the test's to prove the daemon's time is the one used, as reported and whatever its offset). The failure is covered for a failing system info and for an empty or unparsable time, at the monitor and through logs --follow. The replay cases: a die emitted between listing and subscription, and replays of a die for a container listed as exited, a start for one listed as running, the whole life of a container the listing doesn't know, and a restart policy already in action.

I could not reproduce the race against a real engine (Docker Desktop 29.7.2, busybox echo hi, monitor launched concurrently with ContainerStart: 0 missed exits out of 60 runs, with and without since; the exit lands about 60 ms after the start call, far beyond the listing plus subscription round trips). The change is therefore a cheap guard for a narrow window rather than the fix of an observed failure; it is meant to hold when a later step of the series removes the slack that hides it today.

Caveats, deliberately not worked around here: compose logs --follow shares the monitor and gets the same replay (and the extra system-info call). An empty initial listing still ends the monitor before it reads any event, as before.

Why this is the right next brick

It is the last prerequisite the interactive up switchover needs from the monitor, and it is inert for anything that does not race. It touches nothing else.

Part of #14081.

🤖 Generated with Claude Code

@ndeloof
ndeloof requested review from docker-agent and a balanced review from Copilot October 8, 2026 10:58

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

The timestamp parser tests pass errors directly to assert.Check, causing panic instead of validation.

1 open finding
What changed in this PR

Guards monitor startup against missed container events. The stacked diff also migrates lifecycle operations to the phased plan executor.

Changes:

  • Subscribes to events from before the initial container listing.
  • Unifies create/start planning for detached up, scale, watch, and start.
  • Expands reconciler, executor, timeout, provider, and regression coverage.
File Description
pkg/​compose/​watch.go Uses unified create/start planning for rebuilds.
pkg/​compose/​up.go Adds plan-based detached up execution.
pkg/​compose/​start.go Migrates start to start-only plans.
pkg/​compose/​start_test.go Removes obsolete imperative-start tests.
pkg/​compose/​service_containers.go Refines dependency timeout handling and removes legacy start logic.
pkg/​compose/​service_containers_test.go Tests optional dependency timeout behavior.
pkg/​compose/​scale.go Uses unified create/start execution.
pkg/​compose/​restart_test.go Updates shared container fixtures.
pkg/​compose/​reconcile.go Extends start planning and provider handling.
pkg/​compose/​reconcile_start_test.go Adds start-plan regression coverage.
pkg/​compose/​observed_state.go Scopes observed resources by lifecycle phase.
pkg/​compose/​observed_state_test.go Tests start-only observation behavior.
pkg/​compose/​monitor.go Replays events since before initial listing.
pkg/​compose/​monitor_test.go Adds monitor replay tests and fake event log.
pkg/​compose/​executor.go Adds phased execution and bounded waits.
pkg/​compose/​executor_start_test.go Tests phase barriers, timeouts, and recreation.
pkg/​compose/​executor_ops.go Updates wait and rename execution state.
pkg/​compose/​down_test.go Updates shared container fixture usage.
pkg/​compose/​create.go Extracts plan preparation and combined execution.
pkg/​compose/​containers.go Removes an obsolete predicate.

🧠 Review effort: Balanced


Give feedback about Copilot approvals in this survey to enter a drawing for a $150 gift card.

Comment thread pkg/compose/monitor_test.go
@codecov

codecov Bot commented Oct 8, 2026 •

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.

📢 Thoughts on this report? Let us know!

@docker-agent docker-agent left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Assessment: 🟢 APPROVE

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

Monitor startup remains unordered with container startup, so the targeted missed-exit race can still occur.

2 open findings

🧠 Review effort: Balanced


Give feedback about Copilot approvals in this survey to enter a drawing for a $150 gift card.

Comment thread pkg/compose/monitor.go Outdated

@docker-agent docker-agent left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Assessment: 🟢 APPROVE

@ndeloof
ndeloof requested review from docker-agent and a balanced review from Copilot October 8, 2026 12:14

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

Foreground up can still miss fast exits, and narrowed watch rebuilds can misclassify unrelated containers as orphans.

4 open findings

🧠 Review effort: Balanced


Give feedback about Copilot approvals in this survey to enter a drawing for a $150 gift card.

Comment thread pkg/compose/monitor.go
Comment thread pkg/compose/watch.go

@docker-agent docker-agent left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Assessment: 🟢 APPROVE

Comment thread pkg/compose/monitor.go
monitor.Start lists the project's containers, then opens the event
stream. Both are round trips: a container that starts and terminates
in between has its die emitted to nobody, the monitor tracks it
forever, and --abort-on-container-exit / --exit-code-from never fire.
The window is narrow, but a plan running Create and Start back to back
makes the first start follow the monitor's attachment closely.

Ask the engine for events since a point taken before the listing, and
take that point from the daemon (its system time, one extra round trip),
not from the client: events are stamped by the daemon, so a client clock
that differs from it, as against a remote daemon, would either miss part
of the window or replay events from before the monitor was started.
There is no falling back on the client's clock: a daemon whose time
can't be read or parsed makes Start fail with an explicit error, and so
the command. A caller that wants to know before it starts any container
can read the time ahead of Start (readDaemonTime), which then doesn't
ask again.

Replayed events already reflected in the listing are harmless: the
listing notifies nothing, so each is reported once, and the tracked set
only gets an ID added or removed again. Unit tests drive the monitor
against a fake event log that, like the engine, only delivers
unsubscribed events to a subscription asking for them with since, and
stamps events with a clock of its own. They pin that replay for a die, a
start, a destroy and a restart policy, the daemon's time being used
whatever its offset from the client's, the failure when it can't be
read, and that `logs --follow` returns that failure.

Signed-off-by: Nicolas De Loof <nicolas.deloof@gmail.com>

@docker-agent docker-agent left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Assessment: 🟢 APPROVE

The race-fix logic is correct: reading the daemon's clock via Info before the container listing, using it as the since parameter in the event subscription, and failing fast with an explicit error when the clock is unavailable are all sound. The since format (%d.%09d with Unix()/Nanosecond()) round-trips correctly through parseEventsSince. The idempotency of replayed events (listing notifies nothing, so each replayed event is reported once) is valid. Error-handling and context-cancellation semantics are correct.

Lower-confidence findings (not posted inline)

  • [low] pkg/compose/monitor.go:213 — readDaemonTime reads/writes c.since without synchronization (confidence: not scored — low severity, not verified). The documented call contract is sequential, so there is no real race under current usage; a comment asserting the sequential contract, or a sync.Once, would make the invariant explicit. Not a correctness bug today.

  • [low] pkg/compose/monitor_test.go:592 — fakeEventLog.subscribe calls parseEventsSince (which may invoke t.Errorf) while holding l.mu (confidence: not scored — low severity, not verified). t.Errorf does not re-enter the event log, so deadlock is not possible; but holding a mutex during test-framework calls is fragile. In practice this is harmless.

@docker-agent docker-agent left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Assessment: 🟢 APPROVE

No bugs were introduced by the changes in this PR. The since-based event replay logic in readDaemonTime is sound: the daemon time is fetched before the container listing, formatted correctly as <seconds>.<nanoseconds>, and used to filter the event stream so events emitted during the listing–subscription gap are replayed.

Lower-confidence findings (not posted inline)

  • [medium] pkg/compose/monitor.go:229 — readDaemonTime uses time.RFC3339Nano to parse the daemon's SystemTime, with no format fallback (not verified; low-risk: moby consistently returns RFC3339Nano, and failing fast on unexpected formats is the declared design intent)
  • [low] pkg/compose/monitor.go:233 — fmt.Sprintf(\"%d.%09d\", t.Unix(), t.Nanosecond()) is incorrect for pre-epoch times where t.Unix() < 0 and nanoseconds are non-zero, but this is theoretical given daemon system times are always post-epoch

Comment thread pkg/compose/monitor.go
// monitor below
return nil
}
return err

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Making a failed daemon-time read fatal gives logs --follow a new hard dependency on /info.

Measured against a real engine (29.7.2), through a socket proxy that logs requests and can deny /info:

/info denied (403) main this branch
logs --follow streams normally rc=1, zero log lines
up attached, no TTY rc=0 rc=1
up attached, under a PTY already fails fails

Two things narrow it, one widens it:

  • up on a terminal is not a regression. setupNavigationMenu → isDesktopIntegrationActive (up.go:342-345) plus desktop.Endpoint already issue two /info calls and already hard-fail on a 403. I counted 2 on main under a PTY, 0 without one. up -d never starts the monitor, so it is untouched.
  • logs --follow is the real regression: it had no /info at all before. And it needs only CONTAINERS=1 + EVENTS=1 + PING=1 — no POST — which is the archetypal read-only socket-proxy config. tecnativa/docker-socket-proxy ships INFO=0 by default.
  • The attached-up failure is not atomic: network created, container started, its output printed, then rc=1 with the stack left running — monitor.Start fails inside u.eg.Go (up.go:283-284) while s.start runs on context.WithoutCancel (up.go:310).

Same class the project already acted on twice, in a file this change sits next to: observed_state.go:218 and :269.

The "no client clock" rationale holds, but it rules out substituting a clock, not failing the command. A third option is strictly no worse than today:

if err := c.readDaemonTime(ctx); err != nil {
	if ctx.Err() != nil {
		return nil
	}
	// No sound replay boundary: subscribe live, exactly as before this
	// guard existed, rather than failing a command that works without it.
	logrus.Warnf("%v; container events emitted while the monitor attaches may be missed", err)
}

c.since stays "", Events subscribes live, pre-PR semantics apply. #14305 works identically: reading the time before the start phase is about when a failure lands, not whether it has to be fatal.

Counter-argument in your favour: a wrong --exit-code-from is a silent wrong answer, and a warning drowns in a noisy up. That argues for a narrow fallback — degrade on a permission/transport error, keep failing on a malformed SystemTime — rather than no fallback at all.

Not blocking from me, your call. If you keep the strict stance, TestComposeService_Logs_FollowFailsWithoutDaemonTime cements it as contract, which is fine as long as it is deliberate.

One thing to drop from the discussion: "SystemTime is not in swagger's required list" is not a real risk — moby daemon/info.go:58 and Podman's compat/info.go:127 both set it unconditionally as RFC3339Nano.

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants