fix(agent): ett Docker-anrop som hänger i Snapshot() låser all rapportering till mastern #38

Open
opened 2026-10-18 05:22:07 +00:00 by shcizo · 0 comments
Owner

Beskrivning

Ett Docker-API-anrop som aldrig får svar låser agentens hela kommunikation med mastern, för alltid och utan att något loggas.

Hände på agenten manager (swarm-mgr, 0.9.1) 2026-10-17 → 2026-10-18:

  • Runt 2026-10-17 11:28 UTC fick agentens GET /images/json (ImageList) aldrig något svar från dockerd.
  • Agenten skickade sedan ingenting till mastern på 17,8 timmar: inga upserts, ingen progress och inga jobbresultat.
  • Jobb 47 (stina_api, manuellt, 2026-10-18 05:06 UTC) kördes faktiskt: workern uppdaterade tjänsten till den nya digesten (update completed i Swarm). Men jobbet stod som queued i UI:t tills agenten startades om. Efter omstarten markerades det som failed ("lost: the agent did not know this job when it reconnected"), fast uppdateringen gick igenom.
  • TCP/WebSocket-anslutningen var ESTABLISHED med tomma köer på båda sidor hela tiden, så ingen av sidorna märkte något. Agenten loggade ingenting efter master_connected 2026-10-14.

Förväntat beteende

Ett Docker-anrop som hänger ska ge ett fel inom rimlig tid, synas i loggen och inte stoppa progress och resultat för jobb.

Bevis (goroutine-dump via SIGQUIT)

goroutine 1 [select, 1067 minutes]:
net/http.(*persistConn).roundTrip(...)
...
github.com/docker/docker/client.(*Client).ImageList(...)
	client/image_list.go:59
github.com/shcizo/package-updater/internal/agent/inventory.(*Collector).Snapshot(...)
	/src/internal/agent/inventory/collector.go:152
github.com/shcizo/package-updater/internal/agent/conn.(*Agent).session(...)
	/src/internal/agent/conn/conn.go:266
github.com/shcizo/package-updater/internal/agent/conn.(*Agent).Run(...)
	/src/internal/agent/conn/conn.go:110

readLoop, writeLoop och Runner.Run väntade bara som vanligt, så jobbet togs emot och kördes. Den goroutine som skulle skicka resultatet var den som hängde.

Varför dockerd aldrig svarade på just det anropet gick inte att ta reda på i efterhand. Inget i dockerd-loggen, och inga tjänster ändrades vid den tiden. Nya docker images-anrop svarade direkt när felet undersöktes. Agenten måste alltså klara att ett enskilt anrop aldrig besvaras.

Teknisk orsak

session() i internal/agent/conn/conn.go gör allt i en och samma select-loop: flush() av progress och resultat (jobsChanged, timerC) och omräkning av inventeringen (a.changes → a.src.Snapshot(ctx)).

ctx är sessionens context och saknar deadline. Docker-SDK:ns http.Client har ingen egen timeout, så Collector.Snapshot() (internal/agent/inventory/collector.go:143 och framåt: Info, ContainerList, ImageList, Swarm-anropen och resolveSelf/imageRef) kan blockera för evigt. watchLoop anropar Notify() var 60:e sekund, så förr eller senare hamnar ett hängande anrop i loopen.

Masterns säkerhetsnät ("a job whose write later fails stays queued; the agent's next hello settles it as lost", internal/master/hub/jobs.go) förutsätter att anslutningen bryts. Här bröts den aldrig.

Förslag till lösning

  1. Timeout per inventering: snapCtx, cancel := context.WithTimeout(ctx, 30*time.Second) runt a.src.Snapshot(...) i session(), både för den första snapshoten och i case <-a.changes. En timeout ger ett fel, och då startar sessionen om via det vanliga fail(true, err) → master_connection_lost i loggen. Agenten återhämtar sig själv och felet syns.
  2. (Övervägs) Kör inventeringen i en egen goroutine och skicka resultatet tillbaka till loopen, så att ett långsamt Docker-anrop aldrig fördröjer flush(). Med (1) på plats är det mindre viktigt, men det skulle också förhindra att progress fördröjs i upp till timeouten.
  3. Samma genomgång för andra Docker-anrop utan deadline på agenten, t.ex. i BuildCheck (buildRetry). Executorn har redan UPDATE_TIMEOUT via jobCtx.

Test: en fake-Source vars Snapshot blockerar tills ctx avbryts. Förvänta att sessionen avslutas med ett fel inom timeouten, och att ett jobbresultat som köats före hänget inte fastnar.

Relaterat: #21. Loggning av jobbens livscykel hade visat direkt att agenten tagit emot jobbet men aldrig rapporterat det.

## Beskrivning Ett Docker-API-anrop som aldrig får svar låser agentens hela kommunikation med mastern, för alltid och utan att något loggas. Hände på agenten `manager` (swarm-mgr, 0.9.1) 2026-10-17 → 2026-10-18: - Runt 2026-10-17 11:28 UTC fick agentens `GET /images/json` (`ImageList`) aldrig något svar från dockerd. - Agenten skickade sedan ingenting till mastern på 17,8 timmar: inga upserts, ingen progress och inga jobbresultat. - Jobb 47 (`stina_api`, manuellt, 2026-10-18 05:06 UTC) **kördes faktiskt**: workern uppdaterade tjänsten till den nya digesten (`update completed` i Swarm). Men jobbet stod som `queued` i UI:t tills agenten startades om. Efter omstarten markerades det som `failed` ("lost: the agent did not know this job when it reconnected"), fast uppdateringen gick igenom. - TCP/WebSocket-anslutningen var `ESTABLISHED` med tomma köer på båda sidor hela tiden, så ingen av sidorna märkte något. Agenten loggade ingenting efter `master_connected` 2026-10-14. ## Förväntat beteende Ett Docker-anrop som hänger ska ge ett fel inom rimlig tid, synas i loggen och inte stoppa progress och resultat för jobb. ## Bevis (goroutine-dump via SIGQUIT) ``` goroutine 1 [select, 1067 minutes]: net/http.(*persistConn).roundTrip(...) ... github.com/docker/docker/client.(*Client).ImageList(...) client/image_list.go:59 github.com/shcizo/package-updater/internal/agent/inventory.(*Collector).Snapshot(...) /src/internal/agent/inventory/collector.go:152 github.com/shcizo/package-updater/internal/agent/conn.(*Agent).session(...) /src/internal/agent/conn/conn.go:266 github.com/shcizo/package-updater/internal/agent/conn.(*Agent).Run(...) /src/internal/agent/conn/conn.go:110 ``` `readLoop`, `writeLoop` och `Runner.Run` väntade bara som vanligt, så jobbet togs emot och kördes. Den goroutine som skulle skicka resultatet var den som hängde. Varför dockerd aldrig svarade på just det anropet gick inte att ta reda på i efterhand. Inget i dockerd-loggen, och inga tjänster ändrades vid den tiden. Nya `docker images`-anrop svarade direkt när felet undersöktes. Agenten måste alltså klara att ett enskilt anrop aldrig besvaras. ## Teknisk orsak `session()` i `internal/agent/conn/conn.go` gör allt i en och samma `select`-loop: `flush()` av progress och resultat (`jobsChanged`, `timerC`) och omräkning av inventeringen (`a.changes` → `a.src.Snapshot(ctx)`). `ctx` är sessionens context och saknar deadline. Docker-SDK:ns `http.Client` har ingen egen timeout, så `Collector.Snapshot()` (`internal/agent/inventory/collector.go:143` och framåt: `Info`, `ContainerList`, `ImageList`, Swarm-anropen och `resolveSelf`/`imageRef`) kan blockera för evigt. `watchLoop` anropar `Notify()` var 60:e sekund, så förr eller senare hamnar ett hängande anrop i loopen. Masterns säkerhetsnät ("a job whose write later fails stays queued; the agent's next hello settles it as lost", `internal/master/hub/jobs.go`) förutsätter att anslutningen bryts. Här bröts den aldrig. ## Förslag till lösning 1. **Timeout per inventering:** `snapCtx, cancel := context.WithTimeout(ctx, 30*time.Second)` runt `a.src.Snapshot(...)` i `session()`, både för den första snapshoten och i `case <-a.changes`. En timeout ger ett fel, och då startar sessionen om via det vanliga `fail(true, err)` → `master_connection_lost` i loggen. Agenten återhämtar sig själv och felet syns. 2. **(Övervägs)** Kör inventeringen i en egen goroutine och skicka resultatet tillbaka till loopen, så att ett långsamt Docker-anrop aldrig fördröjer `flush()`. Med (1) på plats är det mindre viktigt, men det skulle också förhindra att progress fördröjs i upp till timeouten. 3. Samma genomgång för andra Docker-anrop utan deadline på agenten, t.ex. i `BuildCheck` (`buildRetry`). Executorn har redan `UPDATE_TIMEOUT` via `jobCtx`. Test: en fake-`Source` vars `Snapshot` blockerar tills ctx avbryts. Förvänta att sessionen avslutas med ett fel inom timeouten, och att ett jobbresultat som köats före hänget inte fastnar. Relaterat: #21. Loggning av jobbens livscykel hade visat direkt att agenten tagit emot jobbet men aldrig rapporterat det.
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: shcizo/package-updater#38