| 1 | package console |
| 2 | |
| 3 | import ( |
| 4 | "context" |
| 5 | "encoding/json" |
| 6 | "net/http" |
| 7 | "strconv" |
| 8 | "strings" |
| 9 | "testing" |
| 10 | "time" |
| 11 | |
| 12 | "github.com/carlosframework/platform/internal/apperr" |
| 13 | "github.com/carlosframework/platform/internal/applog" |
| 14 | "github.com/carlosframework/platform/internal/release" |
| 15 | "github.com/carlosframework/platform/internal/svcrole" |
| 16 | "github.com/carlosframework/platform/internal/telemetry" |
| 17 | ) |
| 18 | |
| 19 | func errorsURL(fx *consoleFixture, acct, app, query string) string { |
| 20 | u := fx.ts.URL + "/api/cli/apps/" + acct + "/" + app + "/errors" |
| 21 | if query != "" { |
| 22 | u += "?" + query |
| 23 | } |
| 24 | return u |
| 25 | } |
| 26 | |
| 27 | // seedErrors ships one coalesced edge error and, via seedLogChunks, one |
| 28 | // error-level platform line and one warn-level app line — plus, for |
| 29 | // Availability, a warn-level platform exit, two 502s filed before the |
| 30 | // amendment (one row per path) and one filed after it (by cause). |
| 31 | func seedErrors(t *testing.T, fx *consoleFixture, now time.Time) { |
| 32 | t.Helper() |
| 33 | seedLogChunks(t, fx, now) |
| 34 | warn := []applog.Record{{TS: now.Add(-7 * time.Minute), Box: "box1", Host: "titogo.example.com", |
| 35 | Stream: applog.StreamApp, Level: applog.LevelWarn, Msg: "slow query 4123ms", Seq: 150}, |
| 36 | {TS: now.Add(-6 * time.Minute), Box: "box1", Host: "titogo.example.com", |
| 37 | Stream: applog.StreamPlatform, Level: applog.LevelWarn, Msg: "instance exited: signal: killed", Seq: 151}, |
| 38 | {TS: now.Add(-6 * time.Minute), Box: "box1", Host: "titogo.example.com", |
| 39 | Stream: applog.StreamPlatform, Level: applog.LevelWarn, Msg: "dropped 12 app log line(s) (rate cap)", Seq: 152}} |
| 40 | body, _ := applog.EncodeChunk(warn) |
| 41 | if _, err := fx.rel.Put(context.Background(), mustKey(t)(applog.ChunkKey(release.OpsAccount, "titogo", "box1", applog.HourOf(warn[0].TS), 150, len(body))), body, ""); err != nil { |
| 42 | t.Fatal(err) |
| 43 | } |
| 44 | e := []apperr.Record{{TS: now.Add(-3 * time.Minute), Box: "box1", Host: "titogo.example.com", |
| 45 | Source: apperr.SourceEdge, Kind: apperr.KindHTTP, Name: "500 POST /checkout", Path: "/checkout", Status: 500, |
| 46 | Release: "v3", FP: "edge500", FPV: 1, Count: 12, First: now.Add(-9 * time.Minute), Last: now.Add(-3 * time.Minute), Seq: 200}, |
| 47 | {TS: now.Add(-8 * time.Minute), Box: "box1", Host: "titogo.example.com", |
| 48 | Source: apperr.SourceEdge, Kind: apperr.KindHTTP, Name: "502 GET /.env", Path: "/.env", Status: 502, |
| 49 | Release: "v3", FP: "old502env", FPV: 1, Count: 1, First: now.Add(-8 * time.Minute), Last: now.Add(-8 * time.Minute), Seq: 201}, |
| 50 | {TS: now.Add(-8 * time.Minute), Box: "box1", Host: "titogo.example.com", |
| 51 | Source: apperr.SourceEdge, Kind: apperr.KindHTTP, Name: "502 GET /phpinfo.php", Path: "/phpinfo.php", Status: 502, |
| 52 | Release: "v3", FP: "old502php", FPV: 1, Count: 1, First: now.Add(-8 * time.Minute), Last: now.Add(-8 * time.Minute), Seq: 202}, |
| 53 | {TS: now.Add(-2 * time.Minute), Box: "box1", Host: "titogo.example.com", |
| 54 | Source: apperr.SourceEdge, Kind: apperr.KindUnavailable, Cause: apperr.CauseRefused, |
| 55 | Name: apperr.AvailabilityName(502, apperr.CauseRefused), Path: "/admin", Status: 502, |
| 56 | Release: "v4", FP: "new502", FPV: 1, Count: 5, First: now.Add(-4 * time.Minute), Last: now.Add(-2 * time.Minute), Seq: 203}} |
| 57 | eb, _ := apperr.EncodeChunk(e) |
| 58 | if _, err := fx.rel.Put(context.Background(), mustKey(t)(apperr.ChunkKey(release.OpsAccount, "titogo", "box1", apperr.HourOf(e[0].TS), 200, len(eb))), eb, ""); err != nil { |
| 59 | t.Fatal(err) |
| 60 | } |
| 61 | } |
| 62 | |
| 63 | func TestAPIErrorsGroupsBothFamilies(t *testing.T) { |
| 64 | fx, token := instanceFixture(t, "code-errors-1") |
| 65 | now := time.Now().UTC() |
| 66 | seedErrors(t, fx, now) |
| 67 | get := func(query string) errorsResponse { |
| 68 | t.Helper() |
| 69 | status, _, body := rawReq(t, http.MethodGet, errorsURL(fx, fx.sqid, "titogo", query), token, "") |
| 70 | if status != http.StatusOK { |
| 71 | t.Fatalf("GET ?%s = %d: %s", query, status, body) |
| 72 | } |
| 73 | var resp errorsResponse |
| 74 | if err := json.Unmarshal([]byte(body), &resp); err != nil { |
| 75 | t.Fatal(err) |
| 76 | } |
| 77 | return resp |
| 78 | } |
| 79 | // The 502s and the platform events are Availability's, not Errors'. |
| 80 | resp := get("") |
| 81 | if len(resp.Groups) != 1 { |
| 82 | t.Fatalf("groups = %+v", resp.Groups) |
| 83 | } |
| 84 | if resp.Groups[0].FP != "edge500" || resp.Groups[0].Count != 12 || resp.Groups[0].Releases[0] != "v3" { |
| 85 | t.Fatalf("newest first, coalesced count: %+v", resp.Groups[0]) |
| 86 | } |
| 87 | if resp.LogLevel != "error" || len(resp.Sources) != 1 { |
| 88 | t.Fatalf("meta = %q %v", resp.LogLevel, resp.Sources) |
| 89 | } |
| 90 | // A warn read widens without changing the setting. |
| 91 | if resp = get("level=warn"); len(resp.Groups) != 2 { |
| 92 | t.Fatalf("level=warn groups = %d", len(resp.Groups)) |
| 93 | } |
| 94 | if resp.Groups[1].Source != apperr.SourceLog || !strings.Contains(resp.Groups[1].Name, "slow query") { |
| 95 | t.Fatalf("log-derived group: %+v", resp.Groups[1]) |
| 96 | } |
| 97 | // Source and fp filters. |
| 98 | if resp = get("source=edge"); len(resp.Groups) != 1 || resp.Groups[0].FP != "edge500" { |
| 99 | t.Fatalf("source filter = %+v", resp.Groups) |
| 100 | } |
| 101 | if resp = get("fp=edge500"); len(resp.Records) != 1 || resp.Records[0].Status != 500 { |
| 102 | t.Fatalf("fp expand = %+v", resp.Records) |
| 103 | } |
| 104 | } |
| 105 | |
| 106 | // TestAPIErrorsRefusals mirrors TestAPILogsRefusals (apilogs_test.go): a |
| 107 | // non-member's read is the family's byte-identical 404; bad parameters |
| 108 | // name themselves in a 400. |
| 109 | func TestAPIErrorsRefusals(t *testing.T) { |
| 110 | fx, _ := instanceFixture(t, "code-errs-refusal") |
| 111 | eve := cliToken(t, fx, "eve@keymail.dev", "code-errs-eve") |
| 112 | want := canonicalNotFound(t) |
| 113 | status, h, body := rawReq(t, http.MethodGet, errorsURL(fx, fx.sqid, "titogo", ""), eve, "") |
| 114 | assertNotFound(t, "errors as non-member", want, status, h, body) |
| 115 | |
| 116 | token := cliToken(t, fx, "alice@keymail.dev", "code-errs-token") |
| 117 | for _, q := range []string{"since=nonsense", "source=mars", "fp=has space", "level=loud"} { |
| 118 | status, _, body := rawReq(t, http.MethodGet, errorsURL(fx, fx.sqid, "titogo", q), token, "") |
| 119 | if status != http.StatusBadRequest { |
| 120 | t.Errorf("?%s = %d, want 400 (%s)", q, status, body) |
| 121 | } |
| 122 | } |
| 123 | } |
| 124 | |
| 125 | func TestAPITelemetryPutSetsLogLevel(t *testing.T) { |
| 126 | fx, token := instanceFixture(t, "code-errors-2") |
| 127 | now := time.Now().UTC() |
| 128 | seedErrors(t, fx, now) |
| 129 | // The instance token may read but not write settings: Operate only. |
| 130 | inst := serviceToken(t, fx.st, OpsAccountID, "router", "titogo", svcrole.Instance) |
| 131 | status, _, body := rawReq(t, http.MethodPut, fx.ts.URL+"/api/cli/apps/"+fx.sqid+"/titogo/telemetry", inst, `{"errors":{"log_level":"warn"}}`) |
| 132 | if status != http.StatusForbidden && status != http.StatusNotFound { |
| 133 | t.Fatalf("instance token PUT = %d %s", status, body) |
| 134 | } |
| 135 | // A PERSON must be an owner: the browser form for this setting 404s a |
| 136 | // member, so the API must not be the way around it. alice (the |
| 137 | // fixture's token) is a member. |
| 138 | status, _, body = rawReq(t, http.MethodPut, fx.ts.URL+"/api/cli/apps/"+fx.sqid+"/titogo/telemetry", token, `{"errors":{"log_level":"warn"}}`) |
| 139 | if status != http.StatusForbidden { |
| 140 | t.Fatalf("member PUT = %d %s", status, body) |
| 141 | } |
| 142 | if r, _ := telemetry.Resolve(context.Background(), fx.rel, fx.sqid, "titogo"); r.LogLevel != "error" { |
| 143 | t.Fatalf("a refused PUT wrote anyway: %+v", r) |
| 144 | } |
| 145 | // paul owns the ops account in the fixture. |
| 146 | owner := cliToken(t, fx, "paul@keymail.dev", "code-errors-owner") |
| 147 | status, _, body = rawReq(t, http.MethodPut, fx.ts.URL+"/api/cli/apps/"+fx.sqid+"/titogo/telemetry", owner, `{"errors":{"log_level":"error"}}`) |
| 148 | if status != http.StatusOK { |
| 149 | t.Fatalf("owner PUT = %d %s", status, body) |
| 150 | } |
| 151 | op := serviceToken(t, fx.st, OpsAccountID, "ops", "titogo", svcrole.Operate) |
| 152 | status, _, body = rawReq(t, http.MethodPut, fx.ts.URL+"/api/cli/apps/"+fx.sqid+"/titogo/telemetry", op, `{"errors":{"log_level":"warn"}}`) |
| 153 | if status != http.StatusOK { |
| 154 | t.Fatalf("PUT = %d %s", status, body) |
| 155 | } |
| 156 | r, _ := telemetry.Resolve(context.Background(), fx.rel, fx.sqid, "titogo") |
| 157 | if r.LogLevel != "warn" || r.LogLevelFrom != "app" { |
| 158 | t.Fatalf("resolved = %+v", r) |
| 159 | } |
| 160 | status, _, body = rawReq(t, http.MethodGet, errorsURL(fx, fx.sqid, "titogo", ""), token, "") |
| 161 | var resp errorsResponse |
| 162 | json.Unmarshal([]byte(body), &resp) |
| 163 | if status != 200 || resp.LogLevel != "warn" || len(resp.Groups) != 2 { |
| 164 | t.Fatalf("after set: %d level=%q groups=%d", status, resp.LogLevel, len(resp.Groups)) |
| 165 | } |
| 166 | status, _, body = rawReq(t, http.MethodPut, fx.ts.URL+"/api/cli/apps/"+fx.sqid+"/titogo/telemetry", op, `{"errors":{"log_level":"loud"}}`) |
| 167 | if status != http.StatusBadRequest { |
| 168 | t.Fatalf("bad level = %d %s", status, body) |
| 169 | } |
| 170 | } |
| 171 | |
| 172 | // TestAppErrorsPageCaps: the tab renders a page's worth of both of its |
| 173 | // shapes — appErrorsPageCap groups in the table, appErrorsPageCap |
| 174 | // occurrences in an expanded group — and says so. readErrors collects up to |
| 175 | // logsCollectCap records, so without the cap a busy app's tab is a render |
| 176 | // nobody asked for. |
| 177 | func TestAppErrorsPageCaps(t *testing.T) { |
| 178 | fx, _ := instanceFixture(t, "code-errors-cap") |
| 179 | now := time.Now().UTC() |
| 180 | var recs []apperr.Record |
| 181 | for i := 0; i < appErrorsPageCap+50; i++ { |
| 182 | ts := now.Add(-10 * time.Minute).Add(time.Duration(i) * time.Second) |
| 183 | recs = append(recs, |
| 184 | // One group each: the table's cap. |
| 185 | apperr.Record{TS: ts, Box: "box1", Host: "titogo.example.com", |
| 186 | Source: apperr.SourceEdge, Kind: apperr.KindHTTP, |
| 187 | Name: "500 GET /bulk" + strconv.Itoa(i), Path: "/bulk" + strconv.Itoa(i), Status: 500, |
| 188 | FP: "bulk" + strconv.Itoa(i), FPV: 1, Count: 1, First: ts, Last: ts, Seq: uint64(1000 + i)}, |
| 189 | // One group of many: the expanded view's cap. |
| 190 | apperr.Record{TS: ts, Box: "box1", Host: "titogo.example.com", |
| 191 | Source: apperr.SourceEdge, Kind: apperr.KindHTTP, |
| 192 | Name: "500 POST /one", Path: "/one", Status: 500, |
| 193 | FP: "bulkone", FPV: 1, Count: 1, First: ts, Last: ts, Seq: uint64(9000 + i)}) |
| 194 | } |
| 195 | body, err := apperr.EncodeChunk(recs) |
| 196 | if err != nil { |
| 197 | t.Fatal(err) |
| 198 | } |
| 199 | if _, err := fx.rel.Put(context.Background(), mustKey(t)(apperr.ChunkKey(release.OpsAccount, "titogo", "box1", apperr.HourOf(recs[0].TS), 1000, len(body))), body, ""); err != nil { |
| 200 | t.Fatal(err) |
| 201 | } |
| 202 | fx.setUser("paul@keymail.dev") |
| 203 | c := newBrowser(t) |
| 204 | signUp(t, fx, c, "code-errors-cap-signin") |
| 205 | |
| 206 | status, _, page := get(t, c, fx.u("/apps/titogo/errors")) |
| 207 | if status != http.StatusOK { |
| 208 | t.Fatalf("errors page: %d", status) |
| 209 | } |
| 210 | if n := strings.Count(page, "fp=bulk"); n != appErrorsPageCap { |
| 211 | t.Errorf("group rows = %d, want %d", n, appErrorsPageCap) |
| 212 | } |
| 213 | if !strings.Contains(page, "groups of a larger window") { |
| 214 | t.Error("a capped table must say it was capped") |
| 215 | } |
| 216 | status, _, page = get(t, c, fx.u("/apps/titogo/errors?fp=bulkone")) |
| 217 | if status != http.StatusOK { |
| 218 | t.Fatalf("expanded page: %d", status) |
| 219 | } |
| 220 | if n := strings.Count(page, "<th>Path</th>"); n != appErrorsPageCap { |
| 221 | t.Errorf("occurrence cards = %d, want %d", n, appErrorsPageCap) |
| 222 | } |
| 223 | if !strings.Contains(page, "occurrences of a larger window") { |
| 224 | t.Error("a capped occurrence list must say it was capped") |
| 225 | } |
| 226 | } |
| 227 | |
| 228 | func TestAppErrorsPage(t *testing.T) { |
| 229 | fx, _ := instanceFixture(t, "code-errors-page") |
| 230 | now := time.Now().UTC() |
| 231 | seedErrors(t, fx, now) |
| 232 | fx.setUser("paul@keymail.dev") |
| 233 | c := newBrowser(t) |
| 234 | signUp(t, fx, c, "code-errors-signin") |
| 235 | status, _, body := get(t, c, fx.u("/apps/titogo/errors")) |
| 236 | if status != http.StatusOK { |
| 237 | t.Fatalf("errors page: %d %s", status, body) |
| 238 | } |
| 239 | for _, want := range []string{"500 POST /checkout", "carlos errors --app titogo", "Sources live: edge", "to the nearest flush"} { |
| 240 | if !strings.Contains(body, want) { |
| 241 | t.Errorf("page missing %q", want) |
| 242 | } |
| 243 | } |
| 244 | for _, not := range []string{"wake failed", "502", "phpinfo"} { |
| 245 | if strings.Contains(body, not) { |
| 246 | t.Errorf("errors page shows Availability's %q", not) |
| 247 | } |
| 248 | } |
| 249 | if strings.Contains(body, "slow query") { |
| 250 | t.Error("warn lines must not show at the default level") |
| 251 | } |
| 252 | status, _, body = get(t, c, fx.u("/apps/titogo/errors?level=warn")) |
| 253 | if status != 200 || !strings.Contains(body, "slow query") { |
| 254 | t.Fatalf("level=warn page: %d", status) |
| 255 | } |
| 256 | status, _, body = get(t, c, fx.u("/apps/titogo/errors?fp=edge500")) |
| 257 | if status != 200 || !strings.Contains(body, "/checkout") || !strings.Contains(body, "v3") { |
| 258 | t.Fatalf("expanded group: %d", status) |
| 259 | } |
| 260 | status, _, body = get(t, c, fx.u("/apps/titogo/errors?since=1ns")) |
| 261 | if status != 200 || !strings.Contains(body, "No errors in this window") { |
| 262 | t.Fatalf("empty window: %d", status) |
| 263 | } |
| 264 | } |
| 265 | |
| 266 | // TestAvailability: the API and the tab hold the other half — edge |
| 267 | // 502/503/504 by cause, history filed per path regrouped by status, and |
| 268 | // the platform's lifecycle events at warn and above, whatever the errors |
| 269 | // level — and none of the app's own errors. |
| 270 | func TestAvailability(t *testing.T) { |
| 271 | fx, token := instanceFixture(t, "code-avail-1") |
| 272 | now := time.Now().UTC() |
| 273 | seedErrors(t, fx, now) |
| 274 | api := func(query string) availabilityResponse { |
| 275 | t.Helper() |
| 276 | u := fx.ts.URL + "/api/cli/apps/" + fx.sqid + "/titogo/availability" |
| 277 | if query != "" { |
| 278 | u += "?" + query |
| 279 | } |
| 280 | status, _, body := rawReq(t, http.MethodGet, u, token, "") |
| 281 | if status != http.StatusOK { |
| 282 | t.Fatalf("GET ?%s = %d: %s", query, status, body) |
| 283 | } |
| 284 | var resp availabilityResponse |
| 285 | if err := json.Unmarshal([]byte(body), &resp); err != nil { |
| 286 | t.Fatal(err) |
| 287 | } |
| 288 | return resp |
| 289 | } |
| 290 | resp := api("") |
| 291 | byName := map[string]apperr.Group{} |
| 292 | for _, g := range resp.Groups { |
| 293 | byName[g.Name] = g |
| 294 | } |
| 295 | if len(resp.Groups) != 4 { |
| 296 | t.Fatalf("groups = %+v", resp.Groups) |
| 297 | } |
| 298 | if g := byName["502 · the instance refused the connection"]; g.Count != 5 || g.Releases[0] != "v4" { |
| 299 | t.Fatalf("new-style group = %+v", g) |
| 300 | } |
| 301 | old, ok := byName["502 · cause not recorded"] |
| 302 | if !ok || old.Count != 2 { |
| 303 | t.Fatalf("history must regroup into one row per status: %+v", resp.Groups) |
| 304 | } |
| 305 | for _, want := range []string{"wake failed: nothing is promoted for this instance's channel", "instance exited: signal: killed"} { |
| 306 | if g, ok := byName[want]; !ok || g.Source != apperr.SourceLog { |
| 307 | t.Errorf("platform event %q missing: %+v", want, resp.Groups) |
| 308 | } |
| 309 | } |
| 310 | if _, ok := byName["500 POST /checkout"]; ok { |
| 311 | t.Fatal("the app's own 500 is Errors', not Availability's") |
| 312 | } |
| 313 | for name := range byName { |
| 314 | if strings.Contains(name, "rate cap") { |
| 315 | t.Fatalf("the logging budget's drop notice is not an availability event: %q", name) |
| 316 | } |
| 317 | } |
| 318 | // Expanding the regrouped row finds both paths, by the FP the tab shows |
| 319 | // rather than the one stored. |
| 320 | resp = api("fp=" + old.FP) |
| 321 | if len(resp.Records) != 2 || resp.Records[0].Path == resp.Records[1].Path { |
| 322 | t.Fatalf("expanded history = %+v", resp.Records) |
| 323 | } |
| 324 | |
| 325 | fx.setUser("paul@keymail.dev") |
| 326 | c := newBrowser(t) |
| 327 | signUp(t, fx, c, "code-avail-signin") |
| 328 | status, _, body := get(t, c, fx.u("/apps/titogo/availability")) |
| 329 | if status != http.StatusOK { |
| 330 | t.Fatalf("availability page: %d %s", status, body) |
| 331 | } |
| 332 | for _, want := range []string{"refused the connection", "cause not recorded", "wake failed", ">platform", "carlos availability --app titogo", |
| 333 | `<h2 class="visually-hidden">Availability</h2>`, `/availability" aria-current="page">Availability</a>`} { |
| 334 | if !strings.Contains(body, want) { |
| 335 | t.Errorf("page missing %q", want) |
| 336 | } |
| 337 | } |
| 338 | if strings.Contains(body, "/checkout") { |
| 339 | t.Error("availability page shows the app's own 500") |
| 340 | } |
| 341 | } |
| 342 | |
amadan