Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 6705ba4f authored by Siarhei Vishniakou's avatar Siarhei Vishniakou
Browse files

Add tracing for batching status 

Check whether batching notification has already been made.

Test procedure:
1. Add "system tracing" to quick settings from developer options (enable
   the quick settings tile for system tracing)
2. Start system tracing via UI of quick settings
3. Open all apps and do some swipes
4. Click "stop tracing"
5. Pull the logs to the device `adb pull /data/local/traces/ ~/trace`
6. Go to https://ui.perfetto.dev/
7. Click "open trace file" and navigate to the local file
8. In the trace, open the process of interest. In this case, it's the
   launcher process
9. Scroll down to "InputConsumer processing"
10. The "cookie" field of each entry is the sequence number of this
    event (but not the event id).

Bug: 311142655
Test: perfetto test procedure described above
Change-Id: Idc123a65798ae64fa304553a18140149e5cd0ea8
parent 7757f462

core/java/android/view/BatchedInputEventReceiver.java

+13 −0
Original line number Diff line number Diff line
@@ -19,6 +19,7 @@ package android.view; 
import android.compat.annotation.UnsupportedAppUsage;

import android.os.Handler;

import android.os.Looper;

import android.os.Trace;



/**

 * Similar to {@link InputEventReceiver}, but batches events to vsync boundaries when possible.
@@ -42,6 +43,8 @@ public class BatchedInputEventReceiver extends InputEventReceiver { 
        super(inputChannel, looper);

        mChoreographer = choreographer;

        mBatchingEnabled = true;

        traceBoolVariable("mBatchingEnabled", mBatchingEnabled);

        traceBoolVariable("mBatchedInputScheduled", mBatchedInputScheduled);

        mHandler = new Handler(looper);

    }
@@ -71,6 +74,7 @@ public class BatchedInputEventReceiver extends InputEventReceiver { 
        }



        mBatchingEnabled = batchingEnabled;

        traceBoolVariable("mBatchingEnabled", mBatchingEnabled);

        mHandler.removeCallbacks(mConsumeBatchedInputEvents);

        if (!batchingEnabled) {

            unscheduleBatchedInput();
@@ -81,6 +85,7 @@ public class BatchedInputEventReceiver extends InputEventReceiver { 
    protected void doConsumeBatchedInput(long frameTimeNanos) {

        if (mBatchedInputScheduled) {

            mBatchedInputScheduled = false;

            traceBoolVariable("mBatchedInputScheduled", mBatchedInputScheduled);

            if (consumeBatchedInputEvents(frameTimeNanos) && frameTimeNanos != -1) {

                // If we consumed a batch here, we want to go ahead and schedule the

                // consumption of batched input events on the next frame. Otherwise, we would
@@ -95,6 +100,7 @@ public class BatchedInputEventReceiver extends InputEventReceiver { 
    private void scheduleBatchedInput() {

        if (!mBatchedInputScheduled) {

            mBatchedInputScheduled = true;

            traceBoolVariable("mBatchedInputScheduled", mBatchedInputScheduled);

            mChoreographer.postCallback(Choreographer.CALLBACK_INPUT, mBatchedInputRunnable, null);

        }

    }
@@ -102,11 +108,18 @@ public class BatchedInputEventReceiver extends InputEventReceiver { 
    private void unscheduleBatchedInput() {

        if (mBatchedInputScheduled) {

            mBatchedInputScheduled = false;

            traceBoolVariable("mBatchedInputScheduled", mBatchedInputScheduled);

            mChoreographer.removeCallbacks(

                    Choreographer.CALLBACK_INPUT, mBatchedInputRunnable, null);

        }

    }



    // @TODO(b/311142655): Delete this temporary tracing. It's only used here to debug a very

    // specific issue.

    private void traceBoolVariable(String name, boolean value) {

        Trace.traceCounter(Trace.TRACE_TAG_INPUT, name, value ? 1 : 0);

    }



    private final class BatchedInputRunnable implements Runnable {

        @Override

        public void run() {

core/java/android/view/InputEventReceiver.java

+17 −0
Original line number Diff line number Diff line
@@ -271,12 +271,29 @@ public abstract class InputEventReceiver { 
        return mInputChannel.getToken();

    }



    private String getShortDescription(InputEvent event) {

        if (event instanceof MotionEvent motion) {

            return "MotionEvent " + MotionEvent.actionToString(motion.getAction()) + " deviceId="

                    + motion.getDeviceId() + " source=0x"

                    + Integer.toHexString(motion.getSource()) +  " historySize="

                    + motion.getHistorySize();

        } else if (event instanceof KeyEvent key) {

            return "KeyEvent " + KeyEvent.actionToString(key.getAction())

                    + " deviceId=" + key.getDeviceId();

        } else {

            Log.wtf(TAG, "Illegal InputEvent type: " + event);

            return "InputEvent";

        }

    }



    // Called from native code.

    @SuppressWarnings("unused")

    @UnsupportedAppUsage(maxTargetSdk = Build.VERSION_CODES.R, trackingBug = 170729553)

    private void dispatchInputEvent(int seq, InputEvent event) {

        Trace.traceBegin(Trace.TRACE_TAG_INPUT, "dispatchInputEvent " + getShortDescription(event));

        mSeqMap.put(event.getSequenceNumber(), seq);

        onInputEvent(event);

        Trace.traceEnd(Trace.TRACE_TAG_INPUT);

    }



    /**

core/jni/android_view_InputEventReceiver.cpp

+15 −0
Original line number Diff line number Diff line
@@ -15,6 +15,7 @@ 
 */



#define LOG_TAG "InputEventReceiver"

#define ATRACE_TAG ATRACE_TAG_INPUT



//#define LOG_NDEBUG 0
@@ -46,6 +47,16 @@ static const char* toString(bool value) { 
    return value ? "true" : "false";

}



/**

 * Trace a bool variable, writing "1" if the value is "true" and "0" otherwise.

 * TODO(b/311142655): delete this tracing. It's only useful for debugging very specific issues.

 * @param var the name of the variable

 * @param value the value of the variable

 */

static void traceBoolVariable(const char* var, bool value) {

    ATRACE_INT(var, value ? 1 : 0);

}



static struct {

    jclass clazz;
@@ -130,6 +141,7 @@ NativeInputEventReceiver::NativeInputEventReceiver( 
        mMessageQueue(messageQueue),

        mBatchedInputEventPending(false),

        mFdEvents(0) {

    traceBoolVariable("mBatchedInputEventPending", mBatchedInputEventPending);

    if (kDebugDispatchCycle) {

        ALOGD("channel '%s' ~ Initializing input event receiver.", getInputChannelName().c_str());

    }
@@ -311,6 +323,7 @@ status_t NativeInputEventReceiver::consumeEvents(JNIEnv* env, 


    if (consumeBatches) {

        mBatchedInputEventPending = false;

        traceBoolVariable("mBatchedInputEventPending", mBatchedInputEventPending);

    }

    if (outConsumedBatch) {

        *outConsumedBatch = false;
@@ -344,6 +357,7 @@ status_t NativeInputEventReceiver::consumeEvents(JNIEnv* env, 
                }



                mBatchedInputEventPending = true;

                traceBoolVariable("mBatchedInputEventPending", mBatchedInputEventPending);

                if (kDebugDispatchCycle) {

                    ALOGD("channel '%s' ~ Dispatching batched input event pending notification.",

                          getInputChannelName().c_str());
@@ -355,6 +369,7 @@ status_t NativeInputEventReceiver::consumeEvents(JNIEnv* env, 
                if (env->ExceptionCheck()) {

                    ALOGE("Exception dispatching batched input events.");

                    mBatchedInputEventPending = false; // try again later

                    traceBoolVariable("mBatchedInputEventPending", mBatchedInputEventPending);

                }

            }

            return OK;