Artifact [1ff6bd078d]

Artifact 1ff6bd078d8fdffb69876b7f5e6133eba1907659e3464d8054335c3115e17b0a:

• File internal/timing/storebusy_test.go — part of check-in [433a022052] at 2026-08-31 15:39:21 on branch trunk — the zit figure's count suffix is two bytes, not one

  The multiplication sign in 'zit 34.1ms×2' never matched a byte compare, so the duration parsed as zero and the store note appeared beside an identical zit figure — claiming a wait already accounted for. (user: quarry, size: 2269) [annotate] [blame] [check-ins using]

package timing

import (
	"testing"
	"time"
)

// The footer reported "ops 11.09s×8, zit 32.9ms" on a page whose real
// cost was six seconds of a zit call made on context.Background(). The
// timer lives in the request context, so a detached call is invisible
// to it while the render still waits. The store note is what makes that
// wait visible.
func TestStoreBusyNamesWaitTheContextMissed(t *testing.T) {
	got := WithStoreBusy("ops 11.09s×8, zit 32.9ms", 6*time.Second)
	if got == "ops 11.09s×8, zit 32.9ms" {
		t.Fatal("six seconds of store wait went unreported")
	}
	if want := "store "; !contains(got, want) {
		t.Errorf("breakdown %q does not name the store wait", got)
	}
}

// When the render's own zit total already covers the busy window there
// is nothing new to say, and a second number would only invite adding
// the two together.
func TestStoreBusyStaysQuietWhenAlreadyAttributed(t *testing.T) {
	in := "ops 500ms×3, zit 400ms"
	if got := WithStoreBusy(in, 300*time.Millisecond); got != in {
		t.Errorf("added a redundant note: %q", got)
	}
	if got := WithStoreBusy(in, 0); got != in {
		t.Errorf("added a note for no busy time: %q", got)
	}
}

// A page with no other timing still reports the wait rather than
// dropping it.
func TestStoreBusyOnAnEmptyBreakdown(t *testing.T) {
	if got := WithStoreBusy("", 2*time.Second); got == "" {
		t.Error("store wait dropped when there was nothing else to say")
	}
}

func contains(h, n string) bool {
	for i := 0; i+len(n) <= len(h); i++ {
		if h[i:i+len(n)] == n {
			return true
		}
	}
	return false
}

// The zit figure carries a count suffix ("zit 34.1ms×2"). The
// multiplication sign is two bytes in UTF-8, so a byte comparison never
// finds it and the duration parses as zero — which made the note appear
// beside an identical zit figure, claiming a wait that was already
// accounted for.
func TestStoreBusyReadsAZitFigureWithACount(t *testing.T) {
	in := "ops 107.4ms×8, zit 34.1ms×2"
	if got := WithStoreBusy(in, 34*time.Millisecond); got != in {
		t.Errorf("added a redundant note past a count suffix: %q", got)
	}
	// And still speaks when the wait genuinely exceeds it.
	if got := WithStoreBusy(in, 6*time.Second); got == in {
		t.Error("six seconds of wait went unreported")
	}
}