Stage 17: backend defect fixes (nudge code, TG name, robot names/timing, multi-device push, move-duration metric + admin analytics)
- #3 nudge-on-own-turn: distinct result code nudge_own_turn + i18n (was reused 'not_your_turn') - #2 sanitize connector registration name to the editable format; Player/Игрок-XXXXX fallback - #5 variant-aware robot name pools (composed full/colloquial first + surname forms; ru gets <=20% latin) - #4 move-number-aware robot move timing (early 1-5min -> late 10-90min, skew k=4) - #7 emit move event to the actor too (multi-device sync); opponent_moved stays in-app only - #1 live game_move_duration{variant,phase} histogram + admin console per-user min/avg/max columns and an inline-SVG move-time-by-move-number chart (offline from the journal) - ProvisionRobot bypasses editor name validation (system names like 'Peter J.')
This commit is contained in:
Ilia Denisov
@@ -0,0 +1,116 @@
|
||||
package game
|
||||
|
||||
import (
|
||||
"context"
|
||||
"fmt"
|
||||
"strings"
|
||||
|
||||
"github.com/google/uuid"
|
||||
)
|
||||
|
||||
// A move's "duration" is the think time from the previous move's commit (the moment
|
||||
// the turn started) to this move's commit. Only play/pass/exchange moves count;
|
||||
// timeouts and resignations are not think time. The very first move of a game has no
|
||||
// previous move, so its baseline is the game's creation time. The figures are derived
|
||||
// from the move journal (game_moves.created_at), so no schema change is needed.
|
||||
//
|
||||
// timedMovesCTE is the shared subquery yielding (account, game, ordinal, seconds) for
|
||||
// every timed move; the two reports aggregate it differently.
|
||||
const timedMovesCTE = `
|
||||
SELECT gp.account_id AS aid,
|
||||
m.game_id AS gid,
|
||||
ROW_NUMBER() OVER (PARTITION BY m.game_id ORDER BY m.seq) AS ord,
|
||||
EXTRACT(EPOCH FROM (m.created_at - COALESCE(prev.created_at, g.created_at))) AS secs
|
||||
FROM backend.game_moves m
|
||||
JOIN backend.games g ON g.game_id = m.game_id
|
||||
LEFT JOIN backend.game_moves prev ON prev.game_id = m.game_id AND prev.seq = m.seq - 1
|
||||
JOIN backend.game_players gp ON gp.game_id = m.game_id AND gp.seat = m.seat
|
||||
WHERE m.action IN ('play', 'pass', 'exchange')`
|
||||
|
||||
// MoveDurationStat is the min, max and mean per-move think time (in seconds) for an
|
||||
// account across all its games, with the number of timed moves counted.
|
||||
type MoveDurationStat struct {
|
||||
MinSecs float64
|
||||
MaxSecs float64
|
||||
AvgSecs float64
|
||||
Moves int
|
||||
}
|
||||
|
||||
// MoveDurationStats returns the move-duration summary for each of accountIDs that has
|
||||
// at least one timed move; accounts with none are absent from the map. It powers the
|
||||
// admin user-list columns. The scan over the journal is acceptable for the low-traffic
|
||||
// console; per-human analysis is the authoritative use (the live metric aggregates all
|
||||
// seats including robots).
|
||||
func (s *Store) MoveDurationStats(ctx context.Context, accountIDs []uuid.UUID) (map[uuid.UUID]MoveDurationStat, error) {
|
||||
if len(accountIDs) == 0 {
|
||||
return map[uuid.UUID]MoveDurationStat{}, nil
|
||||
}
|
||||
q := `WITH d AS (` + timedMovesCTE + `)
|
||||
SELECT aid, MIN(secs), MAX(secs), AVG(secs), COUNT(*) FROM d WHERE aid = ANY($1::uuid[]) GROUP BY aid`
|
||||
rows, err := s.db.QueryContext(ctx, q, uuidArrayLiteral(accountIDs))
|
||||
if err != nil {
|
||||
return nil, fmt.Errorf("game: move-duration stats: %w", err)
|
||||
}
|
||||
defer rows.Close()
|
||||
out := make(map[uuid.UUID]MoveDurationStat, len(accountIDs))
|
||||
for rows.Next() {
|
||||
var id uuid.UUID
|
||||
var st MoveDurationStat
|
||||
if err := rows.Scan(&id, &st.MinSecs, &st.MaxSecs, &st.AvgSecs, &st.Moves); err != nil {
|
||||
return nil, fmt.Errorf("game: scan move-duration stat: %w", err)
|
||||
}
|
||||
out[id] = st
|
||||
}
|
||||
return out, rows.Err()
|
||||
}
|
||||
|
||||
// OrdinalDuration is the min/max/mean think time (seconds) at an account's k-th move
|
||||
// (Ordinal) across all its games.
|
||||
type OrdinalDuration struct {
|
||||
Ordinal int
|
||||
MinSecs float64
|
||||
MaxSecs float64
|
||||
AvgSecs float64
|
||||
}
|
||||
|
||||
// MoveDurationByOrdinal returns the account's per-move-number think-time summary,
|
||||
// ordered by move number, for the admin user-detail chart. The ordinal counts the
|
||||
// account's own moves within each game (its 1st, 2nd, … move).
|
||||
func (s *Store) MoveDurationByOrdinal(ctx context.Context, accountID uuid.UUID) ([]OrdinalDuration, error) {
|
||||
q := `WITH d AS (` + timedMovesCTE + ` AND gp.account_id = $1)
|
||||
SELECT ord, MIN(secs), MAX(secs), AVG(secs) FROM d GROUP BY ord ORDER BY ord`
|
||||
rows, err := s.db.QueryContext(ctx, q, accountID)
|
||||
if err != nil {
|
||||
return nil, fmt.Errorf("game: move-duration by ordinal: %w", err)
|
||||
}
|
||||
defer rows.Close()
|
||||
var out []OrdinalDuration
|
||||
for rows.Next() {
|
||||
var od OrdinalDuration
|
||||
if err := rows.Scan(&od.Ordinal, &od.MinSecs, &od.MaxSecs, &od.AvgSecs); err != nil {
|
||||
return nil, fmt.Errorf("game: scan ordinal duration: %w", err)
|
||||
}
|
||||
out = append(out, od)
|
||||
}
|
||||
return out, rows.Err()
|
||||
}
|
||||
|
||||
// uuidArrayLiteral renders ids as a Postgres array literal ("{u1,u2,…}") for an
|
||||
// ANY($1::uuid[]) parameter. UUIDs are fixed-format, so the literal is injection-safe.
|
||||
func uuidArrayLiteral(ids []uuid.UUID) string {
|
||||
ss := make([]string, len(ids))
|
||||
for i, id := range ids {
|
||||
ss[i] = id.String()
|
||||
}
|
||||
return "{" + strings.Join(ss, ",") + "}"
|
||||
}
|
||||
|
||||
// MoveDurationStats exposes the store report to the admin console handlers.
|
||||
func (svc *Service) MoveDurationStats(ctx context.Context, accountIDs []uuid.UUID) (map[uuid.UUID]MoveDurationStat, error) {
|
||||
return svc.store.MoveDurationStats(ctx, accountIDs)
|
||||
}
|
||||
|
||||
// MoveDurationByOrdinal exposes the per-move-number report to the admin console.
|
||||
func (svc *Service) MoveDurationByOrdinal(ctx context.Context, accountID uuid.UUID) ([]OrdinalDuration, error) {
|
||||
return svc.store.MoveDurationByOrdinal(ctx, accountID)
|
||||
}
|
||||
@@ -0,0 +1,52 @@
|
||||
package game
|
||||
|
||||
import (
|
||||
"slices"
|
||||
"testing"
|
||||
"time"
|
||||
|
||||
"github.com/google/uuid"
|
||||
|
||||
"scrabble/backend/internal/engine"
|
||||
"scrabble/backend/internal/notify"
|
||||
)
|
||||
|
||||
// recordingPublisher captures every published intent for assertions.
|
||||
type recordingPublisher struct{ intents []notify.Intent }
|
||||
|
||||
func (p *recordingPublisher) Publish(in ...notify.Intent) { p.intents = append(p.intents, in...) }
|
||||
|
||||
// TestEmitMoveNotifiesActor checks a committed move sends opponent_moved to every
|
||||
// seat — including the actor's own account, so the mover's other devices refresh —
|
||||
// and your_turn only to the next mover.
|
||||
func TestEmitMoveNotifiesActor(t *testing.T) {
|
||||
actor, opp := uuid.New(), uuid.New()
|
||||
pub := &recordingPublisher{}
|
||||
svc := &Service{pub: pub}
|
||||
g := Game{
|
||||
ID: uuid.New(),
|
||||
Status: StatusActive,
|
||||
ToMove: 1,
|
||||
TurnStartedAt: time.Now(),
|
||||
TurnTimeout: time.Hour,
|
||||
Seats: []Seat{{Seat: 0, AccountID: actor}, {Seat: 1, AccountID: opp}},
|
||||
}
|
||||
svc.emitMove(g, engine.MoveRecord{Player: 0, Action: engine.ActionPlay, Score: 10, Total: 10})
|
||||
|
||||
kinds := map[uuid.UUID][]string{}
|
||||
for _, in := range pub.intents {
|
||||
kinds[in.UserID] = append(kinds[in.UserID], in.Kind)
|
||||
}
|
||||
if !slices.Contains(kinds[actor], notify.KindOpponentMoved) {
|
||||
t.Errorf("actor should get opponent_moved, got %v", kinds[actor])
|
||||
}
|
||||
if !slices.Contains(kinds[opp], notify.KindOpponentMoved) {
|
||||
t.Errorf("opponent should get opponent_moved, got %v", kinds[opp])
|
||||
}
|
||||
if !slices.Contains(kinds[opp], notify.KindYourTurn) {
|
||||
t.Errorf("next mover should get your_turn, got %v", kinds[opp])
|
||||
}
|
||||
if slices.Contains(kinds[actor], notify.KindYourTurn) {
|
||||
t.Errorf("actor is not next to move, should not get your_turn")
|
||||
}
|
||||
}
|
||||
@@ -22,6 +22,7 @@ const meterName = "scrabble/backend/game"
|
||||
type gameMetrics struct {
|
||||
replay metric.Float64Histogram
|
||||
validate metric.Float64Histogram
|
||||
moveDur metric.Float64Histogram
|
||||
started metric.Int64Counter
|
||||
abandoned metric.Int64Counter
|
||||
}
|
||||
@@ -39,6 +40,7 @@ func newGameMetrics(meter metric.Meter) *gameMetrics {
|
||||
return &gameMetrics{
|
||||
replay: histogram(meter, "game_replay_duration", "Seconds to rebuild a live game from its journal on a cache miss."),
|
||||
validate: histogram(meter, "game_move_validate_duration", "Seconds to validate and score a tentative play (EvaluatePlay)."),
|
||||
moveDur: histogram(meter, "game_move_duration", "Seconds a seat spent on a committed move (play/pass/exchange), by variant and phase. Aggregates all seats including robots; per-human analysis lives in the admin console."),
|
||||
started: counter(meter, "games_started_total", "Games created and started."),
|
||||
abandoned: counter(meter, "games_abandoned_total", "Player seats dropped by the turn-timeout sweeper."),
|
||||
}
|
||||
@@ -75,6 +77,30 @@ func (m *gameMetrics) recordValidate(ctx context.Context, v engine.Variant, star
|
||||
m.validate.Record(ctx, time.Since(start).Seconds(), variantAttr(v))
|
||||
}
|
||||
|
||||
// recordMoveDuration records how long a seat spent on a committed move, attributed by
|
||||
// variant and the game phase derived from moveCount. A non-positive duration (a clock
|
||||
// skew or a move with no recorded turn start) is dropped.
|
||||
func (m *gameMetrics) recordMoveDuration(ctx context.Context, v engine.Variant, moveCount int, d time.Duration) {
|
||||
if d <= 0 {
|
||||
return
|
||||
}
|
||||
m.moveDur.Record(ctx, d.Seconds(),
|
||||
metric.WithAttributes(attribute.String("variant", v.String()), attribute.String("phase", phaseOf(moveCount))))
|
||||
}
|
||||
|
||||
// phaseOf buckets a move ordinal into the game phase used as a metric attribute. The
|
||||
// thresholds reflect a typical ~28-move game (docs/ARCHITECTURE.md §7).
|
||||
func phaseOf(moveCount int) string {
|
||||
switch {
|
||||
case moveCount <= 8:
|
||||
return "opening"
|
||||
case moveCount <= 20:
|
||||
return "middle"
|
||||
default:
|
||||
return "endgame"
|
||||
}
|
||||
}
|
||||
|
||||
// recordStarted counts one started game of variant.
|
||||
func (m *gameMetrics) recordStarted(ctx context.Context, v engine.Variant) {
|
||||
m.started.Add(ctx, 1, variantAttr(v))
|
||||
|
||||
@@ -26,6 +26,8 @@ func TestGameMetrics(t *testing.T) {
|
||||
m.recordAbandoned(ctx, engine.VariantErudit)
|
||||
m.recordReplay(ctx, engine.VariantEnglish, time.Now().Add(-time.Millisecond))
|
||||
m.recordValidate(ctx, engine.VariantRussianScrabble, time.Now().Add(-time.Millisecond))
|
||||
m.recordMoveDuration(ctx, engine.VariantEnglish, 3, 5*time.Second)
|
||||
m.recordMoveDuration(ctx, engine.VariantEnglish, 3, 0) // non-positive: dropped
|
||||
|
||||
var rm metricdata.ResourceMetrics
|
||||
if err := reader.Collect(ctx, &rm); err != nil {
|
||||
@@ -45,6 +47,19 @@ func TestGameMetrics(t *testing.T) {
|
||||
if c := histogramCount(t, rm, "game_move_validate_duration"); c != 1 {
|
||||
t.Errorf("game_move_validate_duration observations = %d, want 1", c)
|
||||
}
|
||||
if c := histogramCount(t, rm, "game_move_duration"); c != 1 {
|
||||
t.Errorf("game_move_duration observations = %d, want 1 (zero-duration dropped)", c)
|
||||
}
|
||||
}
|
||||
|
||||
// TestPhaseOf checks the move-ordinal to phase bucketing.
|
||||
func TestPhaseOf(t *testing.T) {
|
||||
cases := map[int]string{1: "opening", 8: "opening", 9: "middle", 20: "middle", 21: "endgame", 50: "endgame"}
|
||||
for mc, want := range cases {
|
||||
if got := phaseOf(mc); got != want {
|
||||
t.Errorf("phaseOf(%d) = %q, want %q", mc, got, want)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// counterByAttr sums the int64 counter named name, grouped by the value of the
|
||||
|
||||
@@ -226,6 +226,9 @@ func (svc *Service) transition(ctx context.Context, gameID, accountID uuid.UUID,
|
||||
if err != nil {
|
||||
return MoveResult{}, err
|
||||
}
|
||||
// Record the seat's think time (turn start to commit) for the move-duration
|
||||
// metric; the timeout path commits separately and is excluded by design.
|
||||
svc.metrics.recordMoveDuration(ctx, pre.Variant, post.MoveCount, svc.clock().Sub(pre.TurnStartedAt))
|
||||
return MoveResult{Move: rec, Game: post}, nil
|
||||
}
|
||||
|
||||
@@ -287,14 +290,15 @@ func (svc *Service) commit(ctx context.Context, gameID uuid.UUID, g *engine.Game
|
||||
}
|
||||
|
||||
// emitMove publishes the live events for a just-committed move: opponent_moved to
|
||||
// every seat other than the actor, and your_turn to the next mover while the game
|
||||
// is still active. Delivery is best-effort (notify.Publisher never blocks).
|
||||
// every seat — including the actor's own account, so the mover's other devices (and
|
||||
// their lobby) refresh too — and your_turn to the next mover while the game is still
|
||||
// active. opponent_moved is in-app only (the gateway never turns it into an
|
||||
// out-of-app push), so the actor is not notified out of band about their own move.
|
||||
// Delivery is best-effort (notify.Publisher never blocks) and the gateway fans each
|
||||
// event out to all of the recipient's live streams.
|
||||
func (svc *Service) emitMove(post Game, rec engine.MoveRecord) {
|
||||
intents := make([]notify.Intent, 0, len(post.Seats)+1)
|
||||
for _, s := range post.Seats {
|
||||
if s.Seat == rec.Player {
|
||||
continue
|
||||
}
|
||||
intents = append(intents, notify.OpponentMoved(s.AccountID, post.ID, rec.Player, rec.Action.String(), rec.Score, rec.Total))
|
||||
}
|
||||
if post.Status == StatusActive {
|
||||
|
||||
Reference in New Issue
Block a user