| 1 | package activator |
| 2 | |
| 3 | import ( |
| 4 | "strings" |
| 5 | "testing" |
| 6 | "time" |
| 7 | ) |
| 8 | |
| 9 | // The wake's timing, on the one line an app can actually scrape |
| 10 | // (discussion #6). An instance cannot time its own wake — almost all of it |
| 11 | // happens before the app's code can observe anything — so a cold-start |
| 12 | // budget's most important figure is the one the app structurally cannot |
| 13 | // produce. |
| 14 | |
| 15 | func TestWakeEventMessageCarriesBothFigures(t *testing.T) { |
| 16 | msg := wakeEventMessage(&wokenInstance{ |
| 17 | wakeTook: 1400 * time.Millisecond, |
| 18 | spawnTook: 1200 * time.Millisecond, |
| 19 | spawnVersion: "7507a33", |
| 20 | }, false) |
| 21 | for _, want := range []string{"instance woke", "1.4s", "spawn 1.2s", "7507a33"} { |
| 22 | if !strings.Contains(msg, want) { |
| 23 | t.Errorf("wake message %q is missing %q", msg, want) |
| 24 | } |
| 25 | } |
| 26 | } |
| 27 | |
| 28 | // The two figures have to be separable, because the whole point is telling |
| 29 | // "our boot is slow" from "the wake path is slow". A message carrying only a |
| 30 | // total answers neither. |
| 31 | func TestWakeEventMessageSeparatesSpawnFromTheRest(t *testing.T) { |
| 32 | slowBoot := wakeEventMessage(&wokenInstance{wakeTook: 1400 * time.Millisecond, spawnTook: 1200 * time.Millisecond}, false) |
| 33 | slowPlatform := wakeEventMessage(&wokenInstance{wakeTook: 1400 * time.Millisecond, spawnTook: 200 * time.Millisecond}, false) |
| 34 | if slowBoot == slowPlatform { |
| 35 | t.Fatalf("a slow boot and a slow wake path read identically: %q", slowBoot) |
| 36 | } |
| 37 | if !strings.Contains(slowPlatform, "spawn 200ms") { |
| 38 | t.Errorf("message %q does not carry the spawn figure", slowPlatform) |
| 39 | } |
| 40 | } |
| 41 | |
| 42 | // Unmeasured is not zero. A wake with no timing (a backend or a test that |
| 43 | // does not fill them) must read exactly as the line did before, rather than |
| 44 | // claiming an instant wake. |
| 45 | func TestWakeEventMessageSaysNothingItDoesNotKnow(t *testing.T) { |
| 46 | if got := wakeEventMessage(&wokenInstance{}, false); got != "instance woke" { |
| 47 | t.Errorf("untimed wake = %q, want the bare line", got) |
| 48 | } |
| 49 | if got := wakeEventMessage(&wokenInstance{spawnVersion: "abc1234"}, false); got != "instance woke (version abc1234)" { |
| 50 | t.Errorf("untimed wake with a version = %q", got) |
| 51 | } |
| 52 | if got := wakeEventMessage(nil, false); got != "instance woke" { |
| 53 | t.Errorf("nil wake = %q, want the bare line", got) |
| 54 | } |
| 55 | // A total with no spawn figure still reports the total: half an answer |
| 56 | // beats none, and the alternative is dropping a measurement that was |
| 57 | // actually taken. |
| 58 | if got := wakeEventMessage(&wokenInstance{wakeTook: 900 * time.Millisecond}, false); !strings.Contains(got, "900ms") { |
| 59 | t.Errorf("wake with only a total = %q", got) |
| 60 | } |
| 61 | } |
| 62 | |
| 63 | // Rounded to a millisecond: a log line a person reads and a script greps, |
| 64 | // where microseconds of a several-hundred-millisecond wake are noise in both |
| 65 | // directions. |
| 66 | func TestWakeEventMessageRoundsToMilliseconds(t *testing.T) { |
| 67 | msg := wakeEventMessage(&wokenInstance{ |
| 68 | wakeTook: 812*time.Millisecond + 417*time.Microsecond, |
| 69 | spawnTook: 640*time.Millisecond + 903*time.Microsecond, |
| 70 | }, false) |
| 71 | if !strings.Contains(msg, "812ms") || !strings.Contains(msg, "spawn 641ms") { |
| 72 | t.Errorf("wake message %q is not rounded to milliseconds", msg) |
| 73 | } |
| 74 | } |
| 75 | |
| 76 | // TestWakeEventMessageNamesAWorkerAsStarted pins the one thing the worker |
| 77 | // flag changes, and the reason it exists: nothing dialed a sidecar, so |
| 78 | // "woke" would describe an event that did not happen — no request was |
| 79 | // waiting on the other end of it. The timings mean exactly what they mean |
| 80 | // for an instance and are reported unchanged, which is why the noun is the |
| 81 | // only difference. |
| 82 | func TestWakeEventMessageNamesAWorkerAsStarted(t *testing.T) { |
| 83 | got := wakeEventMessage(&wokenInstance{ |
| 84 | wakeTook: 1400 * time.Millisecond, |
| 85 | spawnVersion: "7507a33", |
| 86 | }, true) |
| 87 | if !strings.Contains(got, "sidecar started") { |
| 88 | t.Fatalf("worker wake message = %q, want it to say the sidecar started", got) |
| 89 | } |
| 90 | if strings.Contains(got, "instance woke") { |
| 91 | t.Fatalf("worker wake message = %q, must not call a sidecar an instance", got) |
| 92 | } |
| 93 | // The figures are not dropped along with the noun. |
| 94 | for _, want := range []string{"1.4s", "7507a33"} { |
| 95 | if !strings.Contains(got, want) { |
| 96 | t.Errorf("worker wake message %q is missing %q", got, want) |
| 97 | } |
| 98 | } |
| 99 | if got := wakeEventMessage(nil, true); got != "sidecar started" { |
| 100 | t.Fatalf("nil yield for a worker = %q, want the bare sidecar line", got) |
| 101 | } |
| 102 | } |
| 103 | |
amadan