bsp: make the compile server explicable — heap at boot, and telemetry that charts what it records

bleep-bsp/src/scala/bleep/bsp/BspMetrics.scala

@@ -342,6 +342,53 @@ object BspMetrics {
         )}","heap_used_mb":$heapUsedMb,"heap_max_mb":$heapMaxMb,"delay_ms":$delayMs,"others_compiling":$othersCompiling}"""
     )
 
+  /** Forked test JVMs, by pid, so a test run can be reconstructed after the fact.
+    *
+    * The compile server already recorded what it compiled; what it *ran* was invisible. These three plus [[recordSuiteScheduled]] answer the questions a slow
+    * or flaky test run actually raises: how many JVMs were started, how many were reused rather than respawned, how long each lived, which were killed rather
+    * than finishing, and which suite ran on which one. The pid is the join key between all of them.
+    */
+  /** The pool announces; this forwards to the same jsonl everything else lands in. Lives here rather than at the call site so there is one place that knows how
+    * a fork becomes an event.
+    */
+  val jvmPoolListener: bleep.testing.JvmPoolListener = new bleep.testing.JvmPoolListener {
+    def onForkStart(pid: Long, label: String, xmxMb: Option[Long]): Unit = recordForkStart(pid, label, xmxMb)
+    def onForkEnd(pid: Long, lifetimeMs: Long, exit: String, killedByUs: Option[String]): Unit = recordForkEnd(pid, lifetimeMs, exit, killedByUs)
+    def onForkReused(pid: Long, label: String): Unit = recordForkReused(pid, label)
+  }
+
+  def recordForkStart(pid: Long, label: String, xmxMb: Option[Long]): Unit =
+    writeEvent(
+      s"""{"type":"fork_start","ts":${now()},"pid":$pid,"label":"${esc(label)}","xmx_mb":${xmxMb.getOrElse(-1L)}}"""
+    )
+
+  /** `killed_by` is the whole point of recording this separately from the exit summary: `destroyForcibly` sends SIGKILL, so a fork bleep terminated is
+    * indistinguishable from one the OS killed unless we say which it was.
+    */
+  def recordForkEnd(pid: Long, lifetimeMs: Long, exit: String, killedByUs: Option[String]): Unit =
+    writeEvent(
+      s"""{"type":"fork_end","ts":${now()},"pid":$pid,"lifetime_ms":$lifetimeMs,"exit":"${esc(exit)}","killed_by":${killedByUs
+          .map(r => s""""${esc(r)}"""")
+          .getOrElse("null")}}"""
+    )
+
+  /** A pooled JVM handed out again instead of a new one being forked. The ratio against `fork_start` is how much the pool actually saves. */
+  def recordForkReused(pid: Long, label: String): Unit =
+    writeEvent(s"""{"type":"fork_reused","ts":${now()},"pid":$pid,"label":"${esc(label)}"}""")
+
+  /** Which suite was placed on which JVM, and how it went. Keyed on pid, so it joins to the fork events above. */
+  def recordSuiteScheduled(pid: Long, project: String, suite: String, framework: String): Unit =
+    writeEvent(
+      s"""{"type":"suite_scheduled","ts":${now()},"pid":$pid,"project":"${esc(project)}","suite":"${esc(suite)}","framework":"${esc(framework)}"}"""
+    )
+
+  def recordSuiteFinished(pid: Long, project: String, suite: String, durationMs: Long, outcome: String): Unit =
+    writeEvent(
+      s"""{"type":"suite_finished","ts":${now()},"pid":$pid,"project":"${esc(project)}","suite":"${esc(
+          suite
+        )}","duration_ms":$durationMs,"outcome":"${esc(outcome)}"}"""
+    )
+
   def recordOomCrash(threadName: String, message: String): Unit = {
     val heap = ManagementFactory.getMemoryMXBean.getHeapMemoryUsage
     val usedMb = heap.getUsed / (1024 * 1024)

bleep-bsp/src/scala/bleep/bsp/MultiWorkspaceBspServer.scala

@@ -2147,7 +2147,7 @@ class MultiWorkspaceBspServer(
 
         // Create JVM pool for test execution. The machine governor caps concurrent forks (cores +
         // fork-memory budget) across ALL clients — the per-pool maxParallelism only bounds this run.
-        testResult <- JvmPool.create(maxParallelism, started.jvmCommand, started.buildPaths.buildDir, machine).use { jvmPool =>
+        testResult <- JvmPool.create(maxParallelism, started.jvmCommand, started.buildPaths.buildDir, machine, BspMetrics.jvmPoolListener).use { jvmPool =>
           // Per-test-run map populated by the AP DAG handler and read by the compile handler. KSP runs as a separate process and emits files directly; no
           // intermediate compile-time data flow, so no equivalent map.
           val apResults = new java.util.concurrent.ConcurrentHashMap[CrossProjectName, AnnotationProcessorResult]()

bleep-bsp/src/scala/bleep/bsp/TestRunner.scala

@@ -75,17 +75,27 @@ object TestRunner {
     val runnerClass = "bleep.testing.runner.ForkedTestRunner"
 
     pool.acquire(suiteName, classpath, options.jvmOptions, runnerClass, options.environment, options.workingDirectory).use { jvm =>
-      executeWithIdleTimeout(
-        project = project,
-        suiteName = suiteName,
-        framework = framework,
-        jvm = jvm,
-        eventQueue = eventQueue,
-        testArgs = options.testArgs,
-        idleTimeout = options.idleTimeout,
-        resolveSourcePath = resolveSourcePath,
-        killSignal = killSignal
-      )
+      // Recorded here rather than in the pool because this is the only place that knows both which JVM was handed out and what is about to run on it. The pid
+      // joins these to the fork_start/fork_end pair, which is what lets a test run be reconstructed: which suites shared a JVM, and which JVM was killed
+      // under which suite.
+      val startedAt = System.currentTimeMillis()
+      IO(BspMetrics.recordSuiteScheduled(jvm.pid, project.value, suiteName, framework)).attempt >>
+        executeWithIdleTimeout(
+          project = project,
+          suiteName = suiteName,
+          framework = framework,
+          jvm = jvm,
+          eventQueue = eventQueue,
+          testArgs = options.testArgs,
+          idleTimeout = options.idleTimeout,
+          resolveSourcePath = resolveSourcePath,
+          killSignal = killSignal
+        ).flatTap { result =>
+          IO(
+            BspMetrics
+              .recordSuiteFinished(jvm.pid, project.value, suiteName, System.currentTimeMillis() - startedAt, result.getClass.getSimpleName.stripSuffix("$"))
+          ).attempt
+        }
     }
   }
 

bleep-cli/src/scala/bleep/Main.scala

@@ -72,7 +72,7 @@ object Main {
       configCommand(logger, userPaths),
       installTabCompletions(userPaths, logger),
       Opts.subcommand("server-metrics", "open BSP server metrics dashboard in browser")(
-        Opts.argument[Long]("pid").orNone.map(pid => commands.ServerMetrics(logger, userPaths, pid))
+        (Opts.argument[Long]("pid").orNone, metricsFileOpt).mapN((pid, file) => commands.ServerMetrics(logger, userPaths, pid, file))
       )
     ).foldK
 
@@ -533,7 +533,9 @@ object Main {
           configCommand(started.pre.logger, started.pre.userPaths),
           installTabCompletions(started.userPaths, started.pre.logger),
           Opts.subcommand("server-metrics", "open BSP server metrics dashboard in browser")(
-            Opts.argument[Long]("pid").orNone.map(pid => commands.ServerMetrics(started.pre.logger, started.pre.userPaths, pid))
+            (Opts.argument[Long]("pid").orNone, metricsFileOpt).mapN((pid, file) =>
+              commands.ServerMetrics(started.pre.logger, started.pre.userPaths, pid, file)
+            )
           ),
           Opts.subcommand("publish-local", "publishes your project locally (deprecated: use 'publish local-ivy')") {
             (
@@ -903,6 +905,12 @@ object Main {
       case None                             => FileUtils.cwd
     }
 
+  /** Point `server-metrics` at a `metrics.jsonl` from anywhere — a CI artifact, a colleague's machine — so the dashboard and the file you download are the same
+    * mechanism rather than two ways of looking at the same bytes.
+    */
+  private val metricsFileOpt: Opts[Option[Path]] =
+    Opts.option[Path]("file", "read this metrics.jsonl instead of the newest local one (e.g. downloaded from CI)").orNone
+
   val ec: ExecutionContext = ExecutionContext.global
 
   def maybeRunWithDifferentVersion(args: Array[String], logger: Logger, buildLoader: BuildLoader, dev: Boolean): ExitCode =