feat(telemetry): measure every tick and tick section per phase

docs/telemetry.md

@@ -130,6 +130,79 @@ telemetry.slowTickThresholdMillis=50
 
 A value below 1 is rejected and the service refuses to start.
 
+## Tick metrics
+
+Spans exist only for slow ticks, so a trace cannot say how long a lobby tick usually takes. Metrics are
+recorded for every tick (`ServerTickMonitorEvent`) and every measured section, per phase. The javaagent exports
+them over OTLP together with its own metrics; without the agent they are no-ops.
+
+| Instrument | Kind | Unit | Attributes |
+| --- | --- | --- | --- |
+| `cygnus.tick.duration` | histogram | `ms` | `cygnus.phase.name` |
+| `cygnus.tick.section.duration` | histogram | `ms` | `cygnus.tick.section.name`, `cygnus.phase.name` |
+| `cygnus.tick.slow` | counter | `{tick}` | `cygnus.phase.name` |
+
+- `cygnus.phase.name` is `lobby`, `waiting`, `gamephase`, `restart`, or `none` (no round or between phases).
+- `cygnus.tick.section.name` is one of the names in [Slow ticks](#slow-ticks). A section is recorded for a tick
+  only if it ran in it, with the total of its runs.
+- `cygnus.tick.slow` counts ticks at or above `telemetry.slowTickThresholdMillis`, the same rule as the span.
+- Unit is milliseconds, not the seconds the semantic conventions prefer: Minestom's budget, the threshold and the
+  span attributes are in milliseconds, and a bucket at `50` reads as 50.
+- Explicit buckets (ms): 0.1, 0.25, 0.5, 1, 2.5, 5, 10, 15, 20, 25, 30, 40, 50, 75, 100, 150, 200. The SDK
+  default starts at 5 and would put the whole lobby in one bucket.
+- The hot path allocates nothing of its own: attributes per phase and per section/phase pair are built once and
+  reused, values are recorded as primitives.
+
+### In Mimir / Grafana
+
+OTLP to Prometheus translation appends the unit and, for counters, `_total` (checked against the existing
+`jvm_gc_duration_seconds_*` and `jvm_cpu_time_seconds_total` in Mimir). Dots become underscores:
+
+| OTel | Prometheus |
+| --- | --- |
+| `cygnus.tick.duration` | `cygnus_tick_duration_milliseconds_bucket` / `_sum` / `_count` |
+| `cygnus.tick.section.duration` | `cygnus_tick_section_duration_milliseconds_bucket` / `_sum` / `_count` |
+| `cygnus.tick.slow` | `cygnus_tick_slow_total` |
+| `cygnus.phase.name` | label `cygnus_phase_name` |
+| `cygnus.tick.section.name` | label `cygnus_tick_section_name` |
+
+For the Kubernetes-FLUX dashboard `cygnus-traces`, the per-phase and sub-tick panels should query these metrics
+rather than derive them from slow tick spans, which only cover the tail. For example the p99 tick per phase:
+
+```promql
+histogram_quantile(0.99, sum by (le, cygnus_phase_name) (rate(cygnus_tick_duration_milliseconds_bucket[5m])))
+```
+
+and the mean cost of a section: `sum by (cygnus_tick_section_name) (rate(..._section_duration_milliseconds_sum[5m]))
+/ sum by (cygnus_tick_section_name) (rate(..._section_duration_milliseconds_count[5m]))`.
+
+## Hunts
+
+A hunt is the chase of one creek after one survivor. It gets a span of its own, `cygnus.action.creek.hunt`, and a
+metric, so "how long are survivors hunted, and how does it end" can be answered per map.
+
+| Outcome | Meaning |
+| --- | --- |
+| `caught` | The creek caught the survivor (the catch is reported just before the hunt ends). |
+| `timeout` | The hunt ran out of its maximum time. |
+| `gone` | The survivor died, left or turned before it ended. |
+| `escaped` | The creek was sent away for good while it hunted (only one survivor left). |
+| `round_end` | The creek was removed, or the round ended with the hunt still going. Hunts still open when a round ends are closed as `round_end` before the phase span ends. |
+
+| Instrument | Kind | Unit | Attributes |
+| --- | --- | --- | --- |
+| `cygnus.creek.hunt.duration` | histogram | `ms` | `cygnus.creek.hunt.outcome`, `cygnus.map` |
+| `cygnus.creek.hunts` | counter | `{hunt}` | `cygnus.creek.hunt.outcome`, `cygnus.map` |
+
+Buckets (ms): 500, 1000, 2500, 5000, 7500, 10000, 15000, 20000, 30000, 45000, 60000, 90000, 120000. There is no
+player attribute on the metrics (one series per player); the UUID is on the span. In Prometheus:
+`cygnus_creek_hunt_duration_milliseconds_bucket` and `cygnus_creek_hunts_total`, labels `cygnus_creek_hunt_outcome`
+and `cygnus_map`. A hunt that starts while no round runs has no span but is still counted.
+
+The creek reports a hunt by the survivor only, not by itself. Two creeks hunting the same survivor are two spans,
+and each end closes the oldest open one of that survivor: the count is right, which span belongs to which creek
+may not be.
+
 ## Shutdown
 
 `ServiceShutdown` ends the span before it calls `Runtime.exit`. The agent flushes its exporter from a JVM
@@ -162,6 +235,7 @@ player at that moment as `cygnus.position.x/y/z` (rounded to 0.1), plus `cygnus.
 | `cygnus.action.blackout.player` | child of a blackout, one per player hit; the player attributes only |
 | `cygnus.action.sanity.threshold` | `cygnus.sanity.band.from`, `cygnus.sanity.band`, `cygnus.sanity.fear` (0 calm, 1 maximum), `cygnus.sanity.value` (1 - fear, as `/creek` shows it), `cygnus.sanity.source` (`page`, `sighting`, `caught`, `selected`, `death`, `stalk`) |
 | `cygnus.action.creek.sighted`, `.selected`, `.stalk` (first step of a stalk only), `.caught` | the survivor's attributes only |
+| `cygnus.action.creek.hunt` | A hunt, from the creek taking the survivor as its target until it stops. Child of the phase it started in. The survivor's attributes at the start, `cygnus.map`, `cygnus.creek.hunt.outcome` (`caught`, `timeout`, `gone`, `escaped`, `round_end`) and `cygnus.creek.hunt.duration_ms`. |
 
 `cygnus.page.out_ms` counts from the moment the page was placed or moved on. A page that has to wait on its
 own spot (no other spot is free) is counted from the moment it was hidden.

game/src/main/java/net/onelitefeather/cygnus/Cygnus.java

@@ -106,6 +106,9 @@
 import net.onelitefeather.cygnus.telemetry.RoundTracer;
 import net.onelitefeather.cygnus.telemetry.ShutdownTracer;
 import net.onelitefeather.cygnus.telemetry.SlowTickTracer;
+import net.onelitefeather.cygnus.telemetry.HuntMetrics;
+import net.onelitefeather.cygnus.telemetry.HuntTracer;
+import net.onelitefeather.cygnus.telemetry.TickMetrics;
 import net.onelitefeather.cygnus.telemetry.TickSections;
 import net.onelitefeather.cygnus.telemetry.TraceStep;
 import net.onelitefeather.cygnus.telemetry.TracedPhaseSeries;
@@ -120,7 +123,7 @@
 
 /**
  * @author theEvilReaper
- * @version 1.4.0
+ * @version 1.6.0
  * @since 1.0.0
  **/
 @SuppressWarnings("java:S3252")
@@ -179,7 +182,8 @@ public Cygnus() {
             try (TraceStep ignored = startup.child("cygnus.startup.config")) {
                 this.gameConfig = new GameConfigReader(path).getConfig();
             }
-            this.slowTickTracer = new SlowTickTracer(this.tracing, this.roundTracer, this.gameConfig.telemetry(), Clock.systemUTC(), tickSections);
+            this.slowTickTracer = new SlowTickTracer(this.tracing, this.roundTracer, this.gameConfig.telemetry(), Clock.systemUTC(), tickSections,
+                    TickMetrics.fromGlobal(serviceVersion(), this.roundTracer::phaseLabel));
             this.staminaService = new StaminaService(this.gameConfig.stamina(), tickSections);
             // Set up as early as possible so anything that goes wrong while the rest of the game is
             // being wired up is already covered. Stays off entirely when no DSN is configured.
@@ -233,7 +237,9 @@ public Cygnus() {
                         // either way, and it needs neither the resource pack nor the overlay gate to be heard.
                         new DamageSoundService(this.gameConfig.damageSound(), System::currentTimeMillis),
                         new CreekModule(this.gameConfig.creek(), this.teamService, this.mapProvider,
-                                sanityService, new HuntedTabWitness(new TracingCreekWitness(sanityService, this.actionTracer, Cygnus::survivorActor),
+                                sanityService, new HuntedTabWitness(new TracingCreekWitness(sanityService, this.actionTracer, Cygnus::survivorActor,
+                                        new HuntTracer(this.roundTracer, Clock.systemUTC(), this::activeMapName,
+                                                Cygnus::survivorActor, HuntMetrics.fromGlobal(serviceVersion()))),
                                         MinecraftServer.getConnectionManager()::getOnlinePlayerByUuid), this.jumpscareManager, this.staminaService, tickSections),
                         sanityService,
                         new AdrenalineService(

game/src/main/java/net/onelitefeather/cygnus/creek/Creek.java

@@ -4,6 +4,7 @@
 import net.minestom.server.entity.Entity;
 import net.minestom.server.entity.Player;
 import net.onelitefeather.cygnus.creek.body.CreekBody;
+import net.onelitefeather.cygnus.creek.dread.HuntEnd;
 import net.onelitefeather.cygnus.creek.state.CreekActions;
 import net.onelitefeather.cygnus.creek.state.CreekContext;
 import net.onelitefeather.cygnus.creek.state.CreekState;
@@ -30,7 +31,7 @@
  * </p>
  *
  * @author theEvilReaper
- * @version 1.1.0
+ * @version 1.2.0
  * @since 2.15.0
  */
 final class Creek {
@@ -49,6 +50,7 @@ final class Creek {
     private Set<UUID> seenLastStep = Set.of();
     private boolean entered;
     private @Nullable UUID hunting;
+    private @Nullable HuntState huntState;
 
     /**
      * Sets up a creek.
@@ -93,11 +95,11 @@ void tick(SurvivorSnapshot survivors, Set<UUID> ignored, long now) {
             this.state.enter(ctx);
             this.entered = true;
             // A hunt the creek starts in may be over within this very step.
-            this.syncHunt();
+            this.syncHunt(HuntEnd.TIMEOUT);
         }
         CreekState next = this.state.tick(ctx);
         if (next != this.state) this.switchTo(next, ctx);
-        this.syncHunt();
+        this.syncHunt(HuntEnd.TIMEOUT);
         // Reported after the step, so a stalk that just ended or turned into a hunt is not counted.
         if (this.state instanceof StalkState stalk) this.round.witness().stalked(stalk.target());
     }
@@ -114,19 +116,28 @@ void vanishForGood(SurvivorSnapshot survivors, long now) {
         // The state it had so far is never entered now, and never needs to be.
         this.entered = true;
         this.switchTo(VanishState.forever(), ctx);
-        this.syncHunt();
+        this.syncHunt(HuntEnd.SENT_AWAY);
     }
 
     /**
      * Tells the witness when the survivor this creek hunts changes: a hunt that starts, one that
      * ends, or a switch to another target. Called after every step, so each hunt is reported once.
+     *
+     * @param otherwise how a hunt ended that did not say so itself; the state a hunt leaves behind
+     *                  knows whether it was a catch, a timeout or the survivor being gone
      */
-    private void syncHunt() {
-        UUID now = this.state instanceof HuntState hunt ? hunt.target() : null;
+    private void syncHunt(HuntEnd otherwise) {
+        HuntState hunt = this.state instanceof HuntState current ? current : null;
+        UUID now = hunt == null ? null : hunt.target();
         UUID before = this.hunting;
         if (Objects.equals(now, before)) return;
+        HuntState ended = this.huntState;
         this.hunting = now;
-        if (before != null) this.round.witness().huntEnded(before);
+        this.huntState = hunt;
+        if (before != null) {
+            HuntEnd how = ended != null && ended.end() != null ? ended.end() : otherwise;
+            this.round.witness().huntEnded(before, how);
+        }
         if (now != null) this.round.witness().hunted(now);
     }
 
@@ -219,7 +230,8 @@ RouteProvider route() {
     void remove() {
         UUID before = this.hunting;
         this.hunting = null;
-        if (before != null) this.round.witness().huntEnded(before);
+        this.huntState = null;
+        if (before != null) this.round.witness().huntEnded(before, HuntEnd.REMOVED);
         this.body.remove();
     }
 

game/src/main/java/net/onelitefeather/cygnus/creek/dread/CreekWitness.java

@@ -90,4 +90,17 @@ default void hunted(UUID survivor) {
     default void huntEnded(UUID survivor) {
         // Nobody listens by default.
     }
+
+    /**
+     * A creek stopped hunting a survivor, and how. The creek reports this one; by default it passes
+     * on to {@link #huntEnded(UUID)}, so a witness that does not care about the reason is unchanged.
+     * A witness that decorates another one has to forward this method, not the other.
+     *
+     * @param survivor the survivor who is no longer hunted
+     * @param how      why the hunt ended
+     * @since 2.15.0
+     */
+    default void huntEnded(UUID survivor, HuntEnd how) {
+        this.huntEnded(survivor);
+    }
 }

game/src/main/java/net/onelitefeather/cygnus/creek/dread/HuntEnd.java

@@ -0,0 +1,22 @@
+package net.onelitefeather.cygnus.creek.dread;
+
+/**
+ * How a creek's hunt of a survivor ended, as told to {@link CreekWitness#huntEnded(java.util.UUID, HuntEnd)}.
+ *
+ * @author TheMeinerLP
+ * @version 1.0.0
+ * @since 2.15.0
+ */
+public enum HuntEnd {
+
+    /** The creek got close enough with nothing in between. */
+    CAUGHT,
+    /** The hunt ran out of time. */
+    TIMEOUT,
+    /** The survivor was no longer among the hunted, because they died, left or were turned. */
+    GONE,
+    /** The creek was sent away for good while it hunted. */
+    SENT_AWAY,
+    /** The creek was taken out of the world, which is what the end of a round does. */
+    REMOVED
+}

game/src/main/java/net/onelitefeather/cygnus/creek/state/HuntState.java

@@ -2,6 +2,8 @@
 
 import net.onelitefeather.cygnus.common.config.CreekConfig;
 import net.onelitefeather.cygnus.creek.body.CreekBody;
+import net.onelitefeather.cygnus.creek.dread.HuntEnd;
+import org.jetbrains.annotations.Nullable;
 
 import java.util.List;
 import java.util.Optional;
@@ -17,7 +19,7 @@
  * </p>
  *
  * @author theEvilReaper
- * @version 1.0.0
+ * @version 1.1.0
  * @since 2.15.0
  */
 public final class HuntState implements CreekState {
@@ -35,6 +37,7 @@ public final class HuntState implements CreekState {
     private final long endsAt;
     private double bestDistance = Double.MAX_VALUE;
     private long progressSince;
+    private @Nullable HuntEnd end;
 
     /**
      * Sets up the hunt.
@@ -76,6 +79,16 @@ public long endsAt() {
         return this.endsAt;
     }
 
+    /**
+     * Tells how the hunt ended.
+     *
+     * @return the reason, or {@code null} while the hunt goes on or when it was cut short from outside
+     * @since 2.15.0
+     */
+    public @Nullable HuntEnd end() {
+        return this.end;
+    }
+
     @Override
     public void enter(CreekContext ctx) {
         CreekBody body = ctx.body();
@@ -88,7 +101,8 @@ public void enter(CreekContext ctx) {
     @Override
     public CreekState tick(CreekContext ctx) {
         Optional<SurvivorView> found = ctx.survivor(this.target);
-        if (found.isEmpty() || ctx.now() >= this.endsAt) return this.over(ctx);
+        if (found.isEmpty()) return this.over(ctx, HuntEnd.GONE);
+        if (ctx.now() >= this.endsAt) return this.over(ctx, HuntEnd.TIMEOUT);
 
         SurvivorView view = found.get();
         CreekConfig config = ctx.config();
@@ -105,7 +119,7 @@ public CreekState tick(CreekContext ctx) {
         double distance = body.position().distance(view.position());
         if (distance <= config.catchDistance() && view.inSight()) {
             ctx.actions().caught(this.target);
-            return this.over(ctx);
+            return this.over(ctx, HuntEnd.CAUGHT);
         }
 
         if (distance < this.bestDistance - PROGRESS) {
@@ -124,7 +138,8 @@ public CreekState tick(CreekContext ctx) {
     /**
      * Ends the hunt and starts the survivor's breather.
      */
-    private CreekState over(CreekContext ctx) {
+    private CreekState over(CreekContext ctx, HuntEnd how) {
+        this.end = how;
         ctx.hunts().ended(this.target, ctx.now());
         return DoneState.INSTANCE;
     }

game/src/main/java/net/onelitefeather/cygnus/creek/tab/HuntedTabWitness.java

@@ -4,6 +4,7 @@
 import net.kyori.adventure.text.format.NamedTextColor;
 import net.minestom.server.entity.Player;
 import net.onelitefeather.cygnus.creek.dread.CreekWitness;
+import net.onelitefeather.cygnus.creek.dread.HuntEnd;
 import org.jetbrains.annotations.Nullable;
 
 import java.util.List;
@@ -31,7 +32,7 @@
  * </p>
  *
  * @author TheMeinerLP
- * @version 1.1.0
+ * @version 1.2.0
  * @since 2.15.0
  */
 public final class HuntedTabWitness implements CreekWitness {
@@ -92,9 +93,19 @@ public void hunted(UUID survivor) {
         });
     }
 
+    @Override
+    public void huntEnded(UUID survivor, HuntEnd how) {
+        this.delegate.huntEnded(survivor, how);
+        this.unmark(survivor);
+    }
+
     @Override
     public void huntEnded(UUID survivor) {
         this.delegate.huntEnded(survivor);
+        this.unmark(survivor);
+    }
+
+    private void unmark(UUID survivor) {
         this.marks.computeIfPresent(survivor, (_, mark) -> {
             if (mark.hunts() > 1) return mark.fewer();
             Player player = this.players.apply(survivor);

game/src/main/java/net/onelitefeather/cygnus/telemetry/ActionTracer.java

@@ -49,7 +49,7 @@
  * </p>
  *
  * @author TheMeinerLP
- * @version 1.0.0
+ * @version 1.1.0
  * @since 2.15.0
  */
 public final class ActionTracer {
@@ -439,7 +439,7 @@ private long outMillis(Spawn spawn) {
         return Duration.between(spawn.at, this.clock.instant()).toMillis();
     }
 
-    private static void position(TraceStep step, double x, double y, double z) {
+    static void position(TraceStep step, double x, double y, double z) {
         step.set(CygnusAttributes.POSITION_X, round(x));
         step.set(CygnusAttributes.POSITION_Y, round(y));
         step.set(CygnusAttributes.POSITION_Z, round(z));