Handler (Part 4): How to Locate Handler Lag? From Slow Delivery to Slow Dispatch

In real troubleshooting, we rarely encounter a clean problem like:

What is the principle of Handler?

More often, we see:

UI not refreshing;
System service responding slowly;
Callback never arriving;
"Slow delivery" appearing in the log;
"Slow dispatch" appearing in the log;
A thread in system_server seems stuck;
A Binder call keeps waiting for a result.

The worst conclusion at this point is:

The Handler is stuck.

Because this statement has no diagnostic value.

A better breakdown is:

Did the business logic actually call post/sendMessage, and is the target Handler correct?
Was the enqueue request accepted by the MessageQueue at that time?
Was the message removed or cleaned up by lifecycle after being accepted?
Which Looper does this Handler hold, and which Thread is that Looper bound to?
Did the actual dispatch start later than Message.when?
Is the current dispatch interval too long?

The first three articles have already established the mechanisms:

Part 1:
    The calling thread is only responsible for enqueuing; the target Looper thread is responsible for execution.

Part 2:
    MessageQueue is not a regular queue; it considers when, barriers, nativePollOnce, and quit.

Part 3:
    Handler troubleshooting must first locate the Looper's thread; you cannot just say "main thread" or "system_server".

This article turns these mechanisms into a troubleshooting path.

There is only one core question:

When a Handler task does not execute as expected, how do you determine which stage it is stuck in?

The source code in this article references the android-16.0.0_r4 tag of Android 16 QPR2. The main text only discusses the stable mechanisms of Handler and does not expand on version-specific implementation differences.

First, separate the normal main chain from the interruption side paths:

Normal main chain:
  Post
  -> Enqueue
  -> Wait
  -> Retrieve
  -> Dispatch and Execute

Post:
  Did post/sendMessage occur? Is the target Handler correct?

Enqueue:
  Was the enqueue request accepted by the MessageQueue at that time? What is the 'when' value?

Wait:
  Has 'when' arrived? What are the evidences for preceding messages, thread scheduling, and barriers?

Retrieve:
  Did MessageQueue.next() return this Message?

Dispatch and Execute:
  Did dispatchMessage choose Runnable, Handler.Callback, or handleMessage?
  Is the actual callback spending time on computation, locks, I/O, Binder, or native/HAL?

Interruption side paths:
  The business logic never posted;
  The enqueue request was rejected;
  It was removed after enqueuing;
  The task was cancelled after the owner's lifecycle ended;
  Looper / HandlerThread quit, causing some unexecuted messages to be discarded.

The way to read this diagram is simple:

Don't start from "stuck".
Start from the message lifecycle.
Prove only one segment at a time.

1. Why Can't We Say "The Handler is Stuck"?

Because the same symptom can originate from completely different stages.

For example, "UI not refreshing" could be:

The business code never called mainHandler.post.
post was called, but returned false.
The 'when' of postDelayed hasn't arrived yet.
It was removed by lifecycle cleanup after enqueuing.
The main thread is executing a previous time-consuming message.
The main thread is runnable but hasn't gotten CPU for a long time.
The current Runnable has started executing but is waiting for a lock internally.
A synchronous Binder call was initiated inside the current Runnable and is being held up by the peer.
In scenarios with clear evidence like UI traversal, normal synchronous messages are delayed by barriers.
The target HandlerThread has already quit.

The evidence for these causes is completely different.

If you only write:

Handler did not execute.

The reader doesn't know what to look at next.

If you write:

post returned true, indicating this enqueue request was accepted by the target queue at that time;
Looper slow log shows Slow delivery;
Perfetto shows the target thread was continuously executing a previous callback during this period;
Therefore, this is not a failure to post the message, but the preceding message occupied the Looper, causing subsequent messages to wait too long.

This is a verifiable conclusion.

Troubleshooting articles must upgrade from "symptom description" to "stage + evidence + conclusion".

2. How to Break Down the Troubleshooting Lifecycle of a Message?

It is recommended to always check along a fixed normal main chain, then separately confirm the interruption side paths. Do not treat quit as the "last step" after every normal message execution.

Main Chain Stage 1: Post

Was post/sendMessage called?
Which thread is the caller?
Is the target Handler the expected one?

This stage mainly relies on business logs, trace points, source code paths, and return values.

Main Chain Stage 2: Enqueue

Is Message.target set to the target Handler?
Is Message.when the current time or a future time?
Is the Message asynchronous?
Is the return value of post/sendMessage true?

This stage needs to combine Handler.enqueueMessage(), MessageQueue.enqueueMessage(), and business wrappers.

Main Chain Stage 3: Wait

Has 'when' not arrived yet?
Is there a long message ahead?
Is the thread delayed by system scheduling?
Is there evidence of synchronous barriers like UI traversal call chains or barrier anomalies?
When the thread stack is at nativePollOnce, what are the enqueue result, 'when', barrier, and current queue selection state?

This stage corresponds to Slow delivery, Perfetto timeline, preceding messages, thread scheduling, and queue state. Synchronous barriers are a branch that requires evidence to establish; they are not the default guess when a normal business Handler is late.

Main Chain Stage 4: Retrieve

Did MessageQueue.next() return this Message?
Did the Looper enter dispatch?

This stage usually needs to be confirmed via Looper logs, trace sections, or lightweight logs you add yourself.

Main Chain Stage 5: Dispatch and Execute

Did dispatchMessage choose Runnable, Handler.Callback, or handleMessage?
Does the callback internally involve I/O, lock waiting, synchronous Binder calls, native/HAL blocking, or complex computation?

Slow dispatch measures the entire interval from dispatchStart to dispatchEnd, which includes both the path selection of dispatchMessage() and the actual callback execution. There is no need to forcibly split this into two consecutive stages in the overall lifecycle. This stage corresponds to thread dumps, Perfetto slices, binder traces, lock owners, and native stacks.

Finally, separately check the side paths that interrupt the main chain:

Was the post/sendMessage rejected by the queue?
Did removeCallbacks/removeMessages/removeCallbacksAndMessages clear the message?
Was the task actively cancelled after the owner's lifecycle ended?
Has the Looper / HandlerThread already quit?

These branches might reject the task before enqueuing, or prevent the task from completing after enqueuing; they are not the normal end of "exit after execution".

3. How to Confirm Which is the Target Thread?

First, go back to the three questions from Part 3:

Which Looper does this Handler hold?
Which Thread is this Looper bound to?
What task is this Thread responsible for in the system design?

Common confirmation methods:

Static location:
    Look at the Looper passed in during Handler construction, and where that Looper was created.

Runtime location:
    Look at the in-process thread list, thread names, Looper logs, and target thread stack.

Timeline location:
    Look at whether the target thread in Perfetto was in running, runnable, or blocked state around the message's due time.

Related commands are collected in the appendix at the end of the article. kill -3 will cause the target process to generate a thread dump and incur additional overhead; stop/start will restart the Android Framework. They can only be used in debugging environments where perturbation is allowed; do not treat them as side-effect-free online read operations.

If it's the App main thread:

The target thread is usually 'main'.
Look at ActivityThread, Choreographer, ViewRootImpl, and the main thread stack.

If it's system_server:

Don't just look at the process name.
Continue looking at the thread name:
    main
    android.ui
    android.display
    android.anim
    android.io
    Binder:<pid>_x
    Other service-created HandlerThreads

If the current stack is in a Binder thread:

It is currently or was previously executing server-side Binder entry code;
The entry might process directly, or post subsequent state handling to a Handler.

Therefore, you must simultaneously confirm:
    Where is the Binder entry currently executing;
    Has it been posted to the target Handler;
    Is the Binder thread still synchronously waiting for the Handler result.

Only after locating the target thread does discussing message waiting or execution become meaningful.

4. How to Confirm if a Message was Posted and Enqueued?

First, check if the call chain actually occurred:

Did the business entry point reach post/sendMessage?
Was there a conditional branch that returned early?
Was the target Handler null?
Has the target Handler been replaced?

Then look at the return value:

boolean ok = handler.post(runnable);

The direct mechanism meaning of ok == false is: this enqueue request failed. For a normally constructed Handler, the most common direct reason is that the target MessageQueue is quitting or has already quit.

Direct mechanism reason:
    The MessageQueue rejected the enqueue at that time, usually because the Looper is quitting.

Next, trace the business root cause:
    Why is the code still posting to a queue that is quitting?
    Is the start/shutdown order of HandlerThread wrong?
    Is an old Handler still being held after the owner is destroyed?
    Is there a late asynchronous callback?
    Is there a race condition between closing the queue and posting the task?

"The component lifecycle has ended" does not directly cause post() to return false. For example, when posting to a MainLooper Handler, even if the Activity is destroyed, the queue might still accept the request and return true; it's just that this work is no longer valid for the business. You must separate "why the queue rejected" and "why the code is still posting" into two layers of conclusions.

Source code entry points:

• Handler.post() return value description
• AOSP MessageQueue enqueue and quit implementation

ok == true only means this enqueue request was accepted by the MessageQueue at that moment. It does not mean the message is still in the queue, nor does it guarantee eventual execution. It might subsequently be removed by removeCallbacks(), removeMessages(), removeCallbacksAndMessages(), or lifecycle cleanup, or it might encounter a Looper quit.

So don't just write in the log:

post updateUi

A better way to write it is:

post updateUi to mainHandler, result=true, caller=worker-1, uptime=123456

For important system paths, the posting side and execution side must be correlated using the same identifier. Regular traceBegin/traceEnd can only cover the synchronous interval of the current thread calling post(), and cannot automatically connect to the Runnable executed later on the target thread.

You can use async trace, Perfetto flow, or logs that simultaneously record sequence + uptime to establish the correlation. For rejections, cancellations, and normal executions, you must also ensure the correlation interval is closed only once; the complete wrapper is in the appendix "Appendix C: How to Correlate Handler Post and Execution".

5. What Are the Possible Reasons a Message Isn't Retrieved?

If the enqueue request was accepted, but the task hasn't executed for a long time, don't immediately look inside the callback. The message might not have been retrieved by MessageQueue.next() yet, or it might have already been removed.

Common reasons:

1. 'when' hasn't arrived
    postDelayed, sendMessageAtTime, and retry backoffs can all set 'when' in the future.

2. Preceding message is too slow
    The target Looper can only dispatch one Message at a time.

3. Thread scheduling delay
    The thread is runnable but hasn't gotten CPU for a long time.

4. Removed after enqueuing or cancelled by lifecycle
    removeCallbacks/removeMessages, component destruction cleanup can all make the task disappear.

5. Synchronous barrier scenarios with evidence
    Normal synchronous messages in paths like UI traversal might wait; only when you see relevant call chains,
    queue state, or barrier anomaly evidence should you continue to confirm if the barrier was removed by token.

6. Queue is quitting
    New enqueue requests will fail; future messages or already-cleaned messages will not continue waiting for execution.

nativePollOnce should not be listed alongside these root causes. When the thread stack is here, it usually means the MessageQueue currently has no executable message selected and is waiting based on timeout, wake, or registered fd events. If an expired message was accepted for enqueuing and changes the current wait result, the normal path will nativeWake(). Therefore, after seeing a poll stack, you should continue to check back on the enqueue result, when, removal, barrier, and quit status; you cannot conclude the thread is "stuck in poll" based solely on this stack frame.

One of the key log evidences here is Slow delivery.

It indicates:

The message's scheduled execution time has arrived,
but the actual dispatch start time is too late.

That is, the delay from the scheduled time to the actual start of execution is too long. This interval usually includes queue waiting, and might also include scheduling delays like the target thread not getting CPU in time.

6. What is Slow Delivery?

Android's Looper.loopOnce() calculates time before and after dispatch.

It can be abstracted like this:

Message msg = queue.next();

long dispatchStart = now();
dispatchMessage(msg);
long dispatchEnd = now();

if (dispatchStart - msg.when > slowDeliveryThreshold) {
    log("Slow delivery");
}

if (dispatchEnd - dispatchStart > slowDispatchThreshold) {
    log("Slow dispatch");
}

Source code entry points:

• Looper.loopOnce() slow delivery and slow dispatch statistics
• showSlowLog() output format

The timeline for Slow delivery is:

Message.when
   |
   |  Start execution delay interval
   v
dispatchStart

Definition:

slow delivery = dispatchStart - Message.when is too long

Its common causes are:

Preceding message execution took too long, possibly blocking on computation, I/O, locks, or synchronous Binder;
Continuous queue backlog, the target Looper cannot consume fast enough;
The thread is runnable, but hasn't gotten CPU for a long time;
Message.when was set unexpectedly;
In scenarios with clear evidence like UI traversal, synchronous barriers delayed normal synchronous messages.

Note: Slow delivery only proves the actual dispatch start time was later than Message.when by more than the threshold. It does not directly prove when the business called post(), nor can it alone prove the message stayed in the queue for the entire interval; it needs to be combined with post logs, return values, thread scheduling, and Perfetto timeline to reconstruct the cause. It certainly does not indicate that the current message itself executed slowly.

Important: Slow delivery / Slow dispatch are post-hoc evidence.

Slow delivery and Slow dispatch are not universal real-time monitoring evidence for all Handler problems.

• When a message hasn't started dispatch yet, there is no dispatchStart, so there might be no Slow delivery for this message;
• When a callback hasn't returned yet, there is no complete dispatchEnd, so the corresponding Slow dispatch log might not have been printed yet;
• If the slow log threshold is not enabled, or the duration does not exceed the threshold, slow logs will not appear.

Therefore, "no Slow log" cannot alone prove there is no waiting or no blocking. When a message hasn't started, look at post logs, queue/Looper logs, and Perfetto; when a callback is still stuck on locks, synchronous Binder, HAL, infinite loops, or long I/O, prioritize looking at Looper dispatch start, thread dump, current Perfetto slice, Binder timeline, and lock owner.

7. What is Slow Dispatch?

Slow dispatch looks at how long the callback itself took after the message started executing.

The timeline is:

dispatchStart
   |
   |  Execution time too long
   v
dispatchEnd

Definition:

slow dispatch = dispatchEnd - dispatchStart is too long

Common causes:

Runnable / handleMessage internally performed I/O;
Waiting for a lock;
Synchronous Binder call;
Waiting for Future / CountDownLatch;
Complex computation;
native/HAL blocking;
Synchronously calling another slow service inside the callback.

The investigation direction for Slow dispatch is inside the current callback.

At this point, a thread dump is very valuable because the target thread is executing this message. You need to see where it is stuck:

Java method stack;
Lock waiting;
BinderProxy.transact;
native methods;
File I/O;
Database or configuration read/write;
HAL calls;
Complex loops.

8. How to Compare Slow Delivery and Slow Dispatch?

Evidence	Calculation Interval	What it proves	Where to look next
Slow delivery	dispatchStart - Message.when	Target message started late	Preceding dispatch, queue backlog, thread scheduling, when; look at barriers if there are relevant call chains
Slow dispatch	dispatchEnd - dispatchStart	Current message executed long	Stack, locks, I/O, Binder, native inside the current Runnable / Callback / handleMessage

For example:

when=12:01:03.120, start=12:01:03.460, end=12:01:03.465
    -> delivery 340ms, dispatch 5ms: investigate the timeline before start.

when=12:01:03.120, start=12:01:03.122, end=12:01:03.320
    -> delivery 2ms, dispatch 198ms: investigate inside the current callback.

Both can also exceed the threshold simultaneously: a preceding message first made the current message late, and the current message itself executed for a long time. The conclusion must write out the two intervals separately, not merge them into one sentence like "Handler lag".

9. Why Does a Synchronous Binder Call Hold Up a Handler Thread?

In many Framework problems, the direct reason a Handler thread is slow is not slow Java code computation, but a synchronous Binder call.

Typical chain:

android.display Handler
  -> Executes some WindowManager callback
  -> Synchronous Binder call to another process or service
  -> Peer is slow / Peer is waiting for a lock / Binder thread pool is tight
  -> android.display is stuck waiting for transact to return
  -> All subsequent display messages experience slow delivery

For this type of problem, you need to look at both sides simultaneously:

Target Handler thread:
    Is it stuck at BinderProxy.transact or a native binder call?

Peer process or other threads in system_server:
    Who is handling this Binder?
    Is the peer also waiting for a lock, I/O, or another Binder?

Caller:
    Is it synchronously waiting for a return?
    Is it initiating a synchronous call on the main thread or a critical system thread?

If you only look at the Handler thread, you will see it "stuck in Binder". But the real root cause might be on the peer side.

So the evidence must be written as a chain:

android.display slow dispatch;
thread dump shows it is in a synchronous Binder call;
binder trace shows the target service processing took a long time;
target service thread stack shows waiting for a certain lock;
Therefore, android.display was held up by a synchronous Binder call, causing slow delivery for subsequent display messages.

10. Case Study: How to Diagnose UI Not Refreshing?

Don't directly write:

Main thread is stuck.

Break it down by lifecycle:

1. Was a refresh task actually posted?
    Check business logs, trace, post return value.

2. Is the target Handler MainLooper?
    Check the Handler creation site, whether Looper.getMainLooper() was explicitly used.

3. Is Message.when currently executable?
    Was postDelayed used, is there a retry backoff.

4. Is there Slow delivery?
    If yes, check preceding messages and Perfetto timeline.

5. What state was the main thread in during the waiting interval?
    Was it executing a preceding callback, runnable but not getting CPU, or at nativePollOnce because there was currently no executable message.

6. Is there evidence of a synchronous barrier?
    Only investigate further when UI traversal call chains, barrier tokens, or abnormal queue states are involved.

7. Is there Slow dispatch?
    If yes, check the internal stack of the current Runnable.

8. Where exactly is the main thread right now?
    Java stack, native stack, Binder, lock, I/O.

Example of a locatable conclusion:

The refresh Runnable was posted to MainLooper by worker-2 at 10:20:31.100; post returned true, indicating the enqueue request was accepted at that time;
Message.when is 10:20:31.100, postDelayed was not used;
logcat shows MainLooper Slow delivery, no corresponding Slow dispatch appeared;
Perfetto shows the main thread was continuously executing a previous ViewRootImpl callback from 10:20:31.090 to 10:20:31.430;
Therefore, this UI not refreshing is because the preceding main thread message executed too long, causing the refresh message to wait too long; it is not that the refresh Runnable itself executed slowly, nor that the message was not posted.

11. Case Study: What to Check First When system_server Service Response is Slow?

Don't directly write:

system_server is slow.

Break it down by thread:

1. Is the call a synchronous Binder or an asynchronous notification?
2. Which Binder thread in system_server received the request?
3. Did the service post the request to a Handler?
4. Does the target Handler hold the Looper for main, android.ui, android.display, android.io, or a self-created thread?
5. Is the Binder thread waiting for the Handler result?
6. Is the Handler thread experiencing Slow delivery or Slow dispatch?
7. Did the slowness occur before the Handler, in the Handler queue, or inside the Handler callback?

Typical conclusion template:

The App initiated a synchronous Binder request at 12:01:03.100;
system_server Binder:1234_5 received the request at 12:01:03.120 and posted it to the android.display Handler;
post returned true, indicating this enqueue request was accepted by the target queue at that time;
Perfetto shows android.display was continuously executing a previous WindowManager callback from 12:01:03.100 to 12:01:03.460;
Looper log shows Slow delivery, not Slow dispatch;
Therefore, the current problem is that the preceding message on android.display executed too long, causing subsequent messages to wait too long in the queue;
It is not that the message was not posted, nor that the current callback itself executed slowly.

If it is Slow dispatch, the conclusion needs to change direction:

android.display started dispatching the target message at 12:01:03.120;
It ended at 12:01:03.520;
thread dump shows it is synchronously calling a certain service inside the target callback;
binder trace shows the peer processing took 380ms;
Therefore, the problem is that the synchronous Binder call inside the current Handler callback was too slow.

12. How Should the Conclusion Be Written?

Don't write:

Handler is stuck.

Also don't just write:

Main thread is stuck.

Write it as:

Target message:
    Which message, what time, posted by whom.

Target thread:
    Which Looper it holds, which Thread this Looper is bound to.

Post result:
    post/sendMessage return value, whether the enqueue request was accepted at that time, whether it was removed afterwards.

Waiting evidence:
    when, slow delivery, preceding messages, thread scheduling, Perfetto timeline;
    Only write synchronous barrier when there is clear UI traversal or barrier anomaly evidence.

Execution evidence:
    slow dispatch, thread dump, Binder, locks, I/O, native stack.

Conclusion:
    Which stage of the normal main chain did the problem occur in, or which rejection/cancellation/exit side path interrupted it.

Fixed template:

The target message was posted at <time> by <calling thread> to <target Handler / Looper thread>;
post returned <true/false>;
Message.when is <time>;
<Evidence 1> indicates the enqueue request was <accepted/rejected> at that time, and afterwards <was not seen removed / was removed by path X / cannot be confirmed>;
<Evidence 2> indicates the target thread was in <preceding dispatch / runnable but not getting CPU /
currently no executable message and at nativePollOnce / lock waiting or Binder call inside current callback> during <time period>;
Looper log is <Slow delivery / Slow dispatch / No slow log>;
Therefore, the current problem is <cause> at <stage>,
not <excluded item 1>, nor <excluded item 2>.

This template is longer than "Handler is stuck", but it can guide the next step of fixing. Handler troubleshooting always starts from the normal main chain and interruption side paths:

Normal main chain:
    Post -> Enqueue -> Wait -> Retrieve -> Dispatch and Execute

Interruption side paths:
    Not posted / Enqueue rejected / Removed after enqueuing / Lifecycle cancellation / Looper quit

The most critical evidence boundaries among these are:

Slow delivery:
    Actual start time is too late relative to Message.when; check preceding messages, scheduling, when, and queue state.

Slow dispatch:
    The message itself executed too long; check inside the callback, locks, I/O, Binder, native.

nativePollOnce:
    Currently no executable message selected by the queue; it is an observed state, not an independent root cause.

This set of four articles forms a complete closed loop here:

How tasks travel:
    post -> Message -> enqueue -> next -> dispatch.

How the queue waits:
    when, synchronous barriers, nativePollOnce, nativeWake, quit.

How threads are divided:
    Main thread, HandlerThread, Binder threads, system_server dedicated Loopers.

How to investigate problems:
    Replace "Handler is stuck" with stages and evidence.

Appendix A: How to Temporarily Enable Looper Slow Logs?

The Looper.getThresholdOverride() in the current source code supports the following system properties:

log.looper.any.main.slow
log.looper.<uid>.any.slow
log.looper.<uid>.<thread-name>.slow

Source code entry point:

• Looper.getThresholdOverride()

On a dedicated test machine where restarting the Framework is allowed, you can first record the original value, then temporarily set it:

adb shell getprop log.looper.any.main.slow
adb shell setprop log.looper.any.main.slow 16

adb shell getprop log.looper.1000.android.ui.slow
adb shell setprop log.looper.1000.android.ui.slow 20

adb shell stop
adb shell start

stop/start will restart the Android Framework, causing the UI, services, connections, and on-site state to be interrupted. It is not suitable for production devices or faults where the original scene needs to be preserved. Whether the property can be written, and whether a Framework or device restart is needed, depends on the build type, property permissions, and vendor branch; after setting, you must verify with getprop, do not assume the command succeeded and took effect.

After reproduction ends, restore the recorded original value; if the original value is empty, clear it in a way supported by the test environment, then perform the same steps to make it effective. Do not keep excessively low thresholds for a long time, otherwise the high-frequency logs themselves will perturb the timing.

Appendix B: What Can Each Tool Prove?

Evidence	What it can prove	What it cannot prove alone
Post log + post return value	Whether the call occurred, whether the enqueue request was accepted at that time	Whether the message is still in the queue, whether it ultimately executed
Looper.setMessageLogging()	The actual start and end of dispatch for a specific message	When the business originally called post
Slow delivery	dispatchStart is too late relative to Message.when	That the lateness was definitely caused by queue backlog or barriers
Slow dispatch	The dispatch interval for the current message is too long	Whether the callback is stuck on a lock, I/O, Binder, or native
thread dump	Java stack, lock waiting, or native entry at the sampling instant	That the entire fault interval was always in the same state
Perfetto	Thread scheduling, preceding slices, temporal relationship of Binder and explicit traces	Automatic correlation of post and execution without embedded flow/async trace/sequence
dumpsys	System component state at the collection moment	The complete causal chain for a past moment

Choose common commands based on evidence, don't run them all aimlessly:

# Threads and logs
adb shell ps -A -T | grep system_server
adb logcat -v threadtime
adb logcat -d | grep -i "Slow dispatch|Slow delivery"

# Java thread dump: sends SIGQUIT to the process, only use when perturbation is allowed
adb shell kill -3 <pid>

# Choose state snapshots based on specific symptoms
adb shell dumpsys activity
adb shell dumpsys window
adb shell dumpsys input
adb shell dumpsys display
adb shell dumpsys binder_calls_stats

For window not refreshing, prioritize evidence collection around the window, activity, and SurfaceFlinger chain; for input lag, look at input, window, and Perfetto input events; for Binder time consumption, look at dual-end thread stacks, Binder timeline, and call statistics. Tools are just evidence sources; ultimately, you must still fall back to the lifecycle of the same message.

Appendix C: How to Correlate Handler Post and Execution

The main text only needs to remember one sentence: Synchronous traceBegin/traceEnd is constrained by the current thread's call stack and can only see the small segment of post(); to span "posting thread -> MessageQueue -> target Looper thread", you need async trace, flow, or an explicit sequence.

Below is a one-shot async trace skeleton for use in Framework / system_server internal code:

final class TracedPost implements Runnable {
    private static final int ENQUEUED = 0;
    private static final int RUNNING = 1;
    private static final int FINISHED = 2;
    private static final int CANCELED = 3;

    private static final AtomicInteger NEXT_COOKIE = new AtomicInteger();

    private final Handler mHandler;
    private final Runnable mTask;
    private final String mTraceName;
    private final int mCookie = NEXT_COOKIE.incrementAndGet();
    private final AtomicInteger mState = new AtomicInteger(ENQUEUED);

    TracedPost(Handler handler, String traceName, Runnable task) {
        mHandler = handler;
        mTraceName = traceName;
        mTask = task;
    }

    boolean post() {
        Trace.asyncTraceBegin(
                Trace.TRACE_TAG_SYSTEM_SERVER, mTraceName, mCookie);

        boolean enqueued = mHandler.post(this);
        if (!enqueued && mState.compareAndSet(ENQUEUED, CANCELED)) {
            endTrace();
        }
        return enqueued;
    }

    boolean cancel() {
        if (!mState.compareAndSet(ENQUEUED, CANCELED)) {
            return false;
        }

        mHandler.removeCallbacks(this);
        endTrace();
        return true;
    }

    @Override
    public void run() {
        if (!mState.compareAndSet(ENQUEUED, RUNNING)) {
            return;
        }

        try {
            mTask.run();
        } finally {
            mState.set(FINISHED);
            endTrace();
        }
    }

    private void endTrace() {
        Trace.asyncTraceEnd(
                Trace.TRACE_TAG_SYSTEM_SERVER, mTraceName, mCookie);
    }
}

This skeleton has four key constraints:

1. begin and end must use the same trace name + cookie;
2. Immediately end on enqueue failure to avoid leaving an unclosed async slice;
3. cancel and run compete via state, only the one that successfully grabs the state is responsible for end;
4. This is a one-shot object; do not post the same TracedPost repeatedly.

If the business also clears messages through external paths like removeCallbacksAndMessages(), those paths must also enter the same cancel() state machine; otherwise, the async trace cannot know the message has been removed. Regular Apps can replace asyncTraceBegin/End + TRACE_TAG_SYSTEM_SERVER with the public Trace.beginAsyncSection/endAsyncSection, with the pairing rules unchanged.

If it's inconvenient to wrap an async trace, at least use the same sequence to record a unified time base:

post:           seq=1042 caller=Binder:1234_5 target=android.display uptime=123456 result=true
dispatchStart:  seq=1042 thread=android.display uptime=123480
dispatchEnd:    seq=1042 thread=android.display uptime=123492

Here, SystemClock.uptimeMillis() should be used, keeping the same time base as Message.when. This way, even without an async slice, you can calculate the delivery and dispatch intervals and determine which segment is missing evidence.

Further Reading

• AOSP Looper.java
• AOSP Handler.java
• AOSP MessageQueue.java
• AOSP Trace.java
• AOSP SystemServer.java
• AOSP HandlerThread.java