package activator import ( "strings" "testing" "time" ) // The wake's timing, on the one line an app can actually scrape // (discussion #6). An instance cannot time its own wake — almost all of it // happens before the app's code can observe anything — so a cold-start // budget's most important figure is the one the app structurally cannot // produce. func TestWakeEventMessageCarriesBothFigures(t *testing.T) { msg := wakeEventMessage(&wokenInstance{ wakeTook: 1400 * time.Millisecond, spawnTook: 1200 * time.Millisecond, spawnVersion: "7507a33", }, false) for _, want := range []string{"instance woke", "1.4s", "spawn 1.2s", "7507a33"} { if !strings.Contains(msg, want) { t.Errorf("wake message %q is missing %q", msg, want) } } } // The two figures have to be separable, because the whole point is telling // "our boot is slow" from "the wake path is slow". A message carrying only a // total answers neither. func TestWakeEventMessageSeparatesSpawnFromTheRest(t *testing.T) { slowBoot := wakeEventMessage(&wokenInstance{wakeTook: 1400 * time.Millisecond, spawnTook: 1200 * time.Millisecond}, false) slowPlatform := wakeEventMessage(&wokenInstance{wakeTook: 1400 * time.Millisecond, spawnTook: 200 * time.Millisecond}, false) if slowBoot == slowPlatform { t.Fatalf("a slow boot and a slow wake path read identically: %q", slowBoot) } if !strings.Contains(slowPlatform, "spawn 200ms") { t.Errorf("message %q does not carry the spawn figure", slowPlatform) } } // Unmeasured is not zero. A wake with no timing (a backend or a test that // does not fill them) must read exactly as the line did before, rather than // claiming an instant wake. func TestWakeEventMessageSaysNothingItDoesNotKnow(t *testing.T) { if got := wakeEventMessage(&wokenInstance{}, false); got != "instance woke" { t.Errorf("untimed wake = %q, want the bare line", got) } if got := wakeEventMessage(&wokenInstance{spawnVersion: "abc1234"}, false); got != "instance woke (version abc1234)" { t.Errorf("untimed wake with a version = %q", got) } if got := wakeEventMessage(nil, false); got != "instance woke" { t.Errorf("nil wake = %q, want the bare line", got) } // A total with no spawn figure still reports the total: half an answer // beats none, and the alternative is dropping a measurement that was // actually taken. if got := wakeEventMessage(&wokenInstance{wakeTook: 900 * time.Millisecond}, false); !strings.Contains(got, "900ms") { t.Errorf("wake with only a total = %q", got) } } // Rounded to a millisecond: a log line a person reads and a script greps, // where microseconds of a several-hundred-millisecond wake are noise in both // directions. func TestWakeEventMessageRoundsToMilliseconds(t *testing.T) { msg := wakeEventMessage(&wokenInstance{ wakeTook: 812*time.Millisecond + 417*time.Microsecond, spawnTook: 640*time.Millisecond + 903*time.Microsecond, }, false) if !strings.Contains(msg, "812ms") || !strings.Contains(msg, "spawn 641ms") { t.Errorf("wake message %q is not rounded to milliseconds", msg) } } // TestWakeEventMessageNamesAWorkerAsStarted pins the one thing the worker // flag changes, and the reason it exists: nothing dialed a sidecar, so // "woke" would describe an event that did not happen — no request was // waiting on the other end of it. The timings mean exactly what they mean // for an instance and are reported unchanged, which is why the noun is the // only difference. func TestWakeEventMessageNamesAWorkerAsStarted(t *testing.T) { got := wakeEventMessage(&wokenInstance{ wakeTook: 1400 * time.Millisecond, spawnVersion: "7507a33", }, true) if !strings.Contains(got, "sidecar started") { t.Fatalf("worker wake message = %q, want it to say the sidecar started", got) } if strings.Contains(got, "instance woke") { t.Fatalf("worker wake message = %q, must not call a sidecar an instance", got) } // The figures are not dropped along with the noun. for _, want := range []string{"1.4s", "7507a33"} { if !strings.Contains(got, want) { t.Errorf("worker wake message %q is missing %q", got, want) } } if got := wakeEventMessage(nil, true); got != "sidecar started" { t.Fatalf("nil yield for a worker = %q, want the bare sidecar line", got) } }