diff --git a/docs/telemetry.md b/docs/telemetry.md index 47de72cd..f4e575ce 100644 --- a/docs/telemetry.md +++ b/docs/telemetry.md @@ -176,6 +176,33 @@ histogram_quantile(0.99, sum by (le, cygnus_phase_name) (rate(cygnus_tick_durati 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 @@ -208,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. diff --git a/game/src/main/java/net/onelitefeather/cygnus/Cygnus.java b/game/src/main/java/net/onelitefeather/cygnus/Cygnus.java index 7ce36efc..896794e1 100644 --- a/game/src/main/java/net/onelitefeather/cygnus/Cygnus.java +++ b/game/src/main/java/net/onelitefeather/cygnus/Cygnus.java @@ -106,6 +106,8 @@ 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; @@ -121,7 +123,7 @@ /** * @author theEvilReaper - * @version 1.5.0 + * @version 1.6.0 * @since 1.0.0 **/ @SuppressWarnings("java:S3252") @@ -235,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( diff --git a/game/src/main/java/net/onelitefeather/cygnus/creek/Creek.java b/game/src/main/java/net/onelitefeather/cygnus/creek/Creek.java index 035ec00b..37a2d484 100644 --- a/game/src/main/java/net/onelitefeather/cygnus/creek/Creek.java +++ b/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 @@ *

* * @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 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 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(); } diff --git a/game/src/main/java/net/onelitefeather/cygnus/creek/dread/CreekWitness.java b/game/src/main/java/net/onelitefeather/cygnus/creek/dread/CreekWitness.java index 2339bc5a..81b81c1b 100644 --- a/game/src/main/java/net/onelitefeather/cygnus/creek/dread/CreekWitness.java +++ b/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); + } } diff --git a/game/src/main/java/net/onelitefeather/cygnus/creek/dread/HuntEnd.java b/game/src/main/java/net/onelitefeather/cygnus/creek/dread/HuntEnd.java new file mode 100644 index 00000000..48865222 --- /dev/null +++ b/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 +} diff --git a/game/src/main/java/net/onelitefeather/cygnus/creek/state/HuntState.java b/game/src/main/java/net/onelitefeather/cygnus/creek/state/HuntState.java index 4ce2b953..64faa21a 100644 --- a/game/src/main/java/net/onelitefeather/cygnus/creek/state/HuntState.java +++ b/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 @@ *

* * @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 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; } diff --git a/game/src/main/java/net/onelitefeather/cygnus/creek/tab/HuntedTabWitness.java b/game/src/main/java/net/onelitefeather/cygnus/creek/tab/HuntedTabWitness.java index 6b7d67b1..a86e72b6 100644 --- a/game/src/main/java/net/onelitefeather/cygnus/creek/tab/HuntedTabWitness.java +++ b/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 @@ *

* * @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); diff --git a/game/src/main/java/net/onelitefeather/cygnus/telemetry/ActionTracer.java b/game/src/main/java/net/onelitefeather/cygnus/telemetry/ActionTracer.java index 5c0f9d00..66e0d6cd 100644 --- a/game/src/main/java/net/onelitefeather/cygnus/telemetry/ActionTracer.java +++ b/game/src/main/java/net/onelitefeather/cygnus/telemetry/ActionTracer.java @@ -49,7 +49,7 @@ *

* * @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)); diff --git a/game/src/main/java/net/onelitefeather/cygnus/telemetry/CygnusAttributes.java b/game/src/main/java/net/onelitefeather/cygnus/telemetry/CygnusAttributes.java index d1225bc1..910da2b0 100644 --- a/game/src/main/java/net/onelitefeather/cygnus/telemetry/CygnusAttributes.java +++ b/game/src/main/java/net/onelitefeather/cygnus/telemetry/CygnusAttributes.java @@ -11,7 +11,7 @@ *

* * @author TheMeinerLP - * @version 1.0.0 + * @version 1.1.0 * @since 2.15.0 */ public final class CygnusAttributes { @@ -58,6 +58,8 @@ public final class CygnusAttributes { public static final String ACTION_CREEK_SELECTED = "cygnus.action.creek.selected"; public static final String ACTION_CREEK_STALK = "cygnus.action.creek.stalk"; public static final String ACTION_CREEK_CAUGHT = "cygnus.action.creek.caught"; + /** A creek hunting a survivor, from the start of the hunt to its end. */ + public static final String ACTION_CREEK_HUNT = "cygnus.action.creek.hunt"; // --- Events on the round span -------------------------------------------------------------- @@ -115,6 +117,8 @@ public final class CygnusAttributes { public static final AttributeKey SANITY_BAND = AttributeKey.stringKey("cygnus.sanity.band"); public static final AttributeKey SANITY_BAND_FROM = AttributeKey.stringKey("cygnus.sanity.band.from"); public static final AttributeKey SANITY_SOURCE = AttributeKey.stringKey("cygnus.sanity.source"); + public static final AttributeKey HUNT_OUTCOME = AttributeKey.stringKey("cygnus.creek.hunt.outcome"); + public static final AttributeKey HUNT_DURATION_MS = AttributeKey.longKey("cygnus.creek.hunt.duration_ms"); public static final AttributeKey LINK_KIND = AttributeKey.stringKey("cygnus.link.kind"); /** The link points at the round trace a player's cookie remembered. */ @@ -126,6 +130,19 @@ public final class CygnusAttributes { /** Link kind: from the shutdown to the round it cut short. */ public static final String LINK_ROUND = "round"; + // --- Values of creek.hunt.outcome ---------------------------------------------------------- + + /** The creek caught the survivor. */ + public static final String HUNT_CAUGHT = "caught"; + /** The creek was sent away while it hunted. */ + public static final String HUNT_ESCAPED = "escaped"; + /** The hunt ran out of time. */ + public static final String HUNT_TIMEOUT = "timeout"; + /** The survivor died or left. */ + public static final String HUNT_GONE = "gone"; + /** The round ended with the hunt still going. */ + public static final String HUNT_ROUND_END = "round_end"; + // --- Values of kick.completed_by ----------------------------------------------------------- /** The client confirmed it dropped the pack. */ diff --git a/game/src/main/java/net/onelitefeather/cygnus/telemetry/HuntMetrics.java b/game/src/main/java/net/onelitefeather/cygnus/telemetry/HuntMetrics.java new file mode 100644 index 00000000..eb2cd505 --- /dev/null +++ b/game/src/main/java/net/onelitefeather/cygnus/telemetry/HuntMetrics.java @@ -0,0 +1,125 @@ +package net.onelitefeather.cygnus.telemetry; + +import io.opentelemetry.api.GlobalOpenTelemetry; +import io.opentelemetry.api.common.Attributes; +import io.opentelemetry.api.metrics.DoubleHistogram; +import io.opentelemetry.api.metrics.LongCounter; +import io.opentelemetry.api.metrics.Meter; +import org.jetbrains.annotations.Nullable; + +import java.util.List; +import java.util.Map; +import java.util.concurrent.ConcurrentHashMap; + +/** + * The metrics of the creek's hunts: how many there were and how long they lasted, by how they ended. + *

+ * The attributes are the outcome and the map only. A player is deliberately not one: the UUID is the + * span's job, on a metric it would make a series per player. The unit is milliseconds, like the tick + * metrics in {@link TickMetrics}. + *

+ * + * + * + * + * + * + * + *
The instruments
NameKindUnitAttributes
{@value #HUNT_DURATION}histogramms{@code cygnus.creek.hunt.outcome}, {@code cygnus.map}
{@value #HUNTS}counter{hunt}{@code cygnus.creek.hunt.outcome}, {@code cygnus.map}
+ * + * @author TheMeinerLP + * @version 1.0.0 + * @since 2.15.0 + */ +public final class HuntMetrics { + + /** Histogram of how long a hunt lasted. */ + public static final String HUNT_DURATION = "cygnus.creek.hunt.duration"; + /** Counter of the hunts that ended. */ + public static final String HUNTS = "cygnus.creek.hunts"; + + /** The value of the map attribute while no map is loaded. */ + public static final String NO_MAP = "none"; + + /** Boundaries in milliseconds: a hunt lasts from a few seconds up to its configured maximum. */ + public static final List BUCKETS_MS = List.of( + 500.0D, 1_000.0D, 2_500.0D, 5_000.0D, 7_500.0D, 10_000.0D, 15_000.0D, 20_000.0D, 30_000.0D, 45_000.0D, + 60_000.0D, 90_000.0D, 120_000.0D); + + /** Metrics that record nothing. */ + public static final HuntMetrics NONE = new HuntMetrics(null); + + private final @Nullable DoubleHistogram duration; + private final @Nullable LongCounter hunts; + private final Map> attributes = new ConcurrentHashMap<>(); + + private HuntMetrics(@Nullable Meter meter) { + if (meter == null) { + this.duration = null; + this.hunts = null; + return; + } + this.duration = meter.histogramBuilder(HUNT_DURATION) + .setDescription("How long a creek hunted a survivor, by how the hunt ended") + .setUnit("ms") + .setExplicitBucketBoundariesAdvice(BUCKETS_MS) + .build(); + this.hunts = meter.counterBuilder(HUNTS) + .setDescription("Hunts that ended, by how they ended") + .setUnit("{hunt}") + .build(); + } + + /** + * Builds the metrics from the global OpenTelemetry instance. Called once, by the composition root. + * + * @param version the version of the running service, reported with the instrumentation scope + * @return the metrics + */ + public static HuntMetrics fromGlobal(String version) { + return of(GlobalOpenTelemetry.get().getMeterProvider() + .meterBuilder(CygnusAttributes.INSTRUMENTATION_NAME) + .setInstrumentationVersion(version) + .build()); + } + + /** + * Wraps a meter, for tests and for callers that already hold one. + * + * @param meter the meter the instruments are created on + * @return the metrics + */ + public static HuntMetrics of(Meter meter) { + return new HuntMetrics(meter); + } + + /** + * Records a hunt that ended. + * + * @param outcome how it ended, one of the {@code HUNT_*} values of {@link CygnusAttributes} + * @param map the map being played, or {@code null} when none is loaded + * @param millis how long it lasted + */ + void record(String outcome, @Nullable String map, long millis) { + if (this.duration == null || this.hunts == null) { + return; + } + Attributes cached = attributes(outcome, map == null ? NO_MAP : map); + this.duration.record(millis, cached); + this.hunts.add(1L, cached); + } + + /** + * Returns the attributes of an outcome on a map. The same instance for the same pair, every time. + */ + Attributes attributes(String outcome, String map) { + Map byMap = this.attributes.computeIfAbsent(outcome, _ -> new ConcurrentHashMap<>()); + Attributes cached = byMap.get(map); + if (cached != null) { + return cached; + } + return byMap.computeIfAbsent(map, name -> Attributes.of( + CygnusAttributes.HUNT_OUTCOME, outcome, + CygnusAttributes.MAP, name)); + } +} diff --git a/game/src/main/java/net/onelitefeather/cygnus/telemetry/HuntTracer.java b/game/src/main/java/net/onelitefeather/cygnus/telemetry/HuntTracer.java new file mode 100644 index 00000000..5b66689c --- /dev/null +++ b/game/src/main/java/net/onelitefeather/cygnus/telemetry/HuntTracer.java @@ -0,0 +1,158 @@ +package net.onelitefeather.cygnus.telemetry; + +import net.onelitefeather.cygnus.creek.dread.HuntEnd; +import org.jetbrains.annotations.Nullable; + +import java.time.Clock; +import java.util.ArrayDeque; +import java.util.ArrayList; +import java.util.HashMap; +import java.util.List; +import java.util.Map; +import java.util.UUID; +import java.util.function.Function; +import java.util.function.Supplier; + +/** + * Measures how long a survivor is hunted: one span per hunt from its start to its end, and the + * duration as a metric. + *

+ * The creek reports a hunt by the survivor only, not by itself, so two creeks hunting the same + * survivor cannot be told apart here. Each start opens its own span and each end closes the + * oldest open one of that survivor - the count stays right, which creek a span belongs to + * may not. + *

+ *

+ * The outcome comes from {@link HuntEnd}: a catch is {@code caught}, a hunt out of time + * {@code timeout}, a survivor who left or died {@code gone}, a creek sent away {@code escaped}, and + * the end of the round {@code round_end}. Hunts still open when the round ends are closed as + * {@code round_end} before the round span ends. A start while no round runs has no span but is still + * counted, so the metric does not depend on tracing being on. + *

+ * + * @author TheMeinerLP + * @version 1.0.0 + * @since 2.15.0 + */ +public final class HuntTracer { + + private final RoundTracer rounds; + private final Clock clock; + private final Supplier<@Nullable String> mapName; + private final Function survivors; + private final HuntMetrics metrics; + private final Map> open = new HashMap<>(); + + /** + * Creates the tracer. + * + * @param rounds owns the round the spans are children of + * @param clock dates the start and the end of a hunt + * @param mapName supplies the name of the map being played, or {@code null} while none is loaded + * @param survivors resolves a survivor's UUID to who and where they are, or {@code null} if gone + * @param metrics where the duration of a hunt goes + */ + public HuntTracer(RoundTracer rounds, Clock clock, Supplier<@Nullable String> mapName, + Function survivors, HuntMetrics metrics) { + this.rounds = rounds; + this.clock = clock; + this.mapName = mapName; + this.survivors = survivors; + this.metrics = metrics; + rounds.onRoundEnding(this::endAll); + } + + /** + * A creek started to hunt a survivor. + * + * @param survivor the survivor + */ + public synchronized void started(UUID survivor) { + long now = this.clock.millis(); + String map = this.mapName.get(); + TraceStep step = null; + try { + step = this.rounds.actionSpan(CygnusAttributes.ACTION_CREEK_HUNT); + if (step != null) { + ActionTracer.Actor actor = this.survivors.apply(survivor); + step.set(CygnusAttributes.PLAYER_UUID, survivor.toString()); + if (actor != null) { + step.set(CygnusAttributes.PLAYER_ROLE, actor.role()); + ActionTracer.position(step, actor.x(), actor.y(), actor.z()); + } + if (map != null) { + step.set(CygnusAttributes.MAP, map); + } + } + } catch (RuntimeException exception) { + // observing must not change what happens; the hunt is still counted + if (step != null) { + step.fail(exception); + } + } + this.open.computeIfAbsent(survivor, _ -> new ArrayDeque<>()).addLast(new Hunt(step, now, map)); + } + + /** + * A creek stopped hunting a survivor. + * + * @param survivor the survivor + * @param how how the hunt ended + */ + public synchronized void ended(UUID survivor, HuntEnd how) { + ArrayDeque hunts = this.open.get(survivor); + if (hunts == null) { + return; + } + Hunt hunt = hunts.pollFirst(); + if (hunts.isEmpty()) { + this.open.remove(survivor); + } + if (hunt != null) { + finish(hunt, outcome(how)); + } + } + + /** + * Closes every hunt still open, because the round is ending. + */ + private synchronized void endAll() { + List hunts = new ArrayList<>(); + this.open.values().forEach(hunts::addAll); + this.open.clear(); + hunts.forEach(hunt -> finish(hunt, CygnusAttributes.HUNT_ROUND_END)); + } + + private void finish(Hunt hunt, String outcome) { + long millis = Math.max(0L, this.clock.millis() - hunt.startedAt); + TraceStep step = hunt.step; + try { + if (step != null) { + step.set(CygnusAttributes.HUNT_OUTCOME, outcome); + step.set(CygnusAttributes.HUNT_DURATION_MS, millis); + } + this.metrics.record(outcome, hunt.map, millis); + } catch (RuntimeException exception) { + if (step != null) { + step.fail(exception); + } + } finally { + if (step != null) { + step.close(); + } + } + } + + static String outcome(HuntEnd how) { + return switch (how) { + case CAUGHT -> CygnusAttributes.HUNT_CAUGHT; + case TIMEOUT -> CygnusAttributes.HUNT_TIMEOUT; + case GONE -> CygnusAttributes.HUNT_GONE; + case SENT_AWAY -> CygnusAttributes.HUNT_ESCAPED; + case REMOVED -> CygnusAttributes.HUNT_ROUND_END; + }; + } + + private record Hunt(@Nullable TraceStep step, long startedAt, @Nullable String map) { + } +} diff --git a/game/src/main/java/net/onelitefeather/cygnus/telemetry/RoundTracer.java b/game/src/main/java/net/onelitefeather/cygnus/telemetry/RoundTracer.java index 7cdab0c1..427c6fc4 100644 --- a/game/src/main/java/net/onelitefeather/cygnus/telemetry/RoundTracer.java +++ b/game/src/main/java/net/onelitefeather/cygnus/telemetry/RoundTracer.java @@ -36,7 +36,7 @@ *

* * @author TheMeinerLP - * @version 1.1.0 + * @version 1.2.0 * @since 2.15.0 */ public final class RoundTracer { @@ -64,6 +64,7 @@ public final class RoundTracer { private final Set linked = new HashSet<>(); private int droppedLinks; private final List boundaryListeners = new CopyOnWriteArrayList<>(); + private final List endingListeners = new CopyOnWriteArrayList<>(); /** * Creates the tracer. @@ -190,6 +191,12 @@ synchronized void phaseFailed(Throwable throwable) { * Ends the round span after its last phase. */ synchronized void roundEnded() { + // Before the spans close, so whatever is still open ends below a parent that is still running. + if (this.round != null) { + for (Runnable listener : this.endingListeners) { + listener.run(); + } + } endPhase(); TraceStep current = this.round; this.round = null; @@ -212,6 +219,15 @@ void onBoundary(Runnable listener) { this.boundaryListeners.add(listener); } + /** + * Registers something that has to finish what it holds open before the round and its phase end. + * + * @param listener called when a running round ends, before its spans close; must be quick + */ + void onRoundEnding(Runnable listener) { + this.endingListeners.add(listener); + } + private void notifyBoundary() { for (Runnable listener : this.boundaryListeners) { listener.run(); diff --git a/game/src/main/java/net/onelitefeather/cygnus/telemetry/TracingCreekWitness.java b/game/src/main/java/net/onelitefeather/cygnus/telemetry/TracingCreekWitness.java index 8f5e6778..3287169d 100644 --- a/game/src/main/java/net/onelitefeather/cygnus/telemetry/TracingCreekWitness.java +++ b/game/src/main/java/net/onelitefeather/cygnus/telemetry/TracingCreekWitness.java @@ -1,6 +1,7 @@ package net.onelitefeather.cygnus.telemetry; import net.onelitefeather.cygnus.creek.dread.CreekWitness; +import net.onelitefeather.cygnus.creek.dread.HuntEnd; import org.jetbrains.annotations.Nullable; import java.util.Set; @@ -21,7 +22,7 @@ *

* * @author TheMeinerLP - * @version 1.1.0 + * @version 1.2.0 * @since 2.15.0 */ public final class TracingCreekWitness implements CreekWitness { @@ -30,6 +31,7 @@ public final class TracingCreekWitness implements CreekWitness { private final ActionTracer actions; private final Function survivors; private final Set stalking = ConcurrentHashMap.newKeySet(); + private final @Nullable HuntTracer hunts; /** * Creates the decorator. @@ -41,6 +43,21 @@ public final class TracingCreekWitness implements CreekWitness { */ public TracingCreekWitness(CreekWitness delegate, ActionTracer actions, Function survivors) { + this(delegate, actions, survivors, null); + } + + /** + * Creates the decorator so that hunts are measured too. + * + * @param delegate the witness that still has to hear everything + * @param actions records the actions + * @param survivors resolves a survivor's UUID to who and where they are, or {@code null} if gone + * @param hunts measures the hunts, or {@code null} to leave them alone + * @since 2.15.0 + */ + public TracingCreekWitness(CreekWitness delegate, ActionTracer actions, + Function survivors, @Nullable HuntTracer hunts) { + this.hunts = hunts; this.delegate = delegate; this.actions = actions; this.survivors = survivors; @@ -78,6 +95,9 @@ public void selected(UUID survivor) { @Override public void hunted(UUID survivor) { + if (this.hunts != null) { + this.hunts.started(survivor); + } this.delegate.hunted(survivor); } @@ -86,6 +106,14 @@ public void huntEnded(UUID survivor) { this.delegate.huntEnded(survivor); } + @Override + public void huntEnded(UUID survivor, HuntEnd how) { + if (this.hunts != null) { + this.hunts.ended(survivor, how); + } + this.delegate.huntEnded(survivor, how); + } + /** * A tracing failure must never reach the creek, which is the part of the game that is being * observed. diff --git a/game/src/test/java/net/onelitefeather/cygnus/creek/CreekIntegrationTest.java b/game/src/test/java/net/onelitefeather/cygnus/creek/CreekIntegrationTest.java index 66bc9427..79419181 100644 --- a/game/src/test/java/net/onelitefeather/cygnus/creek/CreekIntegrationTest.java +++ b/game/src/test/java/net/onelitefeather/cygnus/creek/CreekIntegrationTest.java @@ -12,6 +12,7 @@ import net.onelitefeather.cygnus.creek.consequence.PatrolHelper; import net.onelitefeather.cygnus.creek.consequence.StalkSounds; import net.onelitefeather.cygnus.creek.dread.CreekWitness; +import net.onelitefeather.cygnus.creek.dread.HuntEnd; import net.onelitefeather.cygnus.creek.state.Contexts; import net.onelitefeather.cygnus.creek.state.DoneState; import net.onelitefeather.cygnus.creek.state.CreekContext; @@ -66,6 +67,13 @@ private static final class RecordingWitness implements CreekWitness { private final List selections = new ArrayList<>(); private final List hunts = new ArrayList<>(); private final List huntEnds = new ArrayList<>(); + private final List huntReasons = new ArrayList<>(); + + @Override + public void huntEnded(UUID survivor, HuntEnd how) { + this.huntReasons.add(how); + this.huntEnded(survivor); + } @Override public void hunted(UUID survivor) { @@ -381,6 +389,7 @@ void catchEndsTheHunt(Env env) { assertEquals(List.of(survivor.getUuid()), witness.hunts); assertEquals(List.of(survivor.getUuid()), witness.huntEnds); + assertEquals(List.of(HuntEnd.CAUGHT), witness.huntReasons); } @Test @@ -396,6 +405,7 @@ void timeoutEndsTheHunt(Env env) { creek.tick(survivors(survivor), 600L); assertEquals(List.of(survivor.getUuid()), witness.huntEnds); + assertEquals(List.of(HuntEnd.TIMEOUT), witness.huntReasons); } @Test @@ -412,6 +422,7 @@ void goneSurvivorEndsTheHunt(Env env) { creek.tick(survivors(other), 100L); assertEquals(List.of(target.getUuid()), witness.huntEnds); + assertEquals(List.of(HuntEnd.GONE), witness.huntReasons); } @Test @@ -428,6 +439,7 @@ void removingEndsTheHunt(Env env) { creek.remove(); assertEquals(List.of(survivor.getUuid()), witness.huntEnds); + assertEquals(List.of(HuntEnd.REMOVED), witness.huntReasons); } @Test @@ -443,6 +455,7 @@ void vanishingEndsTheHunt(Env env) { creek.vanishForGood(survivors(survivor), 100L); assertEquals(List.of(survivor.getUuid()), witness.huntEnds); + assertEquals(List.of(HuntEnd.SENT_AWAY), witness.huntReasons); } @Test diff --git a/game/src/test/java/net/onelitefeather/cygnus/creek/state/HuntStateEndTest.java b/game/src/test/java/net/onelitefeather/cygnus/creek/state/HuntStateEndTest.java new file mode 100644 index 00000000..017dc3c8 --- /dev/null +++ b/game/src/test/java/net/onelitefeather/cygnus/creek/state/HuntStateEndTest.java @@ -0,0 +1,70 @@ +package net.onelitefeather.cygnus.creek.state; + +import net.minestom.server.coordinate.Pos; +import net.onelitefeather.cygnus.creek.dread.HuntEnd; +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Test; + +import java.util.ArrayList; +import java.util.UUID; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertNull; + +/** + * Covers how a hunt says why it ended, which is what the hunt outcome is made from. + * + * @author TheMeinerLP + * @version 1.0.0 + * @since 2.15.0 + */ +class HuntStateEndTest { + + private static final UUID TARGET = UUID.randomUUID(); + private static final Pos TARGET_POS = new Pos(0, 40, 0, 180, 0); + + private static CreekContext at(long now, RecordingBody body, UUID who) { + return Contexts.context(now, body, Contexts.route(), new ArrayList<>(), + new SurvivorView(who, TARGET_POS, 0.7D, false)); + } + + @Test + @DisplayName("A running hunt has no end yet") + void runningHuntHasNoEnd() { + HuntState hunt = new HuntState(TARGET, 30_000L); + + hunt.tick(at(0L, new RecordingBody(new Pos(0, 40, 10)), TARGET)); + + assertNull(hunt.end()); + } + + @Test + @DisplayName("A catch ends the hunt as caught") + void catchIsCaught() { + HuntState hunt = new HuntState(TARGET, 30_000L); + + hunt.tick(at(0L, new RecordingBody(new Pos(0, 40, 1)), TARGET)); + + assertEquals(HuntEnd.CAUGHT, hunt.end()); + } + + @Test + @DisplayName("Running out of time ends the hunt as a timeout") + void timeIsUp() { + HuntState hunt = new HuntState(TARGET, 30_000L); + + hunt.tick(at(30_000L, new RecordingBody(new Pos(0, 40, 10)), TARGET)); + + assertEquals(HuntEnd.TIMEOUT, hunt.end()); + } + + @Test + @DisplayName("A target that is no longer among the survivors ends the hunt as gone") + void targetIsGone() { + HuntState hunt = new HuntState(TARGET, 30_000L); + + hunt.tick(at(0L, new RecordingBody(new Pos(0, 40, 10)), UUID.randomUUID())); + + assertEquals(HuntEnd.GONE, hunt.end()); + } +} diff --git a/game/src/test/java/net/onelitefeather/cygnus/telemetry/HuntTracerTest.java b/game/src/test/java/net/onelitefeather/cygnus/telemetry/HuntTracerTest.java new file mode 100644 index 00000000..356e5856 --- /dev/null +++ b/game/src/test/java/net/onelitefeather/cygnus/telemetry/HuntTracerTest.java @@ -0,0 +1,237 @@ +package net.onelitefeather.cygnus.telemetry; + +import io.opentelemetry.api.common.Attributes; +import io.opentelemetry.sdk.metrics.SdkMeterProvider; +import io.opentelemetry.sdk.metrics.data.HistogramPointData; +import io.opentelemetry.sdk.metrics.data.MetricData; +import io.opentelemetry.sdk.testing.exporter.InMemoryMetricReader; +import io.opentelemetry.sdk.trace.data.SpanData; +import net.onelitefeather.cygnus.creek.dread.HuntEnd; +import net.onelitefeather.cygnus.telemetry.ActionTracer.Actor; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.params.ParameterizedTest; +import org.junit.jupiter.params.provider.CsvSource; + +import java.time.Clock; +import java.time.Instant; +import java.time.ZoneId; +import java.time.ZoneOffset; +import java.util.List; +import java.util.UUID; +import java.util.concurrent.atomic.AtomicReference; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertSame; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** + * Covers the hunt span and the hunt metrics. Time is a clock the test moves by hand, the SDK is a + * private in-memory one, nothing waits. + * + * @author TheMeinerLP + * @version 1.0.0 + * @since 2.15.0 + */ +class HuntTracerTest { + + private static final UUID SURVIVOR = UUID.fromString("00000000-0000-0000-0000-0000000000a1"); + + private TestTelemetry telemetry; + private InMemoryMetricReader reader; + private SdkMeterProvider meters; + private RoundTracer rounds; + private HuntMetrics metrics; + private HuntTracer hunts; + private AtomicReference now; + + @BeforeEach + void setUp() { + this.telemetry = new TestTelemetry(); + this.reader = InMemoryMetricReader.create(); + this.meters = SdkMeterProvider.builder().registerMetricReader(this.reader).build(); + this.metrics = HuntMetrics.of(this.meters.get("test")); + this.rounds = new RoundTracer(this.telemetry.tracing(), () -> "round-1"); + this.now = new AtomicReference<>(Instant.parse("2026-01-01T00:00:00Z")); + Clock clock = new Clock() { + @Override + public ZoneId getZone() { + return ZoneOffset.UTC; + } + + @Override + public Clock withZone(ZoneId zone) { + return this; + } + + @Override + public Instant instant() { + return now.get(); + } + }; + this.hunts = new HuntTracer(this.rounds, clock, () -> "Cabin", + id -> new Actor(id, "survivor", 1.04D, 40.0D, -3.0D), this.metrics); + } + + @AfterEach + void tearDown() { + this.meters.close(); + this.telemetry.close(); + } + + private void pass(long seconds) { + this.now.updateAndGet(instant -> instant.plusSeconds(seconds)); + } + + private List huntSpans() { + return this.telemetry.spans().stream() + .filter(span -> span.getName().equals(CygnusAttributes.ACTION_CREEK_HUNT)).toList(); + } + + private MetricData metric(String name) { + return this.reader.collectAllMetrics().stream().filter(data -> data.getName().equals(name)) + .findFirst().orElseThrow(() -> new AssertionError("no metric '" + name + "'")); + } + + @ParameterizedTest(name = "{0} ends the hunt as {1}") + @CsvSource({"CAUGHT,caught", "TIMEOUT,timeout", "GONE,gone", "SENT_AWAY,escaped", "REMOVED,round_end"}) + @DisplayName("Every way a hunt can end has its outcome") + void outcomePerEndPath(HuntEnd how, String outcome) { + this.rounds.roundStarted(); + this.hunts.started(SURVIVOR); + pass(12); + + this.hunts.ended(SURVIVOR, how); + + SpanData span = huntSpans().getFirst(); + assertEquals(outcome, span.getAttributes().get(CygnusAttributes.HUNT_OUTCOME)); + assertEquals(12_000L, span.getAttributes().get(CygnusAttributes.HUNT_DURATION_MS)); + } + + @Test + @DisplayName("A hunt span says who, where and on which map, and hangs below the phase") + void spanAttributes() { + this.rounds.roundStarted(); + this.rounds.phaseStarted("GamePhase"); + this.hunts.started(SURVIVOR); + + this.hunts.ended(SURVIVOR, HuntEnd.CAUGHT); + this.rounds.roundEnded(); + + SpanData span = huntSpans().getFirst(); + assertEquals(SURVIVOR.toString(), span.getAttributes().get(CygnusAttributes.PLAYER_UUID)); + assertEquals("survivor", span.getAttributes().get(CygnusAttributes.PLAYER_ROLE)); + assertEquals(1.0D, span.getAttributes().get(CygnusAttributes.POSITION_X)); + assertEquals(40.0D, span.getAttributes().get(CygnusAttributes.POSITION_Y)); + assertEquals("Cabin", span.getAttributes().get(CygnusAttributes.MAP)); + assertEquals(this.telemetry.span("cygnus.phase.gamephase").getSpanId(), span.getParentSpanId()); + } + + @Test + @DisplayName("The hunt duration is recorded with the outcome and the map") + void histogramHasOutcomeAndMap() { + this.rounds.roundStarted(); + this.hunts.started(SURVIVOR); + pass(8); + this.hunts.ended(SURVIVOR, HuntEnd.TIMEOUT); + + MetricData data = metric(HuntMetrics.HUNT_DURATION); + assertEquals("ms", data.getUnit()); + HistogramPointData point = data.getHistogramData().getPoints().iterator().next(); + assertEquals(1, point.getCount()); + assertEquals(8_000.0D, point.getSum(), 1e-9); + assertEquals(Attributes.of(CygnusAttributes.HUNT_OUTCOME, "timeout", CygnusAttributes.MAP, "Cabin"), + point.getAttributes()); + assertEquals(1L, metric(HuntMetrics.HUNTS).getLongSumData().getPoints().iterator().next().getValue()); + } + + @Test + @DisplayName("No metric carries a player") + void metricsHaveNoPlayer() { + this.rounds.roundStarted(); + this.hunts.started(SURVIVOR); + this.hunts.ended(SURVIVOR, HuntEnd.CAUGHT); + + for (String name : List.of(HuntMetrics.HUNT_DURATION, HuntMetrics.HUNTS)) { + metric(name).getData().getPoints().forEach(point -> { + assertEquals(2, point.getAttributes().size(), "outcome and map only"); + assertNull(point.getAttributes().get(CygnusAttributes.PLAYER_UUID)); + }); + } + } + + @Test + @DisplayName("The ending of a round closes the hunts still open as round_end, below a phase that still runs") + void roundEndClosesOpenHunts() { + this.rounds.roundStarted(); + this.rounds.phaseStarted("GamePhase"); + this.hunts.started(SURVIVOR); + this.hunts.started(UUID.randomUUID()); + pass(5); + + this.rounds.roundEnded(); + + List spans = huntSpans(); + assertEquals(2, spans.size()); + SpanData phase = this.telemetry.span("cygnus.phase.gamephase"); + spans.forEach(span -> { + assertEquals("round_end", span.getAttributes().get(CygnusAttributes.HUNT_OUTCOME)); + assertEquals(5_000L, span.getAttributes().get(CygnusAttributes.HUNT_DURATION_MS)); + assertTrue(span.getEndEpochNanos() <= phase.getEndEpochNanos(), "ends before its parent"); + }); + assertEquals(2L, metric(HuntMetrics.HUNTS).getLongSumData().getPoints().iterator().next().getValue()); + } + + @Test + @DisplayName("Two creeks hunting one survivor are two spans, closed one by one") + void twoHuntsOfOneSurvivor() { + this.rounds.roundStarted(); + this.hunts.started(SURVIVOR); + pass(2); + this.hunts.started(SURVIVOR); + pass(3); + + this.hunts.ended(SURVIVOR, HuntEnd.CAUGHT); + assertEquals(1, huntSpans().size()); + this.hunts.ended(SURVIVOR, HuntEnd.TIMEOUT); + + assertEquals(2, huntSpans().size()); + } + + @Test + @DisplayName("An end without a start is ignored, and a hunt is counted even when no round runs") + void endWithoutStartAndHuntWithoutRound() { + this.hunts.ended(SURVIVOR, HuntEnd.CAUGHT); + assertTrue(this.reader.collectAllMetrics().isEmpty()); + + this.hunts.started(SURVIVOR); + pass(1); + this.hunts.ended(SURVIVOR, HuntEnd.GONE); + + assertTrue(huntSpans().isEmpty(), "no round, no trace to belong to"); + assertEquals(1L, metric(HuntMetrics.HUNTS).getLongSumData().getPoints().iterator().next().getValue()); + } + + @Test + @DisplayName("The attributes of an outcome on a map are built once and reused") + void attributesAreReused() { + assertSame(this.metrics.attributes("caught", "Cabin"), this.metrics.attributes("caught", "Cabin")); + } + + @Test + @DisplayName("Metrics that record nothing leave the span working") + void noneMetrics() { + HuntTracer plain = new HuntTracer(this.rounds, Clock.fixed(Instant.EPOCH, ZoneOffset.UTC), () -> null, + id -> null, HuntMetrics.NONE); + this.rounds.roundStarted(); + + plain.started(SURVIVOR); + plain.ended(SURVIVOR, HuntEnd.CAUGHT); + + assertEquals(1, huntSpans().size()); + assertNull(huntSpans().getFirst().getAttributes().get(CygnusAttributes.MAP)); + } +}