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

Commit 6876f321 authored by Jeff Brown's avatar Jeff Brown
Browse files

Dump information about recent input events.

To help track down ANRs, include more information about recent
events in the input dispatcher dumps.

Bug: 9774124
Change-Id: I94732f173d3518c2f4780668d2eb3ee9ae9fcb10
parent ef981a40
Loading
Loading
Loading
Loading
+58 −6
Original line number Original line Diff line number Diff line
@@ -84,6 +84,8 @@ const nsecs_t STREAM_AHEAD_EVENT_TIMEOUT = 500 * 1000000LL; // 0.5sec
// Log a warning when an event takes longer than this to process, even if an ANR does not occur.
// Log a warning when an event takes longer than this to process, even if an ANR does not occur.
const nsecs_t SLOW_EVENT_PROCESSING_WARNING_TIMEOUT = 2000 * 1000000LL; // 2sec
const nsecs_t SLOW_EVENT_PROCESSING_WARNING_TIMEOUT = 2000 * 1000000LL; // 2sec


// Number of recent events to keep for debugging purposes.
const size_t RECENT_QUEUE_MAX_SIZE = 10;


static inline nsecs_t now() {
static inline nsecs_t now() {
    return systemTime(SYSTEM_TIME_MONOTONIC);
    return systemTime(SYSTEM_TIME_MONOTONIC);
@@ -455,6 +457,14 @@ bool InputDispatcher::enqueueInboundEventLocked(EventEntry* entry) {
    return needWake;
    return needWake;
}
}


void InputDispatcher::addRecentEventLocked(EventEntry* entry) {
    entry->refCount += 1;
    mRecentQueue.enqueueAtTail(entry);
    if (mRecentQueue.count() > RECENT_QUEUE_MAX_SIZE) {
        mRecentQueue.dequeueAtHead()->release();
    }
}

sp<InputWindowHandle> InputDispatcher::findTouchedWindowAtLocked(int32_t displayId,
sp<InputWindowHandle> InputDispatcher::findTouchedWindowAtLocked(int32_t displayId,
        int32_t x, int32_t y) {
        int32_t x, int32_t y) {
    // Traverse windows from front to back to find touched window.
    // Traverse windows from front to back to find touched window.
@@ -624,6 +634,7 @@ void InputDispatcher::releaseInboundEventLocked(EventEntry* entry) {
    if (entry == mNextUnblockedEvent) {
    if (entry == mNextUnblockedEvent) {
        mNextUnblockedEvent = NULL;
        mNextUnblockedEvent = NULL;
    }
    }
    addRecentEventLocked(entry);
    entry->release();
    entry->release();
}
}


@@ -3161,6 +3172,31 @@ void InputDispatcher::dumpDispatchStateLocked(String8& dump) {


    nsecs_t currentTime = now();
    nsecs_t currentTime = now();


    // Dump recently dispatched or dropped events from oldest to newest.
    if (!mRecentQueue.isEmpty()) {
        dump.appendFormat(INDENT "RecentQueue: length=%u\n", mRecentQueue.count());
        for (EventEntry* entry = mRecentQueue.head; entry; entry = entry->next) {
            dump.append(INDENT2);
            entry->appendDescription(dump);
            dump.appendFormat(", age=%0.1fms\n",
                    (currentTime - entry->eventTime) * 0.000001f);
        }
    } else {
        dump.append(INDENT "RecentQueue: <empty>\n");
    }

    // Dump event currently being dispatched.
    if (mPendingEvent) {
        dump.append(INDENT "PendingEvent:\n");
        dump.append(INDENT2);
        mPendingEvent->appendDescription(dump);
        dump.appendFormat(", age=%0.1fms\n",
                (currentTime - mPendingEvent->eventTime) * 0.000001f);
    } else {
        dump.append(INDENT "PendingEvent: <none>\n");
    }

    // Dump inbound events from oldest to newest.
    if (!mInboundQueue.isEmpty()) {
    if (!mInboundQueue.isEmpty()) {
        dump.appendFormat(INDENT "InboundQueue: length=%u\n", mInboundQueue.count());
        dump.appendFormat(INDENT "InboundQueue: length=%u\n", mInboundQueue.count());
        for (EventEntry* entry = mInboundQueue.head; entry; entry = entry->next) {
        for (EventEntry* entry = mInboundQueue.head; entry; entry = entry->next) {
@@ -3809,7 +3845,8 @@ InputDispatcher::ConfigurationChangedEntry::~ConfigurationChangedEntry() {
}
}


void InputDispatcher::ConfigurationChangedEntry::appendDescription(String8& msg) const {
void InputDispatcher::ConfigurationChangedEntry::appendDescription(String8& msg) const {
    msg.append("ConfigurationChangedEvent()");
    msg.append("ConfigurationChangedEvent(), policyFlags=0x%08x",
            policyFlags);
}
}




@@ -3824,7 +3861,8 @@ InputDispatcher::DeviceResetEntry::~DeviceResetEntry() {
}
}


void InputDispatcher::DeviceResetEntry::appendDescription(String8& msg) const {
void InputDispatcher::DeviceResetEntry::appendDescription(String8& msg) const {
    msg.appendFormat("DeviceResetEvent(deviceId=%d)", deviceId);
    msg.appendFormat("DeviceResetEvent(deviceId=%d), policyFlags=0x%08x",
            deviceId, policyFlags);
}
}




@@ -3846,8 +3884,11 @@ InputDispatcher::KeyEntry::~KeyEntry() {
}
}


void InputDispatcher::KeyEntry::appendDescription(String8& msg) const {
void InputDispatcher::KeyEntry::appendDescription(String8& msg) const {
    msg.appendFormat("KeyEvent(action=%d, deviceId=%d, source=0x%08x)",
    msg.appendFormat("KeyEvent(deviceId=%d, source=0x%08x, action=%d, "
            action, deviceId, source);
            "flags=0x%08x, keyCode=%d, scanCode=%d, metaState=0x%08x, "
            "repeatCount=%d), policyFlags=0x%08x",
            deviceId, source, action, flags, keyCode, scanCode, metaState,
            repeatCount, policyFlags);
}
}


void InputDispatcher::KeyEntry::recycle() {
void InputDispatcher::KeyEntry::recycle() {
@@ -3884,8 +3925,19 @@ InputDispatcher::MotionEntry::~MotionEntry() {
}
}


void InputDispatcher::MotionEntry::appendDescription(String8& msg) const {
void InputDispatcher::MotionEntry::appendDescription(String8& msg) const {
    msg.appendFormat("MotionEvent(action=%d, deviceId=%d, source=0x%08x, displayId=%d)",
    msg.appendFormat("MotionEvent(deviceId=%d, source=0x%08x, action=%d, "
            action, deviceId, source, displayId);
            "flags=0x%08x, metaState=0x%08x, buttonState=0x%08x, edgeFlags=0x%08x, "
            "xPrecision=%.1f, yPrecision=%.1f, displayId=%d, pointers=[",
            deviceId, source, action, flags, metaState, buttonState, edgeFlags,
            xPrecision, yPrecision, displayId);
    for (uint32_t i = 0; i < pointerCount; i++) {
        if (i) {
            msg.append(", ");
        }
        msg.appendFormat("%d: (%.1f, %.1f)", pointerProperties[i].id,
                pointerCoords[i].getX(), pointerCoords[i].getY());
    }
    msg.appendFormat("]), policyFlags=0x%08x", policyFlags);
}
}




+4 −0
Original line number Original line Diff line number Diff line
@@ -846,6 +846,7 @@ private:


    EventEntry* mPendingEvent;
    EventEntry* mPendingEvent;
    Queue<EventEntry> mInboundQueue;
    Queue<EventEntry> mInboundQueue;
    Queue<EventEntry> mRecentQueue;
    Queue<CommandEntry> mCommandQueue;
    Queue<CommandEntry> mCommandQueue;


    void dispatchOnceInnerLocked(nsecs_t* nextWakeupTime);
    void dispatchOnceInnerLocked(nsecs_t* nextWakeupTime);
@@ -856,6 +857,9 @@ private:
    // Cleans up input state when dropping an inbound event.
    // Cleans up input state when dropping an inbound event.
    void dropInboundEventLocked(EventEntry* entry, DropReason dropReason);
    void dropInboundEventLocked(EventEntry* entry, DropReason dropReason);


    // Adds an event to a queue of recent events for debugging purposes.
    void addRecentEventLocked(EventEntry* entry);

    // App switch latency optimization.
    // App switch latency optimization.
    bool mAppSwitchSawKeyDown;
    bool mAppSwitchSawKeyDown;
    nsecs_t mAppSwitchDueTime;
    nsecs_t mAppSwitchDueTime;