From 360fec7c674fa48a13d67e75f1ea10861e08adf9 Mon Sep 17 00:00:00 2001 From: Zeyad Gouda Date: Tue, 30 Jan 2024 15:40:42 +0200 Subject: [PATCH] o/state: record change-update notices on change status updates * o/state: address review comments (thanks @benhoyt) * panic when addNotice fails to signal an internal programmer error * better comments * o/state: skip alternating change-update notices * o/state: address review comments (thanks @olivercalder and @benhoyt) * o/state: save change notice status to disk (thanks @pedronis) * o/state: add omitempty to last-recorded-notice-status change state (thanks @pedronis) Signed-off-by: Zeyad Gouda --- overlord/snapstate/snapstate_test.go | 86 ++++++++++++++++++ overlord/state/change.go | 55 +++++++++--- overlord/state/change_test.go | 129 +++++++++++++++++++++++++++ overlord/state/state.go | 5 ++ 4 files changed, 261 insertions(+), 14 deletions(-) diff --git a/overlord/snapstate/snapstate_test.go b/overlord/snapstate/snapstate_test.go index ea583258d1d..c417bb4d6cc 100644 --- a/overlord/snapstate/snapstate_test.go +++ b/overlord/snapstate/snapstate_test.go @@ -10000,3 +10000,89 @@ func (s *snapmgrTestSuite) TestRefreshInhibitProceedTime(c *C) { expectedRefreshInhibitProceedTime := refreshInhibitedTime.Add(snapstate.MaxInhibition) c.Check(snapst.RefreshInhibitProceedTime(s.state), Equals, expectedRefreshInhibitProceedTime) } + +func (s *snapmgrTestSuite) TestChangeStatusRecordsChangeUpdateNotice(c *C) { + st := s.state + st.Lock() + defer st.Unlock() + + chg := st.NewChange("refresh", "") + + s.o.TaskRunner().AddHandler("fake-task", func(task *state.Task, tomb *tomb.Tomb) error { return nil }, nil) + + var prev *state.Task + addTask := func(name string) { + t := st.NewTask(name, "") + chg.AddTask(t) + if prev != nil { + t.WaitFor(prev) + } + prev = t + } + + for i := 0; i < 5; i++ { + addTask("fake-task") + } + + s.settle(c) + + // Check notice is recorded on change status updates + notices := s.state.Notices(nil) + c.Assert(notices, HasLen, 1) + n := noticeToMap(c, notices[0]) + c.Check(n["type"], Equals, "change-update") + c.Check(n["key"], Equals, chg.ID()) + c.Check(n["last-data"], DeepEquals, map[string]any{"kind": "refresh"}) + // Default -> Doing -> Done + c.Check(n["occurrences"], Equals, 3.0) +} + +func (s *snapmgrTestSuite) TestChangeStatusUndoRecordsChangeUpdateNotice(c *C) { + st := s.state + st.Lock() + defer st.Unlock() + + chg := st.NewChange("refresh", "") + + s.o.TaskRunner().AddHandler("fake-task", func(task *state.Task, tomb *tomb.Tomb) error { return nil }, nil) + + var prev *state.Task + addTask := func(name string) { + t := st.NewTask(name, "") + chg.AddTask(t) + if prev != nil { + t.WaitFor(prev) + } + prev = t + } + + for i := 0; i < 5; i++ { + addTask("fake-task") + } + addTask("error-trigger") + for i := 0; i < 5; i++ { + addTask("fake-task") + } + + s.settle(c) + + // Check notice is recorded on change status updates + notices := s.state.Notices(nil) + c.Assert(notices, HasLen, 1) + n := noticeToMap(c, notices[0]) + c.Check(n["type"], Equals, "change-update") + c.Check(n["key"], Equals, chg.ID()) + c.Check(n["last-data"], DeepEquals, map[string]any{"kind": "refresh"}) + // Default -> Doing -> Undo -> Abort -> Undo -> Error + c.Check(n["occurrences"], Equals, 6.0) +} + +// noticeToMap converts a Notice to a map using a JSON marshal-unmarshal round trip. +func noticeToMap(c *C, notice *state.Notice) map[string]any { + buf, err := json.Marshal(notice) + c.Assert(err, IsNil) + var n map[string]any + err = json.Unmarshal(buf, &n) + c.Assert(err, IsNil) + return n +} diff --git a/overlord/state/change.go b/overlord/state/change.go index ec86431450b..0cdb29223c6 100644 --- a/overlord/state/change.go +++ b/overlord/state/change.go @@ -139,16 +139,17 @@ const ( // while the individual Task values would track the running of // the hooks themselves. type Change struct { - state *State - id string - kind string - summary string - status Status - clean bool - data customData - taskIDs []string - ready chan struct{} - lastObservedStatus Status + state *State + id string + kind string + summary string + status Status + clean bool + data customData + taskIDs []string + ready chan struct{} + lastObservedStatus Status + lastRecordedNoticeStatus Status spawnTime time.Time readyTime time.Time @@ -184,6 +185,8 @@ type marshalledChange struct { SpawnTime time.Time `json:"spawn-time"` ReadyTime *time.Time `json:"ready-time,omitempty"` + + LastRecordedNoticeStatus Status `json:"last-recorded-notice-status,omitempty"` } // MarshalJSON makes Change a json.Marshaller @@ -204,6 +207,8 @@ func (c *Change) MarshalJSON() ([]byte, error) { SpawnTime: c.spawnTime, ReadyTime: readyTime, + + LastRecordedNoticeStatus: c.lastRecordedNoticeStatus, }) } @@ -233,6 +238,7 @@ func (c *Change) UnmarshalJSON(data []byte) error { if unmarshalled.ReadyTime != nil { c.readyTime = *unmarshalled.ReadyTime } + c.lastRecordedNoticeStatus = unmarshalled.LastRecordedNoticeStatus return nil } @@ -423,12 +429,33 @@ func (c *Change) Status() Status { panic(fmt.Sprintf("internal error: cannot process change status: %v", statusStats)) } +// addNotice records an occurrence of a change-update notice for this change. +// The notice key is set to the change ID. +func (c *Change) addNotice() error { + opts := &AddNoticeOptions{ + Data: map[string]string{"kind": c.Kind()}, + } + _, err := c.state.AddNotice(nil, ChangeUpdateNotice, c.id, opts) + return err +} + +func shouldSkipChangeUpdateNotice(old, new Status) bool { + // Skip alternating Doing->Do->Doing and Undoing->Undo->Undoing notices + return (old == new) || (old == DoingStatus && new == DoStatus) || (old == UndoingStatus && new == UndoStatus) +} + func (c *Change) notifyStatusChange(new Status) { - if c.lastObservedStatus == new { - return + if c.lastObservedStatus != new { + c.state.notifyChangeStatusChangedHandlers(c, c.lastObservedStatus, new) + c.lastObservedStatus = new + } + if !shouldSkipChangeUpdateNotice(c.lastRecordedNoticeStatus, new) { + // NOTE: Implies State.writing() + if err := c.addNotice(); err != nil { + logger.Panicf(`internal error: failed to add "change-update" notice on status change: %v`, err) + } + c.lastRecordedNoticeStatus = new } - c.state.notifyChangeStatusChangedHandlers(c, c.lastObservedStatus, new) - c.lastObservedStatus = new } // SetStatus sets the change status, overriding the default behavior (see Status method). diff --git a/overlord/state/change_test.go b/overlord/state/change_test.go index f3098c5ba73..94f7d3647e0 100644 --- a/overlord/state/change_test.go +++ b/overlord/state/change_test.go @@ -20,6 +20,7 @@ package state_test import ( + "encoding/json" "errors" "fmt" "sort" @@ -44,6 +45,15 @@ func (cs *changeSuite) TestNewChange(c *C) { chg := st.NewChange("install", "summary...") c.Check(chg.Kind(), Equals, "install") c.Check(chg.Summary(), Equals, "summary...") + + // Check notice is recorded on change spawn + notices := st.Notices(nil) + c.Assert(notices, HasLen, 1) + n := noticeToMap(c, notices[0]) + c.Check(n["type"], Equals, "change-update") + c.Check(n["key"], Equals, chg.ID()) + c.Check(n["last-data"], DeepEquals, map[string]any{"kind": "install"}) + c.Check(n["occurrences"], Equals, 1.0) } func (cs *changeSuite) TestReadyTime(c *C) { @@ -1450,3 +1460,122 @@ func (cs *changeSuite) TestIsWaitingUndoMultipleDependencies(c *C) { t4.SetStatus(state.UndoneStatus) c.Check(chg.Status(), Equals, state.WaitStatus) } + +func (cs *changeSuite) TestChangeStatusRecordsChangeUpdateNotice(c *C) { + st := state.New(nil) + st.Lock() + defer st.Unlock() + + chg := st.NewChange("change", "...") + + t1 := st.NewTask("task1", "...") + t2 := st.NewTask("task2", "...") + t2.WaitFor(t1) + t3 := st.NewTask("task3", "...") + t3.WaitFor(t2) + + chg.AddTask(t1) + chg.AddTask(t2) + chg.AddTask(t3) + + // Verify that change status is alternating Doing -> Do -> Doing + t1.SetStatus(state.DoingStatus) + c.Assert(chg.Status(), Equals, state.DoingStatus) + t1.SetStatus(state.DoneStatus) + c.Assert(chg.Status(), Equals, state.DoStatus) + + t2.SetStatus(state.DoingStatus) + c.Assert(chg.Status(), Equals, state.DoingStatus) + t2.SetStatus(state.DoneStatus) + c.Assert(chg.Status(), Equals, state.DoStatus) + + t3.SetStatus(state.DoingStatus) + c.Assert(chg.Status(), Equals, state.DoingStatus) + t3.SetStatus(state.DoneStatus) + c.Assert(chg.Status(), Equals, state.DoneStatus) + + // Check notice is recorded on change status updates and ignores + // the alternating status + notices := st.Notices(nil) + c.Assert(notices, HasLen, 1) + n := noticeToMap(c, notices[0]) + c.Check(n["type"], Equals, "change-update") + c.Check(n["key"], Equals, chg.ID()) + c.Check(n["last-data"], DeepEquals, map[string]any{"kind": "change"}) + // Default -> Doing -> Done + c.Check(n["occurrences"], Equals, 3.0) +} + +func (cs *changeSuite) TestChangeStatusUndoRecordsChangeUpdateNotice(c *C) { + st := state.New(nil) + st.Lock() + defer st.Unlock() + + chg := st.NewChange("change", "...") + + t1 := st.NewTask("task1", "...") + t2 := st.NewTask("task2", "...") + t2.WaitFor(t1) + t3 := st.NewTask("task3", "...") + t3.WaitFor(t2) + + chg.AddTask(t1) + chg.AddTask(t2) + chg.AddTask(t3) + + // Verify that change status is alternating Doing -> Do -> Doing + t1.SetStatus(state.DoingStatus) + c.Assert(chg.Status(), Equals, state.DoingStatus) + t1.SetStatus(state.DoneStatus) + c.Assert(chg.Status(), Equals, state.DoStatus) + + t2.SetStatus(state.DoingStatus) + c.Assert(chg.Status(), Equals, state.DoingStatus) + t2.SetStatus(state.DoneStatus) + c.Assert(chg.Status(), Equals, state.DoStatus) + + // Trigger an error and abort change + chg.Abort() + t3.SetStatus(state.ErrorStatus) + c.Assert(chg.Status(), Equals, state.UndoStatus) + + // Verify that change status is alternating Undo -> Undoing -> Undo + t2.SetStatus(state.UndoingStatus) + c.Assert(chg.Status(), Equals, state.UndoingStatus) + t2.SetStatus(state.UndoneStatus) + c.Assert(chg.Status(), Equals, state.UndoStatus) + + t1.SetStatus(state.UndoingStatus) + c.Assert(chg.Status(), Equals, state.UndoingStatus) + t1.SetStatus(state.UndoneStatus) + c.Assert(chg.Status(), Equals, state.ErrorStatus) + + // Check notice is recorded on change status updates and ignores + // the alternating status + notices := st.Notices(nil) + c.Assert(notices, HasLen, 1) + n := noticeToMap(c, notices[0]) + c.Check(n["type"], Equals, "change-update") + c.Check(n["key"], Equals, chg.ID()) + c.Check(n["last-data"], DeepEquals, map[string]any{"kind": "change"}) + // Default -> Doing -> Undo -> Undoing -> Error + c.Check(n["occurrences"], Equals, 5.0) +} + +func (cs *changeSuite) TestChangeLastRecordedNoitceStatusPersisted(c *C) { + st := state.New(nil) + st.Lock() + defer st.Unlock() + + chg := st.NewChange("change", "summary...") + chg.SetStatus(state.DoingStatus) + + data, err := json.Marshal(chg) + c.Assert(err, IsNil) + + var chgData map[string]any + err = json.Unmarshal(data, &chgData) + c.Assert(err, IsNil) + obtainedStatus := state.Status(chgData["last-recorded-notice-status"].(float64)) + c.Check(obtainedStatus, Equals, state.DoingStatus) +} diff --git a/overlord/state/state.go b/overlord/state/state.go index b8c64ce701d..4c774344ee4 100644 --- a/overlord/state/state.go +++ b/overlord/state/state.go @@ -343,6 +343,11 @@ func (s *State) NewChange(kind, summary string) *Change { id := strconv.Itoa(s.lastChangeId) chg := newChange(s, id, kind, summary) s.changes[id] = chg + // Add change-update notice for newly spawned change + // NOTE: Implies State.writing() + if err := chg.addNotice(); err != nil { + logger.Panicf(`internal error: failed to add "change-update" notice for new change: %v`, err) + } return chg }