Artifact [7c9e5e66c8]

Artifact 7c9e5e66c8da4c32dd40fe69bc3136cde9499882664a56feaa3351d398dadd44:

• File internal/obs/route_test.go — part of check-in [bb6ec6b896] at 2026-08-25 21:45:00 on branch ops-drill — ops: open a route up — which repository, and which store calls

  The panel finds a slow route; this says why. Two things the roll-up cannot show.

  WHICH REPOSITORY. A route pattern folds pikchr and tcl into one line, and repository size is the dominant cost on this fleet — GET /r/{repo} at 420ms could be either, and the two differ by orders of magnitude.

  WHICH CALLS. Each recent request is listed with the store calls it made, in the order it made them, and what they cost together. A request with no calls listed spent its time somewhere else, which is itself the answer when the store is not to blame.

  Reads the same rings the panels read, so a request that has aged out simply is not there. That is the honest limit of a snapshot: this answers what a slow request just did, not what happened yesterday. (user: dmestas, size: 3299) [annotate] [blame] [check-ins using] [more...]

package obs

import (
	"context"
	"testing"
	"time"
)

// The drilldown exists because the render list and the subprocess list
// were independent tables: "GET /search took 1132ms" and "zit artifact
// ran 499 times" could not be connected even when one caused the other.
// This is the connection.
func TestRouteAttributesCallsToTheRequestThatCausedThem(t *testing.T) {
	r := NewRecorder(100, nil)

	// Two requests on one route, against different repositories, plus
	// background work belonging to neither.
	r.RecordSubprocess(Subprocess{RenderID: "", Verb: "frames", Repo: "tcl", Duration: time.Second})
	r.RecordSubprocess(Subprocess{RenderID: "a", Verb: "ls", Repo: "pikchr", Duration: 5 * time.Millisecond})
	r.RecordSubprocess(Subprocess{RenderID: "a", Verb: "cat", Repo: "pikchr", Duration: 3 * time.Millisecond})
	r.RecordRender(Render{ID: "a", Path: "GET /r/{repo}", Repo: "pikchr", Elapsed: 20 * time.Millisecond})

	r.RecordSubprocess(Subprocess{RenderID: "b", Verb: "diff", Repo: "tcl", Duration: 400 * time.Millisecond})
	r.RecordRender(Render{ID: "b", Path: "GET /r/{repo}", Repo: "tcl", Elapsed: 900 * time.Millisecond})

	d := r.Route("GET /r/{repo}", 10)
	if len(d.Renders) != 2 {
		t.Fatalf("renders = %d, want 2", len(d.Renders))
	}
	// Newest first.
	if d.Renders[0].Render.Repo != "tcl" {
		t.Errorf("first render repo = %q, want tcl (newest first)", d.Renders[0].Render.Repo)
	}
	if len(d.Renders[0].Calls) != 1 || d.Renders[0].Calls[0].Verb != "diff" {
		t.Errorf("tcl request calls = %+v, want exactly its own diff", d.Renders[0].Calls)
	}
	if len(d.Renders[1].Calls) != 2 {
		t.Fatalf("pikchr request calls = %d, want 2", len(d.Renders[1].Calls))
	}
	// Oldest first WITHIN a request: the order the page made them.
	if d.Renders[1].Calls[0].Verb != "ls" || d.Renders[1].Calls[1].Verb != "cat" {
		t.Errorf("call order = %v, want the order the page issued them",
			[]string{d.Renders[1].Calls[0].Verb, d.Renders[1].Calls[1].Verb})
	}
	// Background work belongs to no request and must not be blamed on one.
	for _, rc := range d.Renders {
		for _, c := range rc.Calls {
			if c.Verb == "frames" {
				t.Error("background work was attributed to a request")
			}
		}
	}
}

// A route nobody asked for is empty, not a panic.
func TestRouteWithNoTraffic(t *testing.T) {
	r := NewRecorder(4, nil)
	if d := r.Route("GET /nope", 5); len(d.Renders) != 0 || d.Path != "GET /nope" {
		t.Errorf("got %+v, want an empty detail naming the route", d)
	}
}

// The tag rides the context so a store call deep in a handler can name
// the page above it, and background work — which has no request —
// reports the empty string rather than guessing.
func TestRequestIDRidesTheContext(t *testing.T) {
	ctx, id := WithRequest(context.Background())
	if id == "" {
		t.Fatal("WithRequest returned an empty id")
	}
	if got := RequestID(ctx); got != id {
		t.Errorf("RequestID = %q, want %q", got, id)
	}
	if got := RequestID(context.Background()); got != "" {
		t.Errorf("untagged context = %q, want empty — background work must not borrow an id", got)
	}
	if RequestID(nil) != "" {
		t.Error("a nil context must be empty, not a panic")
	}
	_, id2 := WithRequest(context.Background())
	if id2 == id {
		t.Error("two requests share an id; calls would be attributed to the wrong page")
	}
}