| 1 | package moves |
| 2 | |
| 3 | import ( |
| 4 | "context" |
| 5 | "encoding/json" |
| 6 | "errors" |
| 7 | "fmt" |
| 8 | "os" |
| 9 | "sort" |
| 10 | "strconv" |
| 11 | "strings" |
| 12 | "time" |
| 13 | |
| 14 | "github.com/carlosframework/platform/internal/provision" |
| 15 | "github.com/carlosframework/platform/internal/release" |
| 16 | ) |
| 17 | |
| 18 | // The move log (spec §13, Plan 6 Task 3): one object per transition under the |
| 19 | // move's report prefix, log/<identity>.json, in the deployment bucket beside |
| 20 | // the reports and the stop evidence. |
| 21 | // |
| 22 | // The key is the transition's identity, never a counter (round-2 finding |
| 23 | // 23): <state>-<phase> for a phase step (cutting-stopped, landing-probing, |
| 24 | // rolling_back-source-claimed), probe_attempt-<n> for the landing's n-th |
| 25 | // probe, stuck-<epoch> and retry-<epoch> keyed by the record's recovery retry |
| 26 | // epoch (claim Plan 10, preflight L11), and the terminal outcome itself |
| 27 | // (done, rolled_back, aborted). An object is written create-only: the first |
| 28 | // writer of a transition wins, and a second writer, or a replay, meets the |
| 29 | // existing object, which is success with nothing created (preflight L27). |
| 30 | // The log is read in At order (ReadLog), never by key. |
| 31 | |
| 32 | // LogEvent is one move log object. |
| 33 | type LogEvent struct { |
| 34 | V int `json:"v"` |
| 35 | Op string `json:"op"` |
| 36 | Host string `json:"host"` |
| 37 | Event string `json:"event"` |
| 38 | Identity string `json:"identity"` |
| 39 | Actor string `json:"actor"` |
| 40 | At time.Time `json:"at"` |
| 41 | Fields map[string]string `json:"fields,omitempty"` |
| 42 | } |
| 43 | |
| 44 | // ErrLogIdentity refuses an identity that is not one key segment. |
| 45 | var ErrLogIdentity = errors.New("moves: a log identity is one key segment") |
| 46 | |
| 47 | func validLogIdentity(id string) bool { |
| 48 | return id != "" && id != "." && id != ".." && !strings.ContainsAny(id, "/\\\x00") |
| 49 | } |
| 50 | |
| 51 | // WriteLog writes ev at LogKeyFor(prefix, ev.Identity), create-only. created |
| 52 | // is true only for the writer that made the object; an existing object is |
| 53 | // success with created false. |
| 54 | func WriteLog(ctx context.Context, s release.Store, prefix string, ev LogEvent) (created bool, err error) { |
| 55 | if !validLogIdentity(ev.Identity) { |
| 56 | return false, fmt.Errorf("%w: %q", ErrLogIdentity, ev.Identity) |
| 57 | } |
| 58 | body, err := json.Marshal(ev) |
| 59 | if err != nil { |
| 60 | return false, err |
| 61 | } |
| 62 | if _, err := s.Put(ctx, LogKeyFor(prefix, ev.Identity), body, ""); err != nil { |
| 63 | if errors.Is(err, release.ErrCASConflict) { |
| 64 | return false, nil |
| 65 | } |
| 66 | return false, err |
| 67 | } |
| 68 | return true, nil |
| 69 | } |
| 70 | |
| 71 | // ReadLog reads every object under prefix's log/, ordered by At (then by |
| 72 | // identity, for two at the same instant). An object that went missing |
| 73 | // between the list and the read is skipped. |
| 74 | func ReadLog(ctx context.Context, s release.Store, prefix string) ([]LogEvent, error) { |
| 75 | keys, err := s.List(ctx, prefix+"log/") |
| 76 | if err != nil { |
| 77 | return nil, err |
| 78 | } |
| 79 | out := make([]LogEvent, 0, len(keys)) |
| 80 | for _, k := range keys { |
| 81 | body, _, err := s.Get(ctx, k) |
| 82 | if errors.Is(err, os.ErrNotExist) { |
| 83 | continue |
| 84 | } |
| 85 | if err != nil { |
| 86 | return nil, err |
| 87 | } |
| 88 | var ev LogEvent |
| 89 | if err := json.Unmarshal(body, &ev); err != nil { |
| 90 | return nil, fmt.Errorf("moves: log object %s: %w", k, err) |
| 91 | } |
| 92 | out = append(out, ev) |
| 93 | } |
| 94 | sort.SliceStable(out, func(i, j int) bool { |
| 95 | if !out[i].At.Equal(out[j].At) { |
| 96 | return out[i].At.Before(out[j].At) |
| 97 | } |
| 98 | return out[i].Identity < out[j].Identity |
| 99 | }) |
| 100 | return out, nil |
| 101 | } |
| 102 | |
| 103 | // Timings (spec §13, Plan 6 Task 4): how long a move took, phase by phase, |
| 104 | // each beside its budget, in seconds. They are worked out once, from the |
| 105 | // record's own journal times, when the done or rolled_back entry is built |
| 106 | // (TransitionOf, whoever writes it), never from a clock at delivery, and |
| 107 | // carried in that entry's Fields; detail=1 shows them from there (TimingsOf). |
| 108 | // |
| 109 | // - prepare_s: requested_at to ready_at. |
| 110 | // - cut_s: cut_at to flipped_at. |
| 111 | // - land_s: flipped_at to opened_at, against land_budget_s, the landing |
| 112 | // deadline (provision.LandingDeadlineOf: the earlier of cut_deadline and |
| 113 | // landing_deadline) less flipped_at. |
| 114 | // - offline_s: cut_at to the open, or to the source's reopen after a |
| 115 | // rollback or a revert (provision.MoveOfflineS, the closes' own), |
| 116 | // against cut_budget_s, the admitted stop-to-open estimate (T11). |
| 117 | // - rollback_s: a rollback's decision (rollback.requested_at) to the |
| 118 | // source's reopen (rollback.opened_at), against release_budget_s, its |
| 119 | // release deadline less its decision. The record stamps no "released", |
| 120 | // so the rollback is measured to the reopen, which comes only after the |
| 121 | // target's release. |
| 122 | // |
| 123 | // A timing whose ends are not both stamped is left out, and so is a budget |
| 124 | // the record does not carry. |
| 125 | const ( |
| 126 | TimingPrepare = "prepare_s" |
| 127 | TimingCut = "cut_s" |
| 128 | TimingCutBudget = "cut_budget_s" |
| 129 | TimingLand = "land_s" |
| 130 | TimingLandBudget = "land_budget_s" |
| 131 | TimingOffline = "offline_s" |
| 132 | TimingRollback = "rollback_s" |
| 133 | TimingReleaseBudget = "release_budget_s" |
| 134 | ) |
| 135 | |
| 136 | // timingKeys are every key Timings may set. |
| 137 | var timingKeys = []string{TimingPrepare, TimingCut, TimingCutBudget, TimingLand, TimingLandBudget, TimingOffline, TimingRollback, TimingReleaseBudget} |
| 138 | |
| 139 | // Timings is m's timings (see above); empty for no move. |
| 140 | func Timings(m *provision.MoveState) map[string]float64 { |
| 141 | out := map[string]float64{} |
| 142 | if m == nil { |
| 143 | return out |
| 144 | } |
| 145 | span := func(key string, from, to *time.Time) { |
| 146 | if from != nil && to != nil { |
| 147 | out[key] = to.Sub(*from).Seconds() |
| 148 | } |
| 149 | } |
| 150 | if !m.RequestedAt.IsZero() { |
| 151 | span(TimingPrepare, &m.RequestedAt, m.ReadyAt) |
| 152 | } |
| 153 | span(TimingCut, m.CutAt, m.FlippedAt) |
| 154 | if m.CutBudgetS > 0 { |
| 155 | out[TimingCutBudget] = float64(m.CutBudgetS) |
| 156 | } |
| 157 | if m.State == provision.MoveCommitted { |
| 158 | span(TimingLand, m.FlippedAt, m.OpenedAt) |
| 159 | } |
| 160 | if d, _ := provision.LandingDeadlineOf(m); m.FlippedAt != nil { |
| 161 | span(TimingLandBudget, m.FlippedAt, d) |
| 162 | } |
| 163 | if s, ok := provision.MoveOfflineS(m); ok { |
| 164 | out[TimingOffline] = s |
| 165 | } |
| 166 | if rb := m.Rollback; rb != nil { |
| 167 | span(TimingRollback, rb.RequestedAt, rb.OpenedAt) |
| 168 | span(TimingReleaseBudget, rb.RequestedAt, rb.ReleaseDeadline) |
| 169 | } |
| 170 | return out |
| 171 | } |
| 172 | |
| 173 | // TimingsOf is the timings a logged entry's Fields carry: the timing keys |
| 174 | // alone, each parsed back to seconds; anything else in the fields, and a |
| 175 | // value that does not parse, is left out. |
| 176 | func TimingsOf(fields map[string]string) map[string]float64 { |
| 177 | out := map[string]float64{} |
| 178 | for _, k := range timingKeys { |
| 179 | v, ok := fields[k] |
| 180 | if !ok { |
| 181 | continue |
| 182 | } |
| 183 | if f, err := strconv.ParseFloat(v, 64); err == nil { |
| 184 | out[k] = f |
| 185 | } |
| 186 | } |
| 187 | return out |
| 188 | } |
| 189 | |
| 190 | // timingText is a timing as a field's text: the shortest decimal that |
| 191 | // parses back to it. |
| 192 | func timingText(s float64) string { |
| 193 | return strconv.FormatFloat(s, 'f', -1, 64) |
| 194 | } |
| 195 | |
amadan