Add hotcell_start_time_seconds and deprecate hotcell_uptime_seconds

CHANGELOG.md

@@ -23,6 +23,7 @@ Some actions that application developers should consider taking when upgrading f
 * In your own `perform.hot_cell` subscribers, test for success with `payload[:code] == "ok"` instead of `payload[:code].nil?`, and expect `interrupted`. The event now sets `code` on every call; see [Per-call notification](docs/observability.md#per-call-notification).
 * Where a test instruments `perform.hot_cell` by hand to stand in for a successful call, pass `code: "ok"`. `HotCell::LogSubscriber` and `yabeda-hotcell` now record `code` as the event gives it, so an event without one records no code.
 * Count `code="interrupted"` as a failed call wherever a dashboard or alert computes an error rate from `hotcell_requests`. `yabeda-hotcell` counted these calls as `ok` before.
+* `hotcell_uptime_seconds` is now deprecated. In dashboards and alerts, replace it with `time() - hotcell_start_time_seconds`. `hotcell_start_time_seconds` has a value only for cells running this release.
 
 ### HotCell::Client
 
@@ -39,6 +40,12 @@ Some actions that application developers should consider taking when upgrading f
 
 * On macOS, a call to a full cell reports `capacity` instead of occasionally reporting `unavailable`. A full cell answers and closes the connection without reading the request, so the client's send fails. The client already ignored that failure as `EPIPE` or `ECONNRESET` and read the answer, but macOS sometimes raises `ENOTCONN` instead. (#110)
 
+### HotCell::Server
+
+#### Added
+
+* `metrics` reports `start_time_s`, the time the supervisor booted, in seconds since the Unix epoch. (#112)
+
 ### HotCell::Client::Legacy
 
 #### Breaking
@@ -47,6 +54,14 @@ Some actions that application developers should consider taking when upgrading f
 
 ### Yabeda::HotCell
 
+#### Added
+
+* The `start_time_seconds` gauge records when each cell booted, in seconds since the Unix epoch. (#112)
+
+#### Deprecated
+
+* `uptime_seconds` is now deprecated. Use `time() - hotcell_start_time_seconds` instead. It will be removed in a future version. (#112)
+
 #### Fixed
 
 * A call that an exception interrupted, such as the application's own request timeout, is counted in `requests` under `code="interrupted"` and records no `perform` observation. Previously, it was counted as `code="ok"` with a `perform` of 0 seconds. (#93)

docs/observability.md

@@ -141,7 +141,8 @@ The metrics are in the `hotcell` group:
 | `queue_high_water` | gauge | `cell` | The deepest that the queue has been since boot. |
 | `cancelled` | gauge | `cell` | Callers that gave up before the cell answered. This is a floor. |
 | `killed` | gauge | `cell`, `cause` | Workers killed since boot, by cause. |
-| `uptime_seconds` | gauge | `cell` | Seconds since the supervisor booted. |
+| `start_time_seconds` | gauge | `cell` | When the supervisor booted, in seconds since the Unix epoch. `time() - hotcell_start_time_seconds` is the uptime. |
+| `uptime_seconds` | gauge | `cell` | ⚠️ Deprecated: use `start_time_seconds`. Seconds since the supervisor booted. This field will be removed in a future version. |
 
 On each scrape, the gem reads `metrics` from each registered cell and sets the gauges from it. A scrape
 never fails because a cell misbehaves: the gem reports the error to the Active Support error reporter.

hotcell-server/lib/hot_cell/counters.rb

@@ -18,6 +18,7 @@ module HotCell
   class Counters
     def initialize
       @started_at = Clock.now
+      @start_time = Time.now.to_f
       @requests = Hash.new(0)
       @killed_by = Hash.new(0)
       @cancelled = 0
@@ -42,8 +43,8 @@ def observe_queue(depth)
     end
 
     def to_h(running: 0, queued: 0)
-      { uptime_s: (Clock.now - @started_at).round, running: running, queued: queued,
-        queue_high_water: @queue_high_water, requests: @requests, killed_by: @killed_by,
+      { start_time_s: @start_time, uptime_s: (Clock.now - @started_at).round, running: running,
+        queued: queued, queue_high_water: @queue_high_water, requests: @requests, killed_by: @killed_by,
         cancelled: @cancelled }
     end
   end

hotcell-server/test/control_test.rb

@@ -83,6 +83,18 @@ def test_metrics_count_a_caller_that_gave_up_before_the_cell_answered
     end
   end
 
+  def test_metrics_report_when_the_cell_started
+    before_boot = Time.now.to_f
+
+    TestCell.boot do |cell|
+      started = assert_ok(cell.control("hotcell.metrics")).result[:start_time_s]
+
+      assert_operator started, :>=, before_boot
+      assert_operator started, :<=, Time.now.to_f
+      assert_equal started, assert_ok(cell.control("hotcell.metrics")).result[:start_time_s]
+    end
+  end
+
   def test_metrics_report_what_no_single_caller_can_see
     TestCell.boot(concurrency: 1, queue_size: 4, deadline: 30) do |cell|
       blocker = cell.connect

yabeda-hotcell/lib/yabeda/hot_cell.rb

@@ -33,7 +33,9 @@ def self.install!
           tags: %i[ cell ], aggregation: :most_recent
         gauge :killed, comment: "Workers killed since boot, by cause",
           tags: %i[ cell cause ], aggregation: :most_recent
-        gauge :uptime_seconds, comment: "Seconds since the supervisor booted",
+        gauge :uptime_seconds, comment: "Seconds since the supervisor booted. Deprecated: use start_time_seconds",
+          tags: %i[ cell ], aggregation: :most_recent
+        gauge :start_time_seconds, comment: "When the supervisor booted, in seconds since the Unix epoch",
           tags: %i[ cell ], aggregation: :most_recent
 
         collect { Yabeda::HotCell.collect_stats }
@@ -91,6 +93,7 @@ def self.record_perform(event)
       Yabeda.hotcell.queue_high_water.set(tags, counters[:queue_high_water])
       Yabeda.hotcell.cancelled.set(tags, counters[:cancelled])
       Yabeda.hotcell.uptime_seconds.set(tags, counters[:uptime_s])
+      Yabeda.hotcell.start_time_seconds.set(tags, counters[:start_time_s]) if counters[:start_time_s]
       ::HotCell::Codes::PERMANENT_BY_CAUSE.each_key do |cause|
         Yabeda.hotcell.killed.set(tags.merge(cause: cause), counters[:killed_by].fetch(cause.to_sym, 0))
       end

yabeda-hotcell/test/collect_test.rb

@@ -19,6 +19,28 @@ def test_publishes_a_running_cells_counters
     assert_equal 0, gauge(:queue_high_water)
     assert_equal 0, gauge(:cancelled)
     assert_kind_of Integer, gauge(:uptime_seconds)
+    assert_kind_of Float, gauge(:start_time_seconds)
+  end
+
+  def test_publishes_when_the_cell_started
+    HotCell.root = "/nowhere"
+    register transport: CannedTransport.new(metrics(start_time_s: 1_760_000_000.25))
+
+    Yabeda.collect!
+
+    assert_equal 1_760_000_000.25, gauge(:start_time_seconds)
+  end
+
+  def test_a_cell_that_does_not_report_its_start_time_publishes_none
+    HotCell.root = "/nowhere"
+    register transport: CannedTransport.new(metrics)
+
+    Yabeda.collect!
+
+    refute_includes Yabeda::TestAdapter.instance.gauges[Yabeda.hotcell.start_time_seconds], { cell: "test" }
+    assert_equal 41, gauge(:uptime_seconds)
+    assert_equal 0, gauge(:killed, cause: "memory")
+    assert_empty @reported
   end
 
   def test_publishes_kills_by_cause