Instrument post-action processing phases (#8722)

2026-07-28 20:55:44 +00:00 · 2026-07-20 06:45:21 -07:00
parent 0e1536842e
commit 6b052bf3ad
5 changed files with 535 additions and 269 deletions
@@ -169,6 +169,35 @@ class EagleHistoryAppendEvent extends Event {
  var succeeded: Boolean = false
 }

+@Name("net.eagle0.eagle.PostActionPhase")
+@Label("Eagle Post-Action Phase")
+@Category(Array("Eagle0", "Game Processing"))
+@Enabled(true)
+@StackTrace(false)
+@Threshold("0 ms")
+class EaglePostActionPhaseEvent extends Event {
+  @Label("Game ID")
+  var gameId: String = ""
+
+  @Label("Phase")
+  var phase: String = ""
+
+  @Label("Faction ID")
+  var factionId: Int = -1
+
+  @Label("Action Result Count")
+  var actionResultCount: Int = 0
+
+  @Label("Human Client Count")
+  var humanClientCount: Int = 0
+
+  @Label("Item Count")
+  var itemCount: Long = 0L
+
+  @Label("Succeeded")
+  var succeeded: Boolean = false
+}
+
 object JfrEvents {
  private val usePostgresQueryEvents = new ThreadLocal[Boolean]()

@@ -330,4 +359,26 @@ object JfrEvents {
      }
    } else f(event)
  }
+
+  def postActionPhase[T](
+      gameId: => String,
+      phase: String,
+      factionId: Int = -1
+  )(f: EaglePostActionPhaseEvent => T): T = {
+    val event = new EaglePostActionPhaseEvent()
+    if event.isEnabled then {
+      event.gameId = gameId
+      event.phase = phase
+      event.factionId = factionId
+      event.begin()
+      try {
+        val value = f(event)
+        event.succeeded = true
+        value
+      } finally {
+        event.end()
+        event.commit()
+      }
+    } else f(event)
+  }
 }
@@ -1292,19 +1292,29 @@ class GamesManager(
  override def receive(br: BattleResolution): PostResults = {
    SimpleTimedLogger.printLogger.logLine("Handling battle resolution")
    this.synchronized {
-      synchronizedHandlePostResults(
-        requiredController(br.battle.eagleGameId)
-          .postBattleResolution(br)
-      ).postResults
+      JfrEvents.postActionPhase(br.battle.eagleGameId.toHexString, "gamesManager.battleResolution.total") { event =>
+        val result = synchronizedHandlePostResults(
+          requiredController(br.battle.eagleGameId)
+            .postBattleResolution(br)
+        )
+        event.actionResultCount = result.postResults.results.size
+        event.humanClientCount = result.gameController.humanClients.size
+        result.postResults
+      }
    }
  }

  override def receive(bu: BattleUpdate): PostResults =
    this.synchronized {
-      synchronizedHandlePostResults(
-        requiredController(bu.battle.eagleGameId)
-          .postBattleUpdate(bu)
-      ).postResults
+      JfrEvents.postActionPhase(bu.battle.eagleGameId.toHexString, "gamesManager.battleUpdate.total") { event =>
+        val result = synchronizedHandlePostResults(
+          requiredController(bu.battle.eagleGameId)
+            .postBattleUpdate(bu)
+        )
+        event.actionResultCount = bu.results.size
+        event.humanClientCount = result.gameController.humanClients.size
+        result.postResults
+      }
    }

  override def receiveBattleReset(battle: net.eagle0.eagle.internal.shardok_battle.ShardokBattle): PostResults =
@@ -1795,26 +1805,31 @@ class GamesManager(
  ): Unit = {
    requireLoadedGame(gameId)
    this.synchronized {
-      val afterHumanCommand = synchronizedHandlePostResults(
-        requiredController(gameId)
-          .postHumanCommandOnly(
-            userId = userId,
-            selectedProvinceId = selectedProvinceId,
-            command = command,
-            token = token
-          )
-      )
-      synchronizedHandlePostResults(
-        GameController.performAutomaticContinuation(
-          GameControllerWithPostResults(
-            gameController = afterHumanCommand.gameController,
-            postResults = PostResults(gameState = None, battles = Vector.empty, results = Vector.empty)
+      JfrEvents.postActionPhase(gameId.toHexString, "gamesManager.humanCommand.total") { event =>
+        val afterHumanCommand = synchronizedHandlePostResults(
+          requiredController(gameId)
+            .postHumanCommandOnly(
+              userId = userId,
+              selectedProvinceId = selectedProvinceId,
+              command = command,
+              token = token
+            )
+        )
+        val afterContinuation = synchronizedHandlePostResults(
+          GameController.performAutomaticContinuation(
+            GameControllerWithPostResults(
+              gameController = afterHumanCommand.gameController,
+              postResults = PostResults(gameState = None, battles = Vector.empty, results = Vector.empty)
+            )
          )
        )
-      ): Unit
-      // Record last played time for this user
-      updateLastPlayed(gameId, userId)
-      save()
+        // Record last played time for this user
+        updateLastPlayed(gameId, userId)
+        save()
+        event.actionResultCount =
+          afterHumanCommand.postResults.results.size + afterContinuation.postResults.results.size
+        event.humanClientCount = afterContinuation.gameController.humanClients.size
+      }
    }
  }

@@ -1827,18 +1842,22 @@ class GamesManager(
  ): Unit = {
    requireLoadedGame(gameId)
    this.synchronized {
-      synchronizedHandlePostResults(
-        requiredController(gameId)
-          .postHumanCommandOnly(
-            userId = userId,
-            selectedProvinceId = selectedProvinceId,
-            command = command,
-            token = token
-          )
-      ): Unit
-      // Record last played time for this user
-      updateLastPlayed(gameId, userId)
-      save()
+      JfrEvents.postActionPhase(gameId.toHexString, "gamesManager.humanCommandWithoutContinuation.total") { event =>
+        val result = synchronizedHandlePostResults(
+          requiredController(gameId)
+            .postHumanCommandOnly(
+              userId = userId,
+              selectedProvinceId = selectedProvinceId,
+              command = command,
+              token = token
+            )
+        )
+        // Record last played time for this user
+        updateLastPlayed(gameId, userId)
+        save()
+        event.actionResultCount = result.postResults.results.size
+        event.humanClientCount = result.gameController.humanClients.size
+      }
    }
  }

@@ -2072,6 +2091,18 @@ class GamesManager(
  private def synchronizedHandlePostResults(
      cwrt: GameControllerWithPostResults,
      handleUnrequestedTexts: Boolean
+  ): GameControllerWithPostResults =
+    JfrEvents.postActionPhase(cwrt.gameController.gameId.toHexString, "gamesManager.handlePostResults") { event =>
+      val result = synchronizedHandlePostResultsImpl(cwrt, handleUnrequestedTexts)
+      event.actionResultCount = result.postResults.results.size
+      event.humanClientCount = result.gameController.humanClients.size
+      event.itemCount = result.postResults.battles.size
+      result
+    }
+
+  private def synchronizedHandlePostResultsImpl(
+      cwrt: GameControllerWithPostResults,
+      handleUnrequestedTexts: Boolean
  ): GameControllerWithPostResults = {
    val newController = cwrt.postResults match {
      case PostResults(
@@ -295,15 +295,31 @@ object GameController {
  def performAutomaticContinuation(
      gameControllerWithPostResults: GameControllerWithPostResults
  ): GameControllerWithPostResults = {
-    val automaticUpdates = gameControllerWithPostResults.gameController
-      .withHandledEngineAndResults(gameControllerWithPostResults.gameController.engine.updated)
+    val controller        = gameControllerWithPostResults.gameController
+    lazy val gameIdString = controller.gameId.toHexString
+    val engineUpdate      = JfrEvents.postActionPhase(gameIdString, "automaticContinuation.engineUpdate") { event =>
+      val updated = controller.engine.updated
+      event.actionResultCount = updated.results.size
+      updated
+    }
+    val automaticUpdates  = JfrEvents.postActionPhase(gameIdString, "automaticContinuation.handleResults") { event =>
+      val handled = controller.withHandledEngineAndResults(engineUpdate)
+      event.actionResultCount = handled.postResults.results.size
+      event.humanClientCount = handled.gameController.humanClients.size
+      handled
+    }

-    performAiCommands(
-      GameControllerWithPostResults(
-        gameController = automaticUpdates.gameController,
-        postResults = gameControllerWithPostResults.postResults.append(automaticUpdates.postResults)
+    JfrEvents.postActionPhase(gameIdString, "automaticContinuation.performAiCommands") { event =>
+      val result = performAiCommands(
+        GameControllerWithPostResults(
+          gameController = automaticUpdates.gameController,
+          postResults = gameControllerWithPostResults.postResults.append(automaticUpdates.postResults)
+        )
      )
-    )
+      event.actionResultCount = result.postResults.results.size
+      event.humanClientCount = result.gameController.humanClients.size
+      result
+    }
  }

  private def humanClientsAfterUpdatingLlmStream(
@@ -358,28 +374,32 @@ object GameController {
    // Send battle progress updates if there is any progress to report
    if battleProgress.isEmpty then afterResults
    else {
-      val factions = engine.currentState.factions.values.toVector
+      val factions          = engine.currentState.factions.values.toVector
+      lazy val gameIdString = engine.gameId.toHexString
      afterResults.map { client =>
-        val firstFightableBattleId    =
-          GameStateViewFilter.firstFightableBattle(engine.currentState, client.factionId).map(_.shardokGameId)
-        val activeObservableBattleIds =
-          GameStateViewFilter.activeObservableBattleIds(engine.currentState, client.factionId).toSet
-        val enrichedBattles           = GameStateViewFilter
-          .orderedBattles(engine.currentState)
-          .filter(battle => battleProgress.contains(battle.shardokGameId))
-          .map { battle =>
-            val isAllied = BattleFilter.isParticipantOrAlly(client.factionId, battle, factions)
-            val view     =
-              BattleFilter.filterBattle(battle, factions, Some(client.factionId), engine.currentState.battalions)
-            GameStateViewFilter.markBattleAccess(
-              enrichBattleView(view, battleProgress, lastRevealedRound, isAllied),
-              firstFightableBattleId,
-              activeObservableBattleIds
-            )
+        JfrEvents.postActionPhase(gameIdString, "client.battleProgress", client.factionId) { event =>
+          val firstFightableBattleId    =
+            GameStateViewFilter.firstFightableBattle(engine.currentState, client.factionId).map(_.shardokGameId)
+          val activeObservableBattleIds =
+            GameStateViewFilter.activeObservableBattleIds(engine.currentState, client.factionId).toSet
+          val enrichedBattles           = GameStateViewFilter
+            .orderedBattles(engine.currentState)
+            .filter(battle => battleProgress.contains(battle.shardokGameId))
+            .map { battle =>
+              val isAllied = BattleFilter.isParticipantOrAlly(client.factionId, battle, factions)
+              val view     =
+                BattleFilter.filterBattle(battle, factions, Some(client.factionId), engine.currentState.battalions)
+              GameStateViewFilter.markBattleAccess(
+                enrichBattleView(view, battleProgress, lastRevealedRound, isAllied),
+                firstFightableBattleId,
+                activeObservableBattleIds
+              )
+            }
+          event.itemCount = enrichedBattles.size
+          try client.sendBattleProgress(enrichedBattles, lastRevealedRound)
+          catch {
+            case _: StatusRuntimeException | _: IllegalStateException => client
          }
-        try client.sendBattleProgress(enrichedBattles, lastRevealedRound)
-        catch {
-          case _: StatusRuntimeException | _: IllegalStateException => client
        }
      }
    }
@@ -393,87 +413,107 @@ object GameController {
      engine: Engine,
      fullHistory: FullGameHistory,
      aiFactionIds: Set[FactionId]
-  ): Vector[HumanPlayerClientConnectionState] =
+  ): Vector[HumanPlayerClientConnectionState] = {
+    lazy val gameIdString = engine.gameId.toHexString
    humanClients.flatMap { client =>
-      val clientTextUpdates = visibilityExtensions
-        .filter(_.recipientFactionIds.contains(client.factionId))
-        .flatMap { ext =>
-          clientTextStore.getText(ext.textId) match {
-            case TextGenerationSuccess(text) =>
-              Some(CompleteClientText(id = ext.textId, text = text, requestedAfterHistoryCount = 0))
-            case _                           => None
+      val clientTextUpdates = JfrEvents.postActionPhase(gameIdString, "client.textUpdates", client.factionId) { event =>
+        val updates = visibilityExtensions
+          .filter(_.recipientFactionIds.contains(client.factionId))
+          .flatMap { ext =>
+            clientTextStore.getText(ext.textId) match {
+              case TextGenerationSuccess(text) =>
+                Some(CompleteClientText(id = ext.textId, text = text, requestedAfterHistoryCount = 0))
+              case _                           => None
+            }
          }
-        }
+        event.itemCount = updates.size
+        updates
+      }

-      val updates               = engine.filteredHistoryWithUnfilteredCount(
-        client.factionId,
-        client.unfilteredKnownHistoryCount
-      )
-      val outstandingBattleIds  =
-        GameStateViewFilter.activeObservableBattleIds(engine.currentState, client.factionId)
-      val fightableBattleIds    =
-        GameStateViewFilter.activeFightableBattleIds(engine.currentState, client.factionId).toSet
-      val shardokGameIdsToCheck =
-        outstandingBattleIds.distinct
+      val updates = JfrEvents.postActionPhase(gameIdString, "client.historyProjection", client.factionId) { event =>
+        val historyUpdates = engine.filteredHistoryWithUnfilteredCount(
+          client.factionId,
+          client.unfilteredKnownHistoryCount
+        )
+        event.itemCount = historyUpdates.filteredResults.size
+        historyUpdates
+      }

-      val shardokUpdates =
-        shardokGameIdsToCheck.map { shardokGameId =>
-          val startingCount     = client.knownShardokResultCounts
-            .find(_.shardokGameId == shardokGameId)
-            .map(_.filteredResultCount)
-            .getOrElse(0)
-          val arvs              = fullHistory.shardokPlayerResultsSince(
-            shardokGameId = shardokGameId,
-            factionId = client.factionId,
-            startingCount = startingCount
-          )
-          val acs               = fullHistory
-            .shardokPlayerAvailableCommands(
+      val shardokUpdates = JfrEvents.postActionPhase(gameIdString, "client.shardokProjection", client.factionId) {
+        event =>
+          val outstandingBattleIds  =
+            GameStateViewFilter.activeObservableBattleIds(engine.currentState, client.factionId)
+          val fightableBattleIds    =
+            GameStateViewFilter.activeFightableBattleIds(engine.currentState, client.factionId).toSet
+          val shardokGameIdsToCheck = outstandingBattleIds.distinct
+
+          val updates = shardokGameIdsToCheck.map { shardokGameId =>
+            val startingCount     = client.knownShardokResultCounts
+              .find(_.shardokGameId == shardokGameId)
+              .map(_.filteredResultCount)
+              .getOrElse(0)
+            val arvs              = fullHistory.shardokPlayerResultsSince(
              shardokGameId = shardokGameId,
-              factionId = client.factionId
+              factionId = client.factionId,
+              startingCount = startingCount
            )
-            .filter(_ => fightableBattleIds.contains(shardokGameId))
-          val shardokStatus     = GameController.computeShardokServerStatus(
-            shardokGameId = shardokGameId,
-            myFactionId = client.factionId,
-            fullHistory = fullHistory,
-            allFactionIds = engine.factionIds,
-            aiFactionIds = aiFactionIds
-          )
-          val allArvs           = fullHistory.shardokPlayerResultsSince(
-            shardokGameId = shardokGameId,
-            factionId = client.factionId,
-            startingCount = 0
-          )
-          val tutorialDialogues = client.selectTacticalTutorialDialogues(
-            candidates = TacticalTutorialDialogueSelector.candidates(
-              gameState = engine.currentState,
-              allResultViews = allArvs,
-              newResultViewCount = arvs.size,
-              availableCommands = acs
+            val acs               = fullHistory
+              .shardokPlayerAvailableCommands(
+                shardokGameId = shardokGameId,
+                factionId = client.factionId
+              )
+              .filter(_ => fightableBattleIds.contains(shardokGameId))
+            val shardokStatus     = GameController.computeShardokServerStatus(
+              shardokGameId = shardokGameId,
+              myFactionId = client.factionId,
+              fullHistory = fullHistory,
+              allFactionIds = engine.factionIds,
+              aiFactionIds = aiFactionIds
            )
-          )
-          SingleShardokGameResultResponse(
-            shardokGameId = shardokGameId,
-            actionResultViews = arvs,
-            newResultViewCount = startingCount + arvs.length,
-            availableCommands = acs,
-            shardokServerStatus = Some(shardokStatus),
-            tutorialDialogues = tutorialDialogues.map(ActionResultViewConverter.tutorialDialogueToProto)
-          )
-        }
+            val allArvs           = fullHistory.shardokPlayerResultsSince(
+              shardokGameId = shardokGameId,
+              factionId = client.factionId,
+              startingCount = 0
+            )
+            val tutorialDialogues = client.selectTacticalTutorialDialogues(
+              candidates = TacticalTutorialDialogueSelector.candidates(
+                gameState = engine.currentState,
+                allResultViews = allArvs,
+                newResultViewCount = arvs.size,
+                availableCommands = acs
+              )
+            )
+            SingleShardokGameResultResponse(
+              shardokGameId = shardokGameId,
+              actionResultViews = arvs,
+              newResultViewCount = startingCount + arvs.length,
+              availableCommands = acs,
+              shardokServerStatus = Some(shardokStatus),
+              tutorialDialogues = tutorialDialogues.map(ActionResultViewConverter.tutorialDialogueToProto)
+            )
+          }
+          event.itemCount = updates.size
+          updates
+      }

      try
        Some {
-          val scalaCommands     = engine.getAvailablePlayerCommands(client.factionId)
-          val availableCommands = GameController.toProtoAvailableCommands(scalaCommands, engine, client.factionId)
+          val availableCommands =
+            JfrEvents.postActionPhase(gameIdString, "client.availableCommands", client.factionId) { event =>
+              val scalaCommands = engine.getAvailablePlayerCommands(client.factionId)
+              event.itemCount = scalaCommands.size
+              GameController.toProtoAvailableCommands(scalaCommands, engine, client.factionId)
+            }

-          val serverGameStatus = GameController.computeServerGameStatus(
-            engine = engine,
-            factionId = client.factionId,
-            otherFactionIds = engine.factionIds.filterNot(_ == client.factionId),
-            clientTextStore = clientTextStore
-          )
+          val serverGameStatus =
+            JfrEvents.postActionPhase(gameIdString, "client.serverStatus", client.factionId) { _ =>
+              GameController.computeServerGameStatus(
+                engine = engine,
+                factionId = client.factionId,
+                otherFactionIds = engine.factionIds.filterNot(_ == client.factionId),
+                clientTextStore = clientTextStore
+              )
+            }

          val note  =
            s"fid ${client.factionId}: Updating client with ${updates.filteredResults.length} new results, " +
@@ -485,18 +525,21 @@ object GameController {
          SimpleTimedLogger
            .fileLogger(gameId = engine.gameId, fileName = "timings")
            .withStopwatch(note + note2) {
-              clientTextUpdates.foldLeft(
-                client
-                  .update(
-                    availableCommands = availableCommands,
-                    filteredResults = updates.filteredResults,
-                    unfilteredCountAfter = updates.unfilteredCountAfter,
-                    knownShardokResults = shardokUpdates.toVector,
-                    serverGameStatus = serverGameStatus
-                  )
-              ) {
-                case (client, clientTextUpdate) =>
-                  client.update(clientText = clientTextUpdate)
+              JfrEvents.postActionPhase(gameIdString, "client.dispatch", client.factionId) { event =>
+                event.itemCount = updates.filteredResults.size + shardokUpdates.size + clientTextUpdates.size
+                clientTextUpdates.foldLeft(
+                  client
+                    .update(
+                      availableCommands = availableCommands,
+                      filteredResults = updates.filteredResults,
+                      unfilteredCountAfter = updates.unfilteredCountAfter,
+                      knownShardokResults = shardokUpdates.toVector,
+                      serverGameStatus = serverGameStatus
+                    )
+                ) {
+                  case (client, clientTextUpdate) =>
+                    client.update(clientText = clientTextUpdate)
+                }
              }
            }
        }
@@ -516,6 +559,7 @@ object GameController {
      }
      end try
    }
+  }

  /** Update battle progress tracking from Shardok game update data. */
  private[controller] def updatedBattleProgress(
@@ -666,8 +710,13 @@ final case class GameController(

  // FIXME: this isn't actually atomic, but at least we'll fail violently
  private def copyWithAtomicSave: GameController = try {
-    val newCts    = clientTextStore.saved
-    val newEngine = engine.saveNow
+    lazy val gameIdString = gameId.toHexString
+    val newCts            = JfrEvents.postActionPhase(gameIdString, "save.clientText") { _ =>
+      clientTextStore.saved
+    }
+    val newEngine         = JfrEvents.postActionPhase(gameIdString, "save.history") { _ =>
+      engine.saveNow
+    }

    copy(
      engine = newEngine,
@@ -688,24 +737,34 @@ final case class GameController(
      save: Boolean,
      runUpdateChecks: Boolean = true
  ): GameControllerWithPostResults = {
-    val engineAndResults =
-      if runUpdateChecks then
-        this.engine.postCommand(
-          factionId = factionId,
-          selectedProvinceId = selectedProvinceId,
-          selectedCommand = command
-        )
-      else
-        this.engine.postCommandWithoutUpdateChecks(
-          factionId = factionId,
-          selectedProvinceId = selectedProvinceId,
-          selectedCommand = command
-        )
+    lazy val gameIdString = gameId.toHexString
+    val engineAndResults  = JfrEvents.postActionPhase(gameIdString, "command.engine", factionId) { event =>
+      val result =
+        if runUpdateChecks then
+          this.engine.postCommand(
+            factionId = factionId,
+            selectedProvinceId = selectedProvinceId,
+            selectedCommand = command
+          )
+        else
+          this.engine.postCommandWithoutUpdateChecks(
+            factionId = factionId,
+            selectedProvinceId = selectedProvinceId,
+            selectedCommand = command
+          )
+      event.actionResultCount = result.results.size
+      result
+    }

-    withHandledEngineAndResults(
-      engineAndResults = engineAndResults,
-      updateClientsAndSave = save
-    )
+    JfrEvents.postActionPhase(gameIdString, "command.handleResults", factionId) { event =>
+      val result = withHandledEngineAndResults(
+        engineAndResults = engineAndResults,
+        updateClientsAndSave = save
+      )
+      event.actionResultCount = result.postResults.results.size
+      event.humanClientCount = result.gameController.humanClients.size
+      result
+    }
  }

  def withNewAiClientWithFid(fid: FactionId): GameController =
@@ -720,10 +779,13 @@ final case class GameController(
  def postBattleResolution(
      battleResolution: BattleResolution
  ): GameControllerWithPostResults = {
-    val shardokGameId = battleResolution.battle.shardokGameId
+    val shardokGameId     = battleResolution.battle.shardokGameId
+    lazy val gameIdString = gameId.toHexString

    // A completed strategic battle must never become durable before its final tactical updates.
-    fullHistory.flushShardokWrites()
+    JfrEvents.postActionPhase(gameIdString, "battleResolution.flushShardokWrites") { _ =>
+      fullHistory.flushShardokWrites()
+    }

    // Record the winner in the battle progress tracker
    val winnerFid = battleResolution.resolvedPlayers
@@ -742,32 +804,48 @@ final case class GameController(
      case None          => battleProgress
    }

-    val result = GameController.performAiCommands(
-      withHandledEngineAndResults(
-        engineAndResults = engine.resolveBattle(battleResolution)
+    val engineAndResults = JfrEvents.postActionPhase(gameIdString, "battleResolution.resolveEngine") { event =>
+      val resolved = engine.resolveBattle(battleResolution)
+      event.actionResultCount = resolved.results.size
+      resolved
+    }
+    val handledResults   = JfrEvents.postActionPhase(gameIdString, "battleResolution.handleResults") { event =>
+      val handled = withHandledEngineAndResults(engineAndResults = engineAndResults)
+      event.actionResultCount = handled.postResults.results.size
+      event.humanClientCount = handled.gameController.humanClients.size
+      handled
+    }
+    val result           = JfrEvents.postActionPhase(gameIdString, "battleResolution.performAiCommands") { event =>
+      val withAiCommands = GameController.performAiCommands(handledResults)
+      event.actionResultCount = withAiCommands.postResults.results.size
+      event.humanClientCount = withAiCommands.gameController.humanClients.size
+      withAiCommands
+    }
+
+    JfrEvents.postActionPhase(gameIdString, "battleResolution.cleanup") { event =>
+      // Clean up: remove progress for battles that are no longer outstanding
+      val remainingBattleIds = result.gameController.engine.currentState.outstandingBattles
+        .map(_.shardokGameId)
+        .toSet
+      val cleanedProgress    = updatedProgress.filter { case (id, _) => remainingBattleIds.contains(id) }
+
+      if !remainingBattleIds.contains(shardokGameId) then
+        result.gameController.fullHistory.evictShardokReadCache(shardokGameId)
+
+      // Reset gated round when all battles have ended so the next battle starts at day 0
+      val cleanedLastRevealedRound =
+        if cleanedProgress.isEmpty then 0
+        else result.gameController.lastRevealedRound
+
+      event.actionResultCount = result.postResults.results.size
+      event.itemCount = remainingBattleIds.size
+      result.copy(
+        gameController = result.gameController.copy(
+          battleProgress = cleanedProgress,
+          lastRevealedRound = cleanedLastRevealedRound
+        )
      )
-    )
-
-    // Clean up: remove progress for battles that are no longer outstanding
-    val remainingBattleIds = result.gameController.engine.currentState.outstandingBattles
-      .map(_.shardokGameId)
-      .toSet
-    val cleanedProgress    = updatedProgress.filter { case (id, _) => remainingBattleIds.contains(id) }
-
-    if !remainingBattleIds.contains(shardokGameId) then
-      result.gameController.fullHistory.evictShardokReadCache(shardokGameId)
-
-    // Reset gated round when all battles have ended so the next battle starts at day 0
-    val cleanedLastRevealedRound =
-      if cleanedProgress.isEmpty then 0
-      else result.gameController.lastRevealedRound
-
-    result.copy(
-      gameController = result.gameController.copy(
-        battleProgress = cleanedProgress,
-        lastRevealedRound = cleanedLastRevealedRound
-      )
-    )
+    }
  }

  def applyTutorialSetup(results: Vector[ActionResultT]): GameControllerWithPostResults =
@@ -853,18 +931,22 @@ final case class GameController(
        s"We should have ${battleUpdate.newUnfilteredCount} results, but we had $oldCount and got ${battleUpdate.results.size} new ones"
      )

-      val newHistory = fullHistory.withNewShardokResults(
-        shardokGameId = battleUpdate.battle.shardokGameId,
-        newResults = battleUpdate.results,
-        newPlayerResults = battleUpdate.updates.map { opr =>
-          (opr.eagleFactionId, opr.actionResultViews.toVector)
-        },
-        eagleRoundId = battleUpdate.battle.roundStarted,
-        currentGameState = battleUpdate.currentGameStateBytes,
-        availableCommands = battleUpdate.updates.map { opr =>
-          (opr.eagleFactionId, opr.availableCommands)
-        }
-      )
+      val newHistory = JfrEvents.postActionPhase(gameId.toHexString, "battleUpdate.acceptResults") { event =>
+        event.actionResultCount = battleUpdate.results.size
+        event.itemCount = battleUpdate.updates.size
+        fullHistory.withNewShardokResults(
+          shardokGameId = battleUpdate.battle.shardokGameId,
+          newResults = battleUpdate.results,
+          newPlayerResults = battleUpdate.updates.map { opr =>
+            (opr.eagleFactionId, opr.actionResultViews.toVector)
+          },
+          eagleRoundId = battleUpdate.battle.roundStarted,
+          currentGameState = battleUpdate.currentGameStateBytes,
+          availableCommands = battleUpdate.updates.map { opr =>
+            (opr.eagleFactionId, opr.availableCommands)
+          }
+        )
+      }

      val newEngine = engine.withHistory(newHistory)

@@ -881,7 +963,9 @@ final case class GameController(

      // Only send battle progress when the gated round advances, to avoid flooding
      // clients with per-action updates where the day hasn't changed
-      val updatedHumanClients =
+      val updatedHumanClients = JfrEvents.postActionPhase(gameId.toHexString, "battleUpdate.updateClients") { event =>
+        event.actionResultCount = battleUpdate.results.size
+        event.humanClientCount = humanClients.size
        if newLastRevealedRound > lastRevealedRound then
          GameController.humanClientsAfterPostingResults(
            humanClients = humanClients,
@@ -902,6 +986,8 @@ final case class GameController(
            fullHistory = newHistory,
            aiFactionIds = aiClientFactionIds.toSet
          )
+        end if
+      }

      GameControllerWithPostResults(
        gameController = copy(
@@ -1128,52 +1214,66 @@ final case class GameController(
      engineAndResults: EngineAndResults,
      updateClientsAndSave: Boolean = true
  ): GameControllerWithPostResults = {
+    lazy val gameIdString     = gameId.toHexString
    // Check for tutorial strategic events that should fire based on the new game state
-    val tutorialEvents        = TutorialStrategicEvents.checkForEvents(engineAndResults.engine.currentState)
-    val finalEngineAndResults =
-      if tutorialEvents.isEmpty then engineAndResults
-      else engineAndResults.engine.applyActionResults(tutorialEvents)
+    val finalEngineAndResults = JfrEvents.postActionPhase(gameIdString, "results.tutorialEvents") { event =>
+      val tutorialEvents = TutorialStrategicEvents.checkForEvents(engineAndResults.engine.currentState)
+      event.itemCount = tutorialEvents.size
+      val result         =
+        if tutorialEvents.isEmpty then engineAndResults
+        else engineAndResults.engine.applyActionResults(tutorialEvents)
+      event.actionResultCount = result.results.size
+      result
+    }

-    val llmRequestsWithHistoryCounts = allNewLlmRequests(
-      finalEngineAndResults.engine.history.count - finalEngineAndResults.results.length,
-      finalEngineAndResults.results
-    )
+    val (llmRequestsWithHistoryCounts, clientVisibilityExtensions) =
+      JfrEvents.postActionPhase(gameIdString, "results.collectClientText") { event =>
+        val requests   = allNewLlmRequests(
+          finalEngineAndResults.engine.history.count - finalEngineAndResults.results.length,
+          finalEngineAndResults.results
+        )
+        val extensions = finalEngineAndResults.results.flatMap(_.clientTextVisibilityExtensions)
+        event.actionResultCount = finalEngineAndResults.results.size
+        event.itemCount = requests.size + extensions.size
+        requests -> extensions
+      }

-    val clientVisibilityExtensions =
-      finalEngineAndResults.results.flatMap(_.clientTextVisibilityExtensions)
-
-    val newFullHistory = extractFullHistory(finalEngineAndResults.engine)
-
-    val handledGc = copy(
-      engine = finalEngineAndResults.engine,
-      fullHistory = newFullHistory,
-      userIdToFactionId = userIdToFactionId.filter {
-        case (_, fid) =>
-          finalEngineAndResults.engine.factionIds.contains(fid)
-      },
-      humanClients = humanClients,
-      aiClients = {
-        val afterRemovals = aiClients
-          .filterNot(aic =>
-            finalEngineAndResults.results
-              .exists(_.removedFactionIds.contains(aic.newValue.factionId))
-          )
-        val existingFids  = afterRemovals.map(_.newValue.factionId).toSet ++ userIdToFactionId.values.toSet
-        val newAiFids     = finalEngineAndResults.results
-          .flatMap(_.newFactions.map(_.id))
-          .filterNot(existingFids.contains)
-        newAiFids.foldLeft(afterRemovals) { (clients, fid) =>
-          clients :+ RandomState(
-            AIClient(gameId = gameId, factionId = fid),
-            SeededRandom(GameController.aiSeed(engine.gameId, fid))
-          )
-        }
-      },
-      clientTextStore = foldInExtendedVisibility(
-        foldInLlmRequests(this.clientTextStore, llmRequestsWithHistoryCounts),
-        clientVisibilityExtensions
+    val handledGc = JfrEvents.postActionPhase(gameIdString, "results.prepareController") { event =>
+      val newFullHistory = extractFullHistory(finalEngineAndResults.engine)
+      val controller     = copy(
+        engine = finalEngineAndResults.engine,
+        fullHistory = newFullHistory,
+        userIdToFactionId = userIdToFactionId.filter {
+          case (_, fid) =>
+            finalEngineAndResults.engine.factionIds.contains(fid)
+        },
+        humanClients = humanClients,
+        aiClients = {
+          val afterRemovals = aiClients
+            .filterNot(aic =>
+              finalEngineAndResults.results
+                .exists(_.removedFactionIds.contains(aic.newValue.factionId))
+            )
+          val existingFids  = afterRemovals.map(_.newValue.factionId).toSet ++ userIdToFactionId.values.toSet
+          val newAiFids     = finalEngineAndResults.results
+            .flatMap(_.newFactions.map(_.id))
+            .filterNot(existingFids.contains)
+          newAiFids.foldLeft(afterRemovals) { (clients, fid) =>
+            clients :+ RandomState(
+              AIClient(gameId = gameId, factionId = fid),
+              SeededRandom(GameController.aiSeed(engine.gameId, fid))
+            )
+          }
+        },
+        clientTextStore = foldInExtendedVisibility(
+          foldInLlmRequests(this.clientTextStore, llmRequestsWithHistoryCounts),
+          clientVisibilityExtensions
+        )
      )
-    )
+      event.actionResultCount = finalEngineAndResults.results.size
+      event.humanClientCount = controller.humanClients.size
+      controller
+    }

    val newGc =
      if updateClientsAndSave then {
@@ -1199,18 +1299,22 @@ final case class GameController(
      results: Seq[ActionResultT],
      clientTextStoreForUpdate: ClientTextStore
  ): GameController =
-    copy(
-      humanClients = GameController.humanClientsAfterPostingResults(
-        humanClients = humanClients,
-        clientTextStore = clientTextStoreForUpdate,
-        visibilityExtensions = results.flatMap(_.clientTextVisibilityExtensions).toVector,
-        engine = engine,
-        fullHistory = fullHistory,
-        aiFactionIds = aiClientFactionIds.toSet,
-        battleProgress = battleProgress,
-        lastRevealedRound = lastRevealedRound
+    JfrEvents.postActionPhase(gameId.toHexString, "clients.updateAll") { event =>
+      event.actionResultCount = results.size
+      event.humanClientCount = humanClients.size
+      copy(
+        humanClients = GameController.humanClientsAfterPostingResults(
+          humanClients = humanClients,
+          clientTextStore = clientTextStoreForUpdate,
+          visibilityExtensions = results.flatMap(_.clientTextVisibilityExtensions).toVector,
+          engine = engine,
+          fullHistory = fullHistory,
+          aiFactionIds = aiClientFactionIds.toSet,
+          battleProgress = battleProgress,
+          lastRevealedRound = lastRevealedRound
+        )
      )
-    )
+    }

  def streamUpdates(
      userId: UserId,
@@ -1441,7 +1545,12 @@ final case class GameController(
      }
    val historyCountBeforeCommand = engine.history.count
    val gameStateBeforeCommand    = engine.currentState
-    val availableCommands         = engine.getAvailablePlayerCommands(client.factionId)
+    val availableCommands         =
+      JfrEvents.postActionPhase(gameId.toHexString, "humanCommand.availableCommandsForLog", client.factionId) { event =>
+        val commands = engine.getAvailablePlayerCommands(client.factionId)
+        event.itemCount = commands.size
+        commands
+      }
    val result                    = this
      .withPostedCommand(
        factionId = client.factionId,
@@ -1451,15 +1560,18 @@ final case class GameController(
        runUpdateChecks = false
      )

-    AIDecisionRecordLogger.logHumanCommand(
-      gameStateBeforeCommand = gameStateBeforeCommand,
-      firstActionSeq = historyCountBeforeCommand,
-      factionId = client.factionId,
-      provinceId = selectedProvinceId,
-      selectedCommand = selectedCommand,
-      actionResults = result.postResults.results,
-      availableCommands = availableCommands
-    )
+    JfrEvents.postActionPhase(gameId.toHexString, "humanCommand.decisionLogging", client.factionId) { event =>
+      event.actionResultCount = result.postResults.results.size
+      AIDecisionRecordLogger.logHumanCommand(
+        gameStateBeforeCommand = gameStateBeforeCommand,
+        firstActionSeq = historyCountBeforeCommand,
+        factionId = client.factionId,
+        provinceId = selectedProvinceId,
+        selectedCommand = selectedCommand,
+        actionResults = result.postResults.results,
+        availableCommands = availableCommands
+      )
+    }

    result
  }
@@ -18,6 +18,14 @@ scala_library(
    ],
 )

+scala_test(
+    name = "jfr_events_test",
+    srcs = ["JfrEventsTest.scala"],
+    deps = [
+        "//src/main/scala/net/eagle0/common:jfr_events",
+    ],
+)
+
 scala_test(
    name = "more_option_test",
    srcs = ["MoreOptionTest.scala"],
@@ -0,0 +1,64 @@
+package net.eagle0.common
+
+import java.nio.file.Files
+import java.time.Duration
+
+import scala.jdk.CollectionConverters.*
+
+import jdk.jfr.consumer.RecordingFile
+import jdk.jfr.Recording
+import org.scalatest.flatspec.AnyFlatSpec
+import org.scalatest.matchers.should.Matchers
+
+class JfrEventsTest extends AnyFlatSpec with Matchers {
+  "postActionPhase" should "record phase metadata and counts" in {
+    val recordingPath = Files.createTempFile("eagle-post-action-phase", ".jfr")
+    val recording     = new Recording()
+    try {
+      recording.enable("net.eagle0.eagle.PostActionPhase").withThreshold(Duration.ZERO)
+      recording.start()
+
+      val result = JfrEvents.postActionPhase("game-123", "client.historyProjection", factionId = 7) { event =>
+        event.actionResultCount = 3
+        event.humanClientCount = 2
+        event.itemCount = 11
+        "result"
+      }
+
+      recording.stop()
+      recording.dump(recordingPath)
+
+      result shouldBe "result"
+      val event = RecordingFile
+        .readAllEvents(recordingPath)
+        .asScala
+        .find(_.getEventType.getName == "net.eagle0.eagle.PostActionPhase")
+        .getOrElse(fail("PostActionPhase event was not recorded"))
+      event.getString("gameId") shouldBe "game-123"
+      event.getString("phase") shouldBe "client.historyProjection"
+      event.getInt("factionId") shouldBe 7
+      event.getInt("actionResultCount") shouldBe 3
+      event.getInt("humanClientCount") shouldBe 2
+      event.getLong("itemCount") shouldBe 11L
+      event.getBoolean("succeeded") shouldBe true
+      event.getStackTrace shouldBe null
+    } finally {
+      recording.close()
+      Files.deleteIfExists(recordingPath): Unit
+    }
+  }
+
+  it should "leave lazy metadata unevaluated when no recording is active" in {
+    var metadataEvaluated = false
+
+    JfrEvents.postActionPhase(
+      {
+        metadataEvaluated = true
+        "game-123"
+      },
+      "unused"
+    )(_ => ())
+
+    metadataEvaluated shouldBe false
+  }
+}