Why Method Tracing Lies: The Observer Effect in Android Profiling

Instrumenting profilers slow down the code they measure, creating fake bottlenecks. Learn which tool to trust for which question.

You open a method trace of a janky list screen. Three tiny helpers sit at the top of the flame chart, each one a few lines long. You spend an afternoon rewriting them, rebuild, scroll again, and the jank is exactly where it was.

Nothing was wrong with your reading skills. The profiler changed the program it was watching, and then reported on the changed program. This post explains why that happens, how each family of Android profiling tools distorts reality in its own way, and a workflow that keeps you from chasing ghosts.

The scenarios below are composites built for illustration. The numbers in the charts are illustrative too; the shapes are what matter.

1. The observer effect: measuring changes the measurement

Every measurement needs a probe, and probes cost something. In physics that is a curiosity. In performance work it is a daily hazard, because the probe’s cost is rarely spread evenly across your code. It lands wherever the probe fires most often.

That uneven distribution is the whole problem. A profiler does not add a flat tax to your app. It adds a tax proportional to how often a particular event happens, so code that does little work but runs constantly gets punished the most.

Read the chart as a warning label. Under tracing, isVisible() and clamp() appear to own more than half of the frame. Without the profiler, they cost almost nothing. The method that actually burns the time, decodeBitmap(), gets diluted because everything around it got slower.

2. Instrumented method tracing: a hook on every door

An instrumenting profiler records an event when a method is entered and another when it returns. In Android Studio this is the “trace Java/Kotlin methods” style of recording. You get a complete, ordered call history, which is wonderful for answering “what called what, and how many times”.

The cost model is where it bites. Each entry and exit does bookkeeping: reading a clock, writing a record, sometimes taking a lock. That fixed cost is small, but it is paid per call. A method whose body takes a microsecond and a hook that takes a similar amount means the traced time is roughly double reality. A method that takes ten milliseconds barely notices.

Instrumentation can also alter how the runtime executes your code. Depending on the device and OS version, tracing may keep methods on slower execution paths or interfere with optimizations such as inlining, which means the trace can describe a program that your users never run.

Here is the kind of code that fools it:

/** App-specific loader, not android.graphics.ImageDecoder. Decoding here is deliberately synchronous. */
fun interface BitmapLoader {
    fun load(uri: Uri, targetWidth: Int): Bitmap
}

class FeedBinder(
    private val viewport: Rect,
    private val loader: BitmapLoader,
) {
    fun bind(holder: RowHolder, item: FeedItem) {
        holder.title.text = item.title
        if (!isVisible(item.bounds)) return          // called for every row, every frame
        val w = clamp(item.width, MIN_W, MAX_W)      // called for every row, every frame
        holder.image.setImageBitmap(loader.load(item.uri, w)) // the real cost: a main-thread decode
    }

    private fun isVisible(bounds: Rect): Boolean = Rect.intersects(viewport, bounds)

    private fun clamp(value: Int, lo: Int, hi: Int): Int = value.coerceIn(lo, hi)
}

isVisible and clamp are textbook small functions. In a method trace, their call counts are enormous and their per-call overhead is mostly hook cost. The unmistakable bug, a bitmap decode on the main thread, is one tall call that looks unremarkable next to the forest of hooked calls around it.

Failure modes worth recognizing:

• The inverted ranking. Self-time rankings reorder themselves. Micro-optimizing the top three entries yields no change in a release build.
• The phantom jank. A debug-instrumented run drops frames that the production build never drops, so you “fix” a problem users do not have.
• The vanished race. Slowing every thread changes interleavings. A contention bug that reproduces in the wild can disappear under tracing, and a different one can appear.
• The wrong build. Tracing a debuggable build with shrinking and optimization disabled compounds all of the above.

Use instrumented tracing for what it is excellent at: call counts, call order, and understanding unfamiliar code. Do not use its durations as ground truth for small methods.

3. Sampling profilers: cheaper, but they can miss quick events

A sampling profiler stops asking about every call. Instead, at a fixed interval it peeks at the thread’s current stack and records what it sees. Over many samples, the functions that occupy the stack most often rise to the top.

Overhead is low and, importantly, mostly independent of how many methods your code calls. It depends on the sampling rate. That removes the distortion against tiny methods, which is exactly why a sampled profile of the screen above would point at the bitmap decode.

The trade-off is in the picture. Anything that begins and ends between two ticks is invisible to that run. The chart uses a coarse ten-millisecond interval to make the effect obvious; real profilers sample faster, but the principle holds for any fixed interval, and a sampler’s accuracy for rare, short events improves only with more samples, which means more runs.

Failure modes:

• Missing the spike you came for. A two-millisecond stall that causes one dropped frame may never be sampled in a short capture, yet it is exactly what the user perceives as stutter.
• Over-trusting a single run. One short sampled capture is an anecdote. Confidence comes from aggregating several.
• Misreading “not on the stack”. A thread that is blocked or waiting for a lock may not show up as the work you expect. Sampling answers where is the code spending CPU, not why was the thread not running.
• Bias at safe points. Some samplers can only observe a thread at certain points in execution, which can skew where time appears to land.

4. System-level tracing: the scheduler’s own diary

A system trace takes a different approach. Rather than watching your methods, it records events emitted by the kernel and framework: which thread ran on which CPU core, when it was preempted, when it was runnable but waiting, when frames were produced, when binder transactions started and ended. In Android Studio this surfaces as a system trace; underneath it is the Perfetto ecosystem.

Because the events come from instrumentation points that already exist in the kernel and framework, the overhead is very low. Crucially, it does not depend on how many methods your code calls.

What this view gives you is something neither of the other tools can: an explanation for time that was not spent running your code. In the schematic, the main thread is ready to run but has no core, so a method trace would charge that waiting to whatever function happened to be executing, and a sampler might see nothing at all.

You can also make the trace speak your app’s language by adding your own named sections. The key idiom is to keep them cheap and to make them survive coroutines. Both helpers below go through the AndroidX tracing library rather than android.os.Trace directly: the platform's async-section calls only exist from API 29, while the AndroidX wrapper handles older devices for you, so the code does not crash with a NoSuchMethodError on them.

import androidx.tracing.Trace
import androidx.tracing.trace
import java.util.concurrent.atomic.AtomicInteger

private val cookies = AtomicInteger()

/** Synchronous section: begin and end are guaranteed to run on the same thread. */
inline fun <T> section(name: String, block: () -> T): T = trace(name, block)

/**
 * Section that may suspend. Thread-local begin/end pairs break when a coroutine
 * resumes on another thread, so use an async section keyed by a unique cookie instead.
 */
suspend inline fun <T> asyncSection(name: String, crossinline block: suspend () -> T): T {
    val cookie = cookies.incrementAndGet()
    Trace.beginAsyncSection(name, cookie)
    try {
        return block()
    } finally {
        Trace.endAsyncSection(name, cookie)
    }
}

class FeedBinder(private val loader: BitmapLoader) {
    fun bind(holder: RowHolder, item: FeedItem) = section("Feed.bind") {
        holder.title.text = item.title
        holder.image.setImageBitmap(section("Feed.decode") { loader.load(item.uri, item.width) })
    }
}

Failure modes:

• Mismatched sections across suspension points. Using begin/end around a suspend call can end the section on a different thread than the one that began it, which corrupts the track. That is why the example above uses an async variant.
• Expensive labels. Building a name with string templates inside a hot loop allocates on every call, even when no trace is running. Prefer constant names, or guard dynamic ones behind Trace.isEnabled() (available on the AndroidX Trace wrapper too).
• Section names that explode. Putting IDs in names ("bind row 48213") floods the trace with unique labels that cannot be aggregated.
• Expecting line-level answers. A system trace tells you when and who, and where your own sections begin and end. It will not rank your functions by self-time.

5. The comparison, in one glance

A short way to remember it: instrumented tracing is the most detailed and the most distorting, sampling is the best at finding where CPU goes, and system tracing is the best at explaining why a thread was not making progress.

6. A workflow that keeps you honest

1. Reproduce. Fix the variables first. Use a release-like build (a profileable release build lets the tools attach without turning your app into a debug build), a fixed device, and a scripted interaction. If you cannot reproduce the slowness on demand, no profiler will rescue you.

2. Trace at the system level. Start wide. Find the frames that missed their deadline and ask what the main and render threads were doing. Often the answer is not “slow code” at all: it is a lock, a binder call, a garbage collection, or simple CPU starvation. Those are invisible to the other two tools, so ruling them in or out first saves enormous effort.

3. Narrow down. Add named sections around the suspects, re-record, and see which section actually owns the long slice. Making this repeatable is worth a few lines of code:

@OptIn(ExperimentalMetricApi::class)
@RunWith(AndroidJUnit4::class)
class FeedScrollBenchmark {
    @get:Rule
    val rule = MacrobenchmarkRule()

    @Test
    fun scrollFeed() = rule.measureRepeated(
        packageName = "com.example.feed",
        metrics = listOf(
            FrameTimingMetric(),
            // bind() runs many times per scroll, so sum the slices instead of taking the first one
            TraceSectionMetric("Feed.bind", TraceSectionMetric.Mode.Sum),
        ),
        iterations = 10,
        startupMode = StartupMode.WARM,
        compilationMode = CompilationMode.DEFAULT,
    ) {
        pressHome()
        startActivityAndWait()

        val selector = By.res(packageName, "feed_list")
        // Wait for the list to exist; findObject() returns null if the screen is not ready yet.
        check(device.wait(Until.hasObject(selector), 5_000)) { "feed_list never appeared" }
        val feed = device.findObject(selector)
        feed.setGestureMargin(device.displayWidth / 5) // keep the fling away from system gesture zones
        feed.fling(Direction.DOWN)
        device.waitForIdle()
    }
}

Ten iterations give you a distribution instead of a single lucky or unlucky run, which is also what makes later sampling trustworthy.

4. Sample, only if needed. Once you know which scenario and which section is slow, a sampled profile of that isolated scenario tells you which code inside it is hot. If you want to quantify how much time a thread spent runnable rather than running, the trace itself can answer. The exact state names depend on the tool version, and is_main_thread can be null in traces where the main thread could not be identified, so check yours:

-- Perfetto trace processor: time the main thread spent runnable but off-CPU
SELECT SUM(ts.dur) / 1e6 AS runnable_ms
FROM thread_state ts
JOIN thread USING (utid)
JOIN process USING (upid)
WHERE process.name = 'com.example.feed'
  AND thread.is_main_thread = 1         -- joined on upid, so a recycled pid cannot leak in
  AND ts.state IN ('R', 'R+');

5. Re-measure after every fix, with the same tool that found it. If a system trace showed the problem, a system trace should show it gone. Verifying a system-level fix with an instrumented trace reintroduces the very distortion you were trying to avoid.

A short decision list

• “Who calls this, and how often?” Instrumented tracing, and ignore absolute durations of tiny methods.
• “Where does the CPU time go?” Sampling, over several runs.
• “Why did this frame miss its deadline?” System tracing, first.
• “Did my fix work?” The same tool and the same scripted scenario you started with.

The takeaway

No profiler is lying out of malice. Each one is answering a question truthfully, just not always the question you thought you asked. Instrumented tracing answers what happened and in what order, sampling answers where the CPU went, and system tracing answers what the machine was doing. When a trace’s top entry is a three-line function, suspect the probe before you suspect the code.

📱 Level Up Your Android System Design Game

If you’re prepping for a senior Android role and system design rounds are the part that makes you sweat, I highly recommend “Mastering Android System Design” — a 37-chapter playbook that treats Android like the constrained runtime it actually is, not a small server. It covers Binder IPC, ART’s GC, process death, and background execution limits, then walks through the CRDDS interview framework and 13 full worked case studies (chat, ride-hailing, video streaming, payments, and more) carried end-to-end through API design, offline sync, and the Android-specific edge cases that trip candidates up mid-interview.

• E-book: Available on Google Play
• Kindle Edition: Available on Amazon
• Topmate: Available on Topmate
• Also available in Paperback & Hardcover.

---

Originally published on Medium.