VisionPoseLatencySmokeTest.kt

    @JvmStatic
    fun main(args: Array<String>) {
        installVisionPoseHandler()
        val handler = visionPoseRawHandler() ?: error("no handler registered")

        VisionPoseLatency.reset()
        VisionPoseStream.reset()

        // ---- nothing measured yet ---------------------------------------------------------------
        require(!VisionPoseLatency.offsetKnown) { "the offset must start unknown" }
        require(VisionPoseLatency.clockOffsetNanos == 0L) { "unknown must not masquerade as an offset" }
        require(VisionPoseLatency.report().contains("UNKNOWN")) {
            "a report with no pong must say so rather than print a zero offset as fact"
        }

        // ---- a symmetric round trip recovers the offset ------------------------------------------
        // Several samples, not one, because that is how the estimator is meant to be used: the
        // *first* round trip through this path pays cold class-loading and JSON-parser init inside
        // the measured window, and lands ~200 ms late. That is not a flaw in the estimator, it is the
        // reason it keeps the minimum — but it does mean a single-sample assertion here would be
        // testing the JVM's warm-up, and would have been "fixed" by loosening the tolerance until it
        // no longer checked anything.
        repeat(6) { pong(handler, oneWayNanos = 5 * MILLIS, holdNanos = 2 * MILLIS) }
        require(VisionPoseLatency.offsetKnown) { "a pong must establish the offset" }
        val error = abs(VisionPoseLatency.clockOffsetNanos - TRUE_OFFSET_NANOS)
        // 20 ms is loose against the 5 ms path but tight against every structural error this can have:
        // a sign slip is out by twice the offset (~41 minutes), a missing halving by the offset itself,
        // and swapping the head's two instants by the hold. Host scheduling noise is what is left.
        require(error < 20 * MILLIS) {
            "recovered offset is off by ${error / 1e6} ms — expected ~0 on a symmetric path"
        }

        // The head's own hold must not be charged to the network.
        val rtt = VisionPoseLatency.bestRoundTripNanos
        require(abs(rtt - 10 * MILLIS) < 12 * MILLIS) {
            "round trip should be ~10 ms (two 5 ms crossings, hold excluded), got ${rtt / 1e6} ms"
        }

        // ---- a congested sample must not displace a clean one -----------------------------------
        val cleanOffset = VisionPoseLatency.clockOffsetNanos
        pong(handler, oneWayNanos = 150 * MILLIS, holdNanos = 1 * MILLIS)
        require(VisionPoseLatency.clockOffsetNanos == cleanOffset) {
            "a slower round trip replaced the offset: the estimator must keep the minimum-RTT sample, " +
                "or a contended link estimates the contention rather than the offset"
        }

        // ---- refusals ---------------------------------------------------------------------------
        val before = VisionPoseLatency.bestRoundTripNanos
        handler(pongJson(hostSend = 42L, headRecv = 1L, headSend = 2L))
        require(VisionPoseLatency.bestRoundTripNanos == before) {
            "an unsolicited pong must be ignored — otherwise anything on the bus can move the clock"
        }

        // ---- the device's half round-trips through the wire --------------------------------------
        handler(latencyJson())
        val spans = VisionPoseLatency.deviceSpans
        require(spans.size == 2) { "expected two device spans, got ${spans.keys}" }
        val jitter = spans["head: jitter buffer hold (deliberate)"]
            ?: error("the jitter-buffer span did not survive the wire: ${spans.keys}")
        require(abs(jitter.p50Millis - 33.4) < 0.01) { "p50 lost: ${jitter.p50Millis}" }
        require(jitter.n == 900) { "sample count lost: ${jitter.n}" }

        // ---- host spans are recorded and summarised ----------------------------------------------
        VisionPoseLatency.record(VisionPoseLatency.LATCH_TO_SUBMIT, 4 * MILLIS)
        VisionPoseLatency.record(VisionPoseLatency.LATCH_TO_SUBMIT, 8 * MILLIS)
        VisionPoseLatency.record(VisionPoseLatency.SUBMIT_TO_ENCODED, 11 * MILLIS)
        // A negative span is a mis-attribution, and must be dropped rather than counted as zero —
        // counting it would quietly pull every percentile down.
        VisionPoseLatency.record(VisionPoseLatency.SUBMIT_TO_ENCODED, -5 * MILLIS)

        // ---- the readout names every stage, including what it cannot see -------------------------
        val report = VisionPoseLatency.report()
        listOf(
            VisionPoseLatency.POSE_AGE_AT_LATCH,
            VisionPoseLatency.LATCH_TO_SUBMIT,
            VisionPoseLatency.SUBMIT_TO_ENCODED,
            "head: jitter buffer hold (deliberate)",
            "compositor frame",
        ).forEach { needle ->
            require(report.contains(needle)) { "the report omits '$needle':\n$report" }
        }
        require(!report.contains("UNKNOWN")) { "the offset is known by now" }
        require(Regex("""submit to encoded[^\n]*n=1""").containsMatchIn(report)) {
            "the negative span was counted; it must be dropped:\n$report"
        }

        println(report)
        println("VisionPoseLatencySmokeTest ok")
    }