docker: say where the runtime's event history begins, so a short history never reads as a quiet one (hq issue 348)

docker_events asked for three hours across the 2026-10-09 resolver outage on the control node answered
zero events: the runtime keeps only its last ~256 events in memory, and health-check execs filled them
with the last ten minutes. The answer now carries held, oldest_held and complete, and a history line
when the window reaches further back than what the runtime still holds. The type filter moves into the
tool, since the history's start is only known from all of it.
This commit is contained in:
jochen
2026-10-09 13:24:58 +02:00
parent e9f5727cad
commit d79a4eeab9
3 changed files with 101 additions and 5 deletions
+52 -1
View File
@@ -4,6 +4,7 @@ import (
"context"
"encoding/json"
"errors"
"fmt"
"io/fs"
"os"
"reflect"
@@ -307,7 +308,8 @@ func TestEventsAreABoundedWindowWithoutExecNoise(t *testing.T) {
if len(evs) != 1 || evs[0]["action"] != "die" || evs[0]["mesh_held"] != true || evs[0]["exit_code"] != "137" {
t.Fatalf("%v", evs)
}
if !f.ran("docker events --since 30m --until 0s --format {{json .}} --filter type=container") {
// The type is filtered here, not by the runtime: the history's start is only known from all of it (issue 348).
if !f.ran("docker events --since 30m --until 0s --format {{json .}}") || f.ran("docker events --since 30m --until 0s --format {{json .}} --filter") {
t.Fatalf("%+v", f.calls)
}
if _, err := client(f, 1000).Events(context.Background(), 30, "secret", 10, false); err == nil {
@@ -362,3 +364,52 @@ func TestProblemsNameWhyAndUnlabelledIsTheCleanupList(t *testing.T) {
t.Fatalf("%v %v", u, err)
}
}
// eventLine is one line of `docker events --format '{{json .}}'`.
func eventLine(at time.Time, kind, action, name string) string {
return fmt.Sprintf(`{"Type":%q,"Action":%q,"Actor":{"ID":"abcdef0123456789","Attributes":{"name":%q}},"timeNano":%d}`+"\n",
kind, action, name, at.UnixNano())
}
// Issue 348: three hours asked across an outage answered zero, because the runtime's history held only the
// last ten minutes of health-check execs. The answer must say the history is short, not that nothing happened.
func TestEventsSayWhereTheRuntimesHistoryBeginsWhenTheWindowReachesFurther(t *testing.T) {
now := time.Date(2026, 10, 9, 11, 24, 0, 0, time.UTC)
var out strings.Builder
for i := 0; i < 250; i++ {
out.WriteString(eventLine(now.Add(-10*time.Minute+time.Duration(i)*2*time.Second), "container", "exec_die", "mailu-webmail"))
}
got, err := client((&fake{}).on("docker events", Ran{Stdout: out.String()}), 1000).eventsAt(context.Background(), now, 180, "", 200, false)
if err != nil {
t.Fatal(err)
}
if got["count"] != 0 || got["held"] != 250 {
t.Fatalf("count %v held %v, want 0 shown of 250 held", got["count"], got["held"])
}
if got["complete"] != false || !strings.Contains(fmt.Sprint(got["history"]), "gone from here, not absent") ||
got["oldest_held"] != "2026-10-09T11:14:00Z" {
t.Fatalf("an empty answer from a short history reads as quiet: %v", got)
}
}
func TestEventsCoveringTheWholeWindowSayItIsCompleteAndFilterTheTypeHere(t *testing.T) {
now := time.Date(2026, 10, 9, 11, 24, 0, 0, time.UTC)
out := eventLine(now.Add(-59*time.Minute), "network", "destroy", "build-net") +
eventLine(now.Add(-30*time.Minute), "container", "die", "build-bus") +
eventLine(now.Add(-1*time.Minute), "network", "create", "build-net")
f := (&fake{}).on("docker events", Ran{Stdout: out})
got, err := client(f, 1000).eventsAt(context.Background(), now, 60, "network", 200, false)
if err != nil {
t.Fatal(err)
}
if got["complete"] != true || got["count"] != 2 || got["history"] != nil {
t.Fatalf("a covered window: %v", got)
}
if f.ran("docker events --since 60m --until 0s --format {{json .}} --filter") {
t.Fatal("the type was filtered by the runtime, so the history's start is unknown")
}
got, _ = client((&fake{}).on("docker events", Ran{}), 1000).eventsAt(context.Background(), now, 60, "", 200, false)
if got["complete"] != false || got["history"] == nil {
t.Fatalf("no events at all reads as quiet: %v", got)
}
}