From f8683368c527478997e0ec1af42e922f7ebe3746 Mon Sep 17 00:00:00 2001 From: Mike Dalessio Date: Sat, 10 Oct 2026 10:47:08 -0400 Subject: [PATCH] Fix yabeda-hotcell recording 0 seconds for calls with no perform_ms When the cell refused a call with `capacity`, or the client failed a call itself with `unavailable` or `timeout`, the response carried no `perform_ms`. `yabeda-hotcell` recorded those calls as 0-second `perform` observations, which pulled down the histogram's low percentiles. Record `perform` only when the response carries `perform_ms`. ref: https://github.com/basecamp/hotcell/issues/112 --- CHANGELOG.md | 8 ++++++++ docs/observability.md | 2 +- yabeda-hotcell/lib/yabeda/hot_cell.rb | 6 +++++- yabeda-hotcell/test/perform_test.rb | 8 ++++++++ 4 files changed, 22 insertions(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index a5563c3..fa8bca4 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,6 +13,14 @@ This changelog covers these gems, which release together on the same version: A `Tooling` section records changes to the checks and scripts in `bin/` and `examples/`, which ship in no gem but are what an operator runs against their own image. +## next / unreleased + +### Yabeda::HotCell + +#### Fixed + +* `perform` records nothing for a call whose response has no `perform_ms`: a call that the cell refused with `capacity`, or that the client failed itself with `unavailable` or `timeout`. Previously, it recorded 0 seconds, which pulled down the low percentiles. (#112) + ## v1.1.0 / 2026-10-08 ### HotCell::Server diff --git a/docs/observability.md b/docs/observability.md index f037c19..bf35fd1 100644 --- a/docs/observability.md +++ b/docs/observability.md @@ -135,7 +135,7 @@ The metrics are in the `hotcell` group: | Metric | Type | Tags | Description | | --- | --- | --- | --- | | `requests` | counter | `cell`, `operation`, `code`, `cause` | Each call. `code` is `ok` on success, and `cause` is empty when there's none. | -| `perform` | histogram | `cell`, `operation` | Seconds that the cell spent in `perform`. | +| `perform` | histogram | `cell`, `operation` | Seconds that the cell spent in `perform`. A call whose response has no `perform_ms`, such as `capacity`, `unavailable` or `timeout`, records nothing. | | `up` | gauge | `cell` | 1 when the local cell answers its control socket, otherwise 0. | | `running` | gauge | `cell` | Workers busy right now. | | `queued` | gauge | `cell` | Connections waiting for a worker. | diff --git a/yabeda-hotcell/lib/yabeda/hot_cell.rb b/yabeda-hotcell/lib/yabeda/hot_cell.rb index 4a1ae0f..b8cc0fb 100644 --- a/yabeda-hotcell/lib/yabeda/hot_cell.rb +++ b/yabeda-hotcell/lib/yabeda/hot_cell.rb @@ -75,7 +75,11 @@ def self.record_perform(event) # and a query by code would silently split. Yabeda.hotcell.requests.increment(labels.merge(code: event.payload[:code] || "ok", cause: event.payload[:cause].to_s)) - Yabeda.hotcell.perform.measure(labels, (event.payload[:perform_ms] || 0) / 1000.0) + + # The response has no perform_ms when the cell refuses the call with `capacity`, or when the client fails + # the call itself with `unavailable` or `timeout`. Recording 0 would pull down the low percentiles. + perform_ms = event.payload[:perform_ms] + Yabeda.hotcell.perform.measure(labels, perform_ms / 1000.0) if perform_ms end private_class_method def self.set_counters(cell, counters) diff --git a/yabeda-hotcell/test/perform_test.rb b/yabeda-hotcell/test/perform_test.rb index ca37520..edb893e 100644 --- a/yabeda-hotcell/test/perform_test.rb +++ b/yabeda-hotcell/test/perform_test.rb @@ -20,6 +20,14 @@ def test_counts_a_failure_under_its_own_code assert_equal 1, requests(code: "capacity", cause: "") end + def test_records_no_perform_time_when_the_cell_refuses_a_call_with_capacity + answer HotCell::Response.failed(HotCell::Failure.new(code: "capacity", message: "no"), timing: { queued_ms: 0 }) + + assert_raises(TemporarilyUnavailable) { Anything.perform_in_hotcell [], [], {} } + + assert_nil perform_seconds + end + # `killed` is one code and several verdicts: which limit the worker hit decides whether the file did it. # Every other code carries an empty cause, because a label that is sometimes absent is a separate series in # Prometheus, and a query by code would silently split.