From 220eb51cce40deae111c6d6c7f94d784c1f8a727 Mon Sep 17 00:00:00 2001 From: stswidwinski Date: Mon, 21 Aug 2023 20:57:17 +0800 Subject: [PATCH 1/6] Ensure that the index processed by the client is at least as new as the last index processed so that stale data does not impact the running allocations. --- client/client.go | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/client/client.go b/client/client.go index a39431c57834..7eb1170e8dbf 100644 --- a/client/client.go +++ b/client/client.go @@ -2360,6 +2360,18 @@ OUTER: default: } + // We have not received any new data, or received stale data. This may happen in + // an array of situations, the worst of which seems to be a blocking request + // timeout when the scheduler which we are contacting is newly added or recovering + // after a prolonged downtime. + // + // For full context, please see https://github.com/hashicorp/nomad/issues/18267 + if resp.Index < req.MinQueryIndex { + c.logger.Debug("Received stale allocation information. Retrying.", + "received index", resp.Index, "requested min index", req.MinQueryIndex) + continue OUTER + } + // Filter all allocations whose AllocModifyIndex was not incremented. // These are the allocations who have either not been updated, or whose // updates are a result of the client sending an update for the alloc. From d24f64420c9ac092aae6c7f6b35a0e97b6f6fe30 Mon Sep 17 00:00:00 2001 From: stswidwinski Date: Tue, 22 Aug 2023 09:10:11 +0800 Subject: [PATCH 2/6] Add a smoke test for the issue. Testing for absence is a rather difficult task without hooks into the code to assert that given code paths have been hit. In this test we simply make sure that a transaction with a lower raft index does not make it to the client and depend on the timeout to make sure that this is the case. If the invariant is broken we expect the test to become either flaky or entirely broken. I acknowledge there may be a better way to test here, but lacking context this seems to be a minimal attempt to ensure that a similar issue doesn't creep back in. Feedback welcome. --- client/client.go | 2 +- client/client_test.go | 35 ++++++++++++++++++++++++++++++++++- 2 files changed, 35 insertions(+), 2 deletions(-) diff --git a/client/client.go b/client/client.go index 7eb1170e8dbf..1ecc3bb088ae 100644 --- a/client/client.go +++ b/client/client.go @@ -2366,7 +2366,7 @@ OUTER: // after a prolonged downtime. // // For full context, please see https://github.com/hashicorp/nomad/issues/18267 - if resp.Index < req.MinQueryIndex { + if resp.Index <= req.MinQueryIndex { c.logger.Debug("Received stale allocation information. Retrying.", "received index", resp.Index, "requested min index", req.MinQueryIndex) continue OUTER diff --git a/client/client_test.go b/client/client_test.go index 4124b31ad890..f1b6d866123a 100644 --- a/client/client_test.go +++ b/client/client_test.go @@ -562,11 +562,17 @@ func TestClient_WatchAllocs(t *testing.T) { alloc1.JobID = job.ID alloc1.Job = job alloc1.NodeID = c1.Node().ID + alloc2 := mock.Alloc() alloc2.NodeID = c1.Node().ID alloc2.JobID = job.ID alloc2.Job = job + alloc3 := mock.Alloc() + alloc3.NodeID = c1.Node().ID + alloc3.JobID = job.ID + alloc3.Job = job + state := s1.State() if err := state.UpsertJob(structs.MsgTypeTestSetup, 100, nil, job); err != nil { t.Fatal(err) @@ -599,7 +605,7 @@ func TestClient_WatchAllocs(t *testing.T) { // alloc runner. alloc2_2 := alloc2.Copy() alloc2_2.DesiredStatus = structs.AllocDesiredStatusStop - if err := state.UpsertAllocs(structs.MsgTypeTestSetup, 104, []*structs.Allocation{alloc2_2}); err != nil { + if err := state.UpsertAllocs(structs.MsgTypeTestSetup, 105, []*structs.Allocation{alloc2_2}); err != nil { t.Fatalf("err upserting stopped alloc: %v", err) } @@ -622,6 +628,33 @@ func TestClient_WatchAllocs(t *testing.T) { }, func(err error) { t.Fatalf("err: %v", err) }) + + // Attempt to add an allocation with a RAFT index which predates the one currently + // known to the client. This is to ensure that the client monotonically increases the + // index it asks for and does not accept responses which have already been seen. + // + // Unfortunately, this requires us to depend on timeout for assertion. This isn't + // ideal, but barring changes to the state machine it is hard for us to assert that + // the client has made a query against the scheduler and received a stale answer. + alloc3.DesiredStatus = structs.AllocDesiredStatusStop + if err := state.UpsertAllocs(structs.MsgTypeTestSetup, 104, []*structs.Allocation{alloc3}); err != nil { + t.Fatalf("err upserting stopped alloc: %v", err) + } + + failureSeen := false + testutil.WaitForResult(func() (bool, error) { + c1.allocLock.RLock() + if _, ok := c1.allocs[alloc3.ID]; ok { + failureSeen = true + return true, fmt.Errorf("Unexpected allocation present in client state.") + } + return false, nil + + }, func(err error) { + if failureSeen { + t.Fatalf("err: %v", err) + } + }) } func waitTilNodeReady(client *Client, t *testing.T) { From 0db169aacf1444bf37ce019ecfd9fe9f957f0ef0 Mon Sep 17 00:00:00 2001 From: stswidwinski Date: Tue, 22 Aug 2023 09:12:10 +0800 Subject: [PATCH 3/6] Add unlock. --- client/client_test.go | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/client/client_test.go b/client/client_test.go index f1b6d866123a..213264ac6f20 100644 --- a/client/client_test.go +++ b/client/client_test.go @@ -644,7 +644,9 @@ func TestClient_WatchAllocs(t *testing.T) { failureSeen := false testutil.WaitForResult(func() (bool, error) { c1.allocLock.RLock() - if _, ok := c1.allocs[alloc3.ID]; ok { + _, ok := c1.allocs[alloc3.ID] + c1.allocLock.RUnlock() + if ok { failureSeen = true return true, fmt.Errorf("Unexpected allocation present in client state.") } From 1b7b43ca948487c089209f7b650a44bf1c81a0f6 Mon Sep 17 00:00:00 2001 From: stswidwinski Date: Tue, 22 Aug 2023 09:36:10 +0800 Subject: [PATCH 4/6] Reverting the proposed tests for a few reasons: 1. error is ignored in WaitForResult 2. existing timeouts in blocking queries cannot be overridden and would make the tests always pass 3. the scheduler seems to ignore raft transactions with lower ids As such, we would need more infrastructure to write such tests. Do you have an idea is there is a precedent I can use here no to reinvent the wheel? In general we need: 1. To reduce the raft index of scheduler (purge the state or reassign the state: This can be done with regular assignment into a newly created state 2. Induce a timeout on the blocking query to ensure that the query result is passed to client -> This I see no easy way of achieving --- client/client_test.go | 37 +------------------------------------ 1 file changed, 1 insertion(+), 36 deletions(-) diff --git a/client/client_test.go b/client/client_test.go index 213264ac6f20..4124b31ad890 100644 --- a/client/client_test.go +++ b/client/client_test.go @@ -562,17 +562,11 @@ func TestClient_WatchAllocs(t *testing.T) { alloc1.JobID = job.ID alloc1.Job = job alloc1.NodeID = c1.Node().ID - alloc2 := mock.Alloc() alloc2.NodeID = c1.Node().ID alloc2.JobID = job.ID alloc2.Job = job - alloc3 := mock.Alloc() - alloc3.NodeID = c1.Node().ID - alloc3.JobID = job.ID - alloc3.Job = job - state := s1.State() if err := state.UpsertJob(structs.MsgTypeTestSetup, 100, nil, job); err != nil { t.Fatal(err) @@ -605,7 +599,7 @@ func TestClient_WatchAllocs(t *testing.T) { // alloc runner. alloc2_2 := alloc2.Copy() alloc2_2.DesiredStatus = structs.AllocDesiredStatusStop - if err := state.UpsertAllocs(structs.MsgTypeTestSetup, 105, []*structs.Allocation{alloc2_2}); err != nil { + if err := state.UpsertAllocs(structs.MsgTypeTestSetup, 104, []*structs.Allocation{alloc2_2}); err != nil { t.Fatalf("err upserting stopped alloc: %v", err) } @@ -628,35 +622,6 @@ func TestClient_WatchAllocs(t *testing.T) { }, func(err error) { t.Fatalf("err: %v", err) }) - - // Attempt to add an allocation with a RAFT index which predates the one currently - // known to the client. This is to ensure that the client monotonically increases the - // index it asks for and does not accept responses which have already been seen. - // - // Unfortunately, this requires us to depend on timeout for assertion. This isn't - // ideal, but barring changes to the state machine it is hard for us to assert that - // the client has made a query against the scheduler and received a stale answer. - alloc3.DesiredStatus = structs.AllocDesiredStatusStop - if err := state.UpsertAllocs(structs.MsgTypeTestSetup, 104, []*structs.Allocation{alloc3}); err != nil { - t.Fatalf("err upserting stopped alloc: %v", err) - } - - failureSeen := false - testutil.WaitForResult(func() (bool, error) { - c1.allocLock.RLock() - _, ok := c1.allocs[alloc3.ID] - c1.allocLock.RUnlock() - if ok { - failureSeen = true - return true, fmt.Errorf("Unexpected allocation present in client state.") - } - return false, nil - - }, func(err error) { - if failureSeen { - t.Fatalf("err: %v", err) - } - }) } func waitTilNodeReady(client *Client, t *testing.T) { From 5d5789677f68a57fc04f791bbc1b168a8e5db5e7 Mon Sep 17 00:00:00 2001 From: stswidwinski Date: Fri, 25 Aug 2023 16:06:03 -0400 Subject: [PATCH 5/6] Update client/client.go Use identifier-style keys for structured logs Co-authored-by: Michael Schurter --- client/client.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/client/client.go b/client/client.go index 1ecc3bb088ae..84b576e211de 100644 --- a/client/client.go +++ b/client/client.go @@ -2368,7 +2368,7 @@ OUTER: // For full context, please see https://github.com/hashicorp/nomad/issues/18267 if resp.Index <= req.MinQueryIndex { c.logger.Debug("Received stale allocation information. Retrying.", - "received index", resp.Index, "requested min index", req.MinQueryIndex) + "index", resp.Index, "min_index", req.MinQueryIndex) continue OUTER } From 83310de68ceeb7a0b6b0faf25b23c2557318eb9b Mon Sep 17 00:00:00 2001 From: Michael Schurter Date: Fri, 25 Aug 2023 15:18:15 -0700 Subject: [PATCH 6/6] add cl --- .changelog/18269.txt | 3 +++ 1 file changed, 3 insertions(+) create mode 100644 .changelog/18269.txt diff --git a/.changelog/18269.txt b/.changelog/18269.txt new file mode 100644 index 000000000000..435b5b875497 --- /dev/null +++ b/.changelog/18269.txt @@ -0,0 +1,3 @@ +```release-note:bug +client: Ignore stale server updates to prevent GCing allocations that should be running +```