Iris's ask after using the Compose bench build on her phone: the old scroll phase used animateScrollBy, which can only ever cover the fixed distance/time it's given, so it never flings the way a real fast swipe does. BenchRun.run now has four phases: fling (8 flings out + 8 back through the list's own FlingBehavior at 12,000px/s), stream (unchanged), type (600 fixed characters into the real composer TextFieldValue, then deleted, to exercise wrapping and the transcript being pushed upward), and keyboard (five show/hide cycles via WindowInsetsControllerCompat, each confirmed by isImeVisible rather than assumed). FrameStats.markPhase/phaseLines slice the same FrameMetrics recording by phase rather than running a second recorder; debugReport gains a phaseFrames section ahead of the existing whole-run frames/accounting/ work sections, which are otherwise unchanged. Also fixes a pre-existing, unrelated break in MainActivity.kt's benchSessionSummary() -- missing several SessionSummary constructor arguments from an earlier change -- since it blocked compileBenchKotlin outright. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
185 lines
7.5 KiB
Kotlin
185 lines
7.5 KiB
Kotlin
package com.example.aiapp
|
|
|
|
import android.content.ClipData
|
|
import android.content.ClipboardManager
|
|
import android.content.Context
|
|
import androidx.core.content.getSystemService
|
|
import java.util.concurrent.ConcurrentHashMap
|
|
import java.util.concurrent.atomic.AtomicLong
|
|
|
|
/**
|
|
* Counters and timers for the work the transcript does, for the readout behind the debug button.
|
|
*
|
|
* Here because the emulator cannot answer the question this is for. Its own scroll sits at the same
|
|
* frame times as the stock Settings app -- 21ms at the median for both -- so every app-level cost
|
|
* is under the floor of what it can measure. Counts do not have that problem: how many times a row
|
|
* was composed, or a reply parsed, is the same number on any machine, and it is the number that
|
|
* says whether the work is proportional to what is on screen or to everything ever loaded.
|
|
*
|
|
* Always on rather than behind a build flag. What is measured is an atomic increment on paths that
|
|
* already allocate lists and parse markdown, and a counter that is only compiled into the build
|
|
* nobody is holding when it is slow is not an instrument.
|
|
*/
|
|
object DebugStats {
|
|
private val counts = ConcurrentHashMap<String, AtomicLong>()
|
|
private val nanos = ConcurrentHashMap<String, AtomicLong>()
|
|
private val worst = ConcurrentHashMap<String, AtomicLong>()
|
|
|
|
private fun at(map: ConcurrentHashMap<String, AtomicLong>, name: String) =
|
|
map.computeIfAbsent(name) { AtomicLong() }
|
|
|
|
fun count(name: String, by: Long = 1) {
|
|
at(counts, name).addAndGet(by)
|
|
}
|
|
|
|
/** Keeps [name] at the largest value it has been given, for a high-water mark. */
|
|
fun atLeast(name: String, value: Long) {
|
|
val slot = at(counts, name)
|
|
while (true) {
|
|
val had = slot.get()
|
|
if (value <= had || slot.compareAndSet(had, value)) break
|
|
}
|
|
}
|
|
|
|
/** Records one occurrence of [name] that took [elapsed] nanoseconds. */
|
|
fun record(name: String, elapsed: Long) {
|
|
count(name)
|
|
at(nanos, name).addAndGet(elapsed)
|
|
val slot = at(worst, name)
|
|
while (true) {
|
|
val had = slot.get()
|
|
if (elapsed <= had || slot.compareAndSet(had, elapsed)) break
|
|
}
|
|
}
|
|
|
|
fun <T> timed(name: String, body: () -> T): T {
|
|
val started = System.nanoTime()
|
|
try {
|
|
return body()
|
|
} finally {
|
|
record(name, System.nanoTime() - started)
|
|
}
|
|
}
|
|
|
|
fun reset() {
|
|
counts.clear()
|
|
nanos.clear()
|
|
worst.clear()
|
|
}
|
|
|
|
/** One line per counter: how many, how long in total, and the worst single one. */
|
|
fun lines(): List<String> =
|
|
counts.keys.sorted().map { name ->
|
|
val n = counts[name]?.get() ?: 0
|
|
val total = nanos[name]?.get() ?: 0
|
|
if (total == 0L) " $name: $n"
|
|
else
|
|
" $name: $n, ${ms(total)}ms total, ${ms(total / n.coerceAtLeast(1))}ms mean," +
|
|
" ${ms(worst[name]?.get() ?: 0)}ms worst"
|
|
}
|
|
|
|
/** How long everything named [name] took in total, or zero if it never happened. */
|
|
fun nanosOf(name: String): Long = nanos[name]?.get() ?: 0
|
|
|
|
private fun ms(nanos: Long) = "%.1f".format(nanos / 1_000_000.0)
|
|
}
|
|
|
|
/**
|
|
* How much of the frame's draw phase is this app's own work, and how much is not.
|
|
*
|
|
* The draw phase is where Compose's measurement lands as well as its recording -- the platform
|
|
* calls `measureAndLayout()` from `dispatchDraw` -- so "draw is high" has never said which of three
|
|
* different things is high. The transcript times its own measure, placement and recording, and this
|
|
* is the subtraction. What is left over is the framework's per-frame bookkeeping after a layout,
|
|
* which grows with how many nodes are alive rather than how many are on screen.
|
|
*
|
|
* Per frame rather than in total, because the budget it has to fit in is per frame. The recordings
|
|
* are not themselves per-frame, so these are shares of an average frame.
|
|
*/
|
|
fun drawAccounting(drawNanos: Long, frames: Int): List<String> {
|
|
if (frames == 0 || drawNanos == 0L) return emptyList()
|
|
val measure = DebugStats.nanosOf("measure: the whole transcript")
|
|
val place = DebugStats.nanosOf("place: the whole transcript")
|
|
// The rows and blocks record *inside* this one, so adding them too would count them twice.
|
|
val record = DebugStats.nanosOf("draw: the whole transcript")
|
|
val ours = measure + place + record
|
|
val rest = (drawNanos - ours).coerceAtLeast(0)
|
|
fun per(n: Long) = "%.2f".format(n / 1_000_000.0 / frames)
|
|
return listOf(
|
|
" draw phase ${per(drawNanos)}ms per frame, of which:",
|
|
" the transcript: ${per(ours)}ms" +
|
|
" (measure ${per(measure)}, place ${per(place)}, record ${per(record)})",
|
|
" everything else: ${per(rest)}ms" +
|
|
" (${if (drawNanos == 0L) "n/a" else "${rest * 100 / drawNanos}%"})",
|
|
)
|
|
}
|
|
|
|
/**
|
|
* Everything the debug button copies: what the device is, what the transcript is holding, where the
|
|
* frames went, and what the app did to produce them.
|
|
*
|
|
* Written for somebody to paste into a conversation, so it is plain text with the units on every
|
|
* number -- a report whose reader has to ask what the columns mean costs another round trip.
|
|
*/
|
|
fun debugReport(
|
|
device: String,
|
|
transcript: List<String>,
|
|
frames: List<String>,
|
|
accounting: List<String>,
|
|
crash: String?,
|
|
/**
|
|
* P0's benchmark-only measurements (process CPU time, peak RSS, battery current) -- empty on
|
|
* every path but [BenchRun.runP0Benchmark], which is the only caller that has them. A section
|
|
* heading only appears when there is something to put under it, so an ordinary copy from the
|
|
* render-report button reads exactly as it did before this existed.
|
|
*/
|
|
extra: List<String> = emptyList(),
|
|
/**
|
|
* Bench v2's per-phase frame accounting ([FrameStats.phaseLines]) --
|
|
* fling/stream/type/keyboard, each a slice of the same frames the whole-run sections below
|
|
* still cover in full. Empty on every path but the scripted bench run, same reasoning as
|
|
* [extra].
|
|
*/
|
|
phaseFrames: List<String> = emptyList(),
|
|
): String = buildString {
|
|
appendLine("ai-app render report")
|
|
appendLine(device)
|
|
appendLine()
|
|
// First, because a crash outranks every timing below it and the reader should not have to
|
|
// scroll past two screens of counters to find out the app fell over.
|
|
if (crash != null) {
|
|
appendLine("last crash:")
|
|
crash.trimEnd().lines().forEach { appendLine(" $it") }
|
|
appendLine()
|
|
}
|
|
appendLine("transcript:")
|
|
transcript.forEach { appendLine(it) }
|
|
appendLine()
|
|
if (phaseFrames.isNotEmpty()) {
|
|
appendLine("per phase:")
|
|
phaseFrames.forEach { appendLine(it) }
|
|
appendLine()
|
|
}
|
|
appendLine("frames:")
|
|
frames.forEach { appendLine(it) }
|
|
appendLine()
|
|
if (accounting.isNotEmpty()) {
|
|
appendLine("where the draw phase went:")
|
|
accounting.forEach { appendLine(it) }
|
|
appendLine()
|
|
}
|
|
appendLine("work since this was last copied:")
|
|
val work = DebugStats.lines()
|
|
if (work.isEmpty()) appendLine(" nothing recorded") else work.forEach { appendLine(it) }
|
|
if (extra.isNotEmpty()) {
|
|
appendLine()
|
|
appendLine("bench:")
|
|
extra.forEach { appendLine(it) }
|
|
}
|
|
}
|
|
|
|
/** Puts [text] on the clipboard under [label], which is what the system offers as its name. */
|
|
fun Context.copyToClipboard(label: String, text: String) {
|
|
getSystemService<ClipboardManager>()?.setPrimaryClip(ClipData.newPlainText(label, text))
|
|
}
|