Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge "Coalesce input events that arrive faster than 333Hz."

Browse Source
This commit is contained in:
Jeff Brown
2011-04-07 13:18:38 -07:00
committed by Android (Google) Code Review
parent 6d4b4901eb 4e91a180be
commit 6181de3443
9 changed files with 275 additions and 33 deletions
Download Patch File Download Diff File Expand all files Collapse all files

15
core/java/android/view/HardwareRenderer.java
View File

@@ -645,8 +645,21 @@ public abstract class HardwareRenderer {
}
attachInfo.mIgnoreDirtyState = false;
final long swapBuffersStartTime;
if (ViewDebug.DEBUG_LATENCY) {
swapBuffersStartTime = System.nanoTime();
}
sEgl.eglSwapBuffers(sEglDisplay, mEglSurface);
if (ViewDebug.DEBUG_LATENCY) {
long now = System.nanoTime();
Log.d(LOG_TAG, "Latency: Spent "
+ ((now - swapBuffersStartTime) * 0.000001f)
+ "ms waiting for eglSwapBuffers()");
}
checkEglErrors();
}
}

7
core/java/android/view/InputEvent.java
View File

@@ -106,6 +106,13 @@ public abstract class InputEvent implements Parcelable {
*/
public abstract void setTainted(boolean tainted);
/**
* Returns the time (in ns) when this specific event was generated.
* The value is in nanosecond precision but it may not have nanosecond accuracy.
* @hide
*/
public abstract long getEventTimeNano();
public int describeContents() {
return 0;
}

6
core/java/android/view/KeyEvent.java
View File

@@ -2340,6 +2340,12 @@ public class KeyEvent extends InputEvent implements Parcelable {
return mEventTime;
}
/** @hide */
@Override
public final long getEventTimeNano() {
return mEventTime * 1000000L;
}
/**
* Renamed to {@link #getDeviceId}.
*

16
core/java/android/view/ViewDebug.java
View File

@@ -140,6 +140,22 @@ public class ViewDebug {
*/
public static final boolean DEBUG_DRAG = false;
/**
* Enables logging of factors that affect the latency and responsiveness of an application.
*
* Logs the relative difference between the time an event was created and the time it
* was delivered.
*
* Logs the time spent waiting for Surface.lockCanvas() or eglSwapBuffers().
* This is time that the event loop spends blocked and unresponsive. Ideally, drawing
* and animations should be perfectly synchronized with VSYNC so that swap buffers
* is instantaneous.
*
* Logs the time spent in ViewRoot.performTraversals() or ViewRoot.draw().
* @hide
*/
public static final boolean DEBUG_LATENCY = false;
/**
* <p>Enables or disables views consistency check. Even when this property is enabled,
* view consistency checks happen only if {@link android.util.Config#DEBUG} is set

134
core/java/android/view/ViewRoot.java
View File

@@ -186,6 +186,8 @@ public final class ViewRoot extends Handler implements ViewParent,
final Rect mVisRect; // used to retrieve visible rect of focused view.
boolean mTraversalScheduled;
long mLastTraversalFinishedTimeNanos;
long mLastDrawDurationNanos;
boolean mWillDrawSoon;
boolean mLayoutRequested;
boolean mFirst;
@@ -671,6 +673,14 @@ public final class ViewRoot extends Handler implements ViewParent,
public void scheduleTraversals() {
if (!mTraversalScheduled) {
mTraversalScheduled = true;
if (ViewDebug.DEBUG_LATENCY && mLastTraversalFinishedTimeNanos != 0) {
final long now = System.nanoTime();
Log.d(TAG, "Latency: Scheduled traversal, it has been "
+ ((now - mLastTraversalFinishedTimeNanos) * 0.000001f)
+ "ms since the last traversal finished.");
}
sendEmptyMessage(DO_TRAVERSAL);
}
}
@@ -1389,8 +1399,18 @@ public final class ViewRoot extends Handler implements ViewParent,
if (!cancelDraw && !newSurface) {
mFullRedrawNeeded = false;
final long drawStartTime;
if (ViewDebug.DEBUG_LATENCY) {
drawStartTime = System.nanoTime();
}
draw(fullRedrawNeeded);
if (ViewDebug.DEBUG_LATENCY) {
mLastDrawDurationNanos = System.nanoTime() - drawStartTime;
}
if ((relayoutResult&WindowManagerImpl.RELAYOUT_FIRST_TIME) != 0
|| mReportNextDraw) {
if (LOCAL_LOGV) {
@@ -1601,8 +1621,20 @@ public final class ViewRoot extends Handler implements ViewParent,
int right = dirty.right;
int bottom = dirty.bottom;
final long lockCanvasStartTime;
if (ViewDebug.DEBUG_LATENCY) {
lockCanvasStartTime = System.nanoTime();
}
canvas = surface.lockCanvas(dirty);
if (ViewDebug.DEBUG_LATENCY) {
long now = System.nanoTime();
Log.d(TAG, "Latency: Spent "
+ ((now - lockCanvasStartTime) * 0.000001f)
+ "ms waiting for surface.lockCanvas()");
}
if (left != dirty.left || top != dirty.top || right != dirty.right ||
bottom != dirty.bottom) {
mAttachInfo.mIgnoreDirtyState = true;
@@ -2011,8 +2043,24 @@ public final class ViewRoot extends Handler implements ViewParent,
Debug.startMethodTracing("ViewRoot");
}
final long traversalStartTime;
if (ViewDebug.DEBUG_LATENCY) {
traversalStartTime = System.nanoTime();
mLastDrawDurationNanos = 0;
}
performTraversals();
if (ViewDebug.DEBUG_LATENCY) {
long now = System.nanoTime();
Log.d(TAG, "Latency: Spent "
+ ((now - traversalStartTime) * 0.000001f)
+ "ms in performTraversals(), with "
+ (mLastDrawDurationNanos * 0.000001f)
+ "ms of that time in draw()");
mLastTraversalFinishedTimeNanos = now;
}
if (mProfile) {
Debug.stopMethodTracing();
mProfile = false;
@@ -2180,25 +2228,68 @@ public final class ViewRoot extends Handler implements ViewParent,
}
}
private void startInputEvent(InputQueue.FinishedCallback finishedCallback) {
private void startInputEvent(InputEvent event, InputQueue.FinishedCallback finishedCallback) {
if (mFinishedCallback != null) {
Slog.w(TAG, "Received a new input event from the input queue but there is "
+ "already an unfinished input event in progress.");
}
if (ViewDebug.DEBUG_LATENCY) {
mInputEventReceiveTimeNanos = System.nanoTime();
mInputEventDeliverTimeNanos = 0;
mInputEventDeliverPostImeTimeNanos = 0;
}
mFinishedCallback = finishedCallback;
}
private void finishInputEvent(boolean handled) {
private void finishInputEvent(InputEvent event, boolean handled) {
if (LOCAL_LOGV) Log.v(TAG, "Telling window manager input event is finished");
if (mFinishedCallback != null) {
mFinishedCallback.finished(handled);
mFinishedCallback = null;
} else {
if (mFinishedCallback == null) {
Slog.w(TAG, "Attempted to tell the input queue that the current input event "
+ "is finished but there is no input event actually in progress.");
return;
}
if (ViewDebug.DEBUG_LATENCY) {
final long now = System.nanoTime();
final long eventTime = event.getEventTimeNano();
final StringBuilder msg = new StringBuilder();
msg.append("Latency: Spent ");
msg.append((now - mInputEventReceiveTimeNanos) * 0.000001f);
msg.append("ms processing ");
if (event instanceof KeyEvent) {
final KeyEvent keyEvent = (KeyEvent)event;
msg.append("key event, action=");
msg.append(KeyEvent.actionToString(keyEvent.getAction()));
} else {
final MotionEvent motionEvent = (MotionEvent)event;
msg.append("motion event, action=");
msg.append(MotionEvent.actionToString(motionEvent.getAction()));
msg.append(", historySize=");
msg.append(motionEvent.getHistorySize());
}
msg.append(", handled=");
msg.append(handled);
msg.append(", received at +");
msg.append((mInputEventReceiveTimeNanos - eventTime) * 0.000001f);
if (mInputEventDeliverTimeNanos != 0) {
msg.append("ms, delivered at +");
msg.append((mInputEventDeliverTimeNanos - eventTime) * 0.000001f);
}
if (mInputEventDeliverPostImeTimeNanos != 0) {
msg.append("ms, delivered post IME at +");
msg.append((mInputEventDeliverPostImeTimeNanos - eventTime) * 0.000001f);
}
msg.append("ms, finished at +");
msg.append((now - eventTime) * 0.000001f);
msg.append("ms.");
Log.d(TAG, msg.toString());
}
mFinishedCallback.finished(handled);
mFinishedCallback = null;
}
/**
@@ -2323,6 +2414,10 @@ public final class ViewRoot extends Handler implements ViewParent,
}
private void deliverPointerEvent(MotionEvent event, boolean sendDone) {
if (ViewDebug.DEBUG_LATENCY) {
mInputEventDeliverTimeNanos = System.nanoTime();
}
if (mInputEventConsistencyVerifier != null) {
if (event.isTouchEvent()) {
mInputEventConsistencyVerifier.onTouchEvent(event, 0);
@@ -2425,7 +2520,7 @@ public final class ViewRoot extends Handler implements ViewParent,
private void finishMotionEvent(MotionEvent event, boolean sendDone, boolean handled) {
event.recycle();
if (sendDone) {
finishInputEvent(handled);
finishInputEvent(event, handled);
}
if (LOCAL_LOGV || WATCH_POINTER) {
if ((event.getSource() & InputDevice.SOURCE_CLASS_POINTER) != 0) {
@@ -2435,6 +2530,10 @@ public final class ViewRoot extends Handler implements ViewParent,
}
private void deliverTrackballEvent(MotionEvent event, boolean sendDone) {
if (ViewDebug.DEBUG_LATENCY) {
mInputEventDeliverTimeNanos = System.nanoTime();
}
if (DEBUG_TRACKBALL) Log.v(TAG, "Motion event:" + event);
if (mInputEventConsistencyVerifier != null) {
@@ -2569,6 +2668,10 @@ public final class ViewRoot extends Handler implements ViewParent,
}
private void deliverGenericMotionEvent(MotionEvent event, boolean sendDone) {
if (ViewDebug.DEBUG_LATENCY) {
mInputEventDeliverTimeNanos = System.nanoTime();
}
if (mInputEventConsistencyVerifier != null) {
mInputEventConsistencyVerifier.onGenericMotionEvent(event, 0);
}
@@ -2808,6 +2911,10 @@ public final class ViewRoot extends Handler implements ViewParent,
}
private void deliverKeyEvent(KeyEvent event, boolean sendDone) {
if (ViewDebug.DEBUG_LATENCY) {
mInputEventDeliverTimeNanos = System.nanoTime();
}
if (mInputEventConsistencyVerifier != null) {
mInputEventConsistencyVerifier.onKeyEvent(event, 0);
}
@@ -2858,6 +2965,10 @@ public final class ViewRoot extends Handler implements ViewParent,
}
private void deliverKeyEventPostIme(KeyEvent event, boolean sendDone) {
if (ViewDebug.DEBUG_LATENCY) {
mInputEventDeliverPostImeTimeNanos = System.nanoTime();
}
// If the view went away, then the event will not be handled.
if (mView == null || !mAdded) {
finishKeyEvent(event, sendDone, false);
@@ -2971,7 +3082,7 @@ public final class ViewRoot extends Handler implements ViewParent,
private void finishKeyEvent(KeyEvent event, boolean sendDone, boolean handled) {
if (sendDone) {
finishInputEvent(handled);
finishInputEvent(event, handled);
}
}
@@ -3262,16 +3373,19 @@ public final class ViewRoot extends Handler implements ViewParent,
sendMessage(msg);
}
private long mInputEventReceiveTimeNanos;
private long mInputEventDeliverTimeNanos;
private long mInputEventDeliverPostImeTimeNanos;
private InputQueue.FinishedCallback mFinishedCallback;
private final InputHandler mInputHandler = new InputHandler() {
public void handleKey(KeyEvent event, InputQueue.FinishedCallback finishedCallback) {
startInputEvent(finishedCallback);
startInputEvent(event, finishedCallback);
dispatchKey(event, true);
}
public void handleMotion(MotionEvent event, InputQueue.FinishedCallback finishedCallback) {
startInputEvent(finishedCallback);
startInputEvent(event, finishedCallback);
dispatchMotion(event, true);
}
};

8
libs/ui/InputTransport.cpp
View File

@@ -27,8 +27,14 @@
namespace android {
#define ROUND_UP(value, boundary) (((value) + (boundary) - 1) & ~((boundary) - 1))
#define MIN_HISTORY_DEPTH 20
// Must be at least sizeof(InputMessage) + sufficient space for pointer data
static const int DEFAULT_MESSAGE_BUFFER_SIZE = 16384;
static const int DEFAULT_MESSAGE_BUFFER_SIZE = ROUND_UP(
sizeof(InputMessage) + MIN_HISTORY_DEPTH
* (sizeof(InputMessage::SampleData) + MAX_POINTERS * sizeof(PointerCoords)),
4096);
// Signal sent by the producer to the consumer to inform it that a new message is
// available to be consumed in the shared memory buffer.

17
services/input/EventHub.cpp
View File

@@ -539,7 +539,24 @@ size_t EventHub::getEvents(int timeoutMillis, RawEvent* buffer, size_t bufferSiz
(int) iev.time.tv_sec, (int) iev.time.tv_usec,
iev.type, iev.code, iev.value);
#ifdef HAVE_POSIX_CLOCKS
// Use the time specified in the event instead of the current time
// so that downstream code can get more accurate estimates of
// event dispatch latency from the time the event is enqueued onto
// the evdev client buffer.
//
// The event's timestamp fortuitously uses the same monotonic clock
// time base as the rest of Android. The kernel event device driver
// (drivers/input/evdev.c) obtains timestamps using ktime_get_ts().
// The systemTime(SYSTEM_TIME_MONOTONIC) function we use everywhere
// calls clock_gettime(CLOCK_MONOTONIC) which is implemented as a
// system call that also queries ktime_get_ts().
event->when = nsecs_t(iev.time.tv_sec) * 1000000000LL
+ nsecs_t(iev.time.tv_usec) * 1000LL;
LOGV("event time %lld, now %lld", event->when, now);
#else
event->when = now;
#endif
event->deviceId = deviceId;
event->type = iev.type;
event->scanCode = iev.code;

91
services/input/InputDispatcher.cpp
View File

@@ -79,6 +79,22 @@ const nsecs_t APP_SWITCH_TIMEOUT = 500 * 1000000LL; // 0.5sec
// before considering it stale and dropping it.
const nsecs_t STALE_EVENT_TIMEOUT = 10000 * 1000000LL; // 10sec
// Motion samples that are received within this amount of time are simply coalesced
// when batched instead of being appended. This is done because some drivers update
// the location of pointers one at a time instead of all at once.
// For example, when there are 10 fingers down, the input dispatcher may receive 10
// samples in quick succession with only one finger's location changed in each sample.
//
// This value effectively imposes an upper bound on the touch sampling rate.
// Touch sensors typically have a 50Hz - 200Hz sampling rate, so we expect distinct
// samples to become available 5-20ms apart but individual finger reports can trickle
// in over a period of 2-4ms or so.
//
// Empirical testing shows that a 2ms coalescing interval (500Hz) is not enough,
// a 3ms coalescing interval (333Hz) works well most of the time and doesn't introduce
// significant quantization noise on current hardware.
const nsecs_t MOTION_SAMPLE_COALESCE_INTERVAL = 3 * 1000000LL; // 3ms, 333Hz
static inline nsecs_t now() {
return systemTime(SYSTEM_TIME_MONOTONIC);
@@ -2505,21 +2521,15 @@ void InputDispatcher::notifyMotion(nsecs_t eventTime, int32_t deviceId, uint32_t
continue;
}
if (motionEntry->action != action
|| motionEntry->pointerCount != pointerCount
|| motionEntry->isInjected()) {
if (!motionEntry->canAppendSamples(action, pointerCount, pointerIds)) {
// Last motion event in the queue for this device and source is
// not compatible for appending new samples. Stop here.
goto NoBatchingOrStreaming;
}
// The last motion event is a move and is compatible for appending.
// Do the batching magic.
mAllocator.appendMotionSample(motionEntry, eventTime, pointerCoords);
#if DEBUG_BATCHING
LOGD("Appended motion sample onto batch for most recent "
"motion event for this device in the inbound queue.");
#endif
batchMotionLocked(motionEntry, eventTime, metaState, pointerCoords,
"most recent motion event for this device and source in the inbound queue");
mLock.unlock();
return; // done!
}
@@ -2534,19 +2544,15 @@ void InputDispatcher::notifyMotion(nsecs_t eventTime, int32_t deviceId, uint32_t
&& mPendingEvent->type == EventEntry::TYPE_MOTION) {
MotionEntry* motionEntry = static_cast<MotionEntry*>(mPendingEvent);
if (motionEntry->deviceId == deviceId && motionEntry->source == source) {
if (motionEntry->action != action
|| motionEntry->pointerCount != pointerCount
|| motionEntry->isInjected()) {
// Pending event is not compatible for appending new samples. Stop here.
if (!motionEntry->canAppendSamples(action, pointerCount, pointerIds)) {
// Pending motion event is for this device and source but it is
// not compatible for appending new samples. Stop here.
goto NoBatchingOrStreaming;
}
// The pending motion event is a move and is compatible for appending.
// Do the batching magic.
mAllocator.appendMotionSample(motionEntry, eventTime, pointerCoords);
#if DEBUG_BATCHING
LOGD("Appended motion sample onto batch for the pending motion event.");
#endif
batchMotionLocked(motionEntry, eventTime, metaState, pointerCoords,
"pending motion event");
mLock.unlock();
return; // done!
}
@@ -2629,7 +2635,7 @@ void InputDispatcher::notifyMotion(nsecs_t eventTime, int32_t deviceId, uint32_t
mAllocator.appendMotionSample(motionEntry, eventTime, pointerCoords);
#if DEBUG_BATCHING
LOGD("Appended motion sample onto batch for most recently dispatched "
"motion event for this device in the outbound queues. "
"motion event for this device and source in the outbound queues. "
"Attempting to stream the motion sample.");
#endif
nsecs_t currentTime = now();
@@ -2660,6 +2666,36 @@ NoBatchingOrStreaming:;
}
}
void InputDispatcher::batchMotionLocked(MotionEntry* entry, nsecs_t eventTime,
int32_t metaState, const PointerCoords* pointerCoords, const char* eventDescription) {
// Combine meta states.
entry->metaState |= metaState;
// Coalesce this sample if not enough time has elapsed since the last sample was
// initially appended to the batch.
MotionSample* lastSample = entry->lastSample;
long interval = eventTime - lastSample->eventTimeBeforeCoalescing;
if (interval <= MOTION_SAMPLE_COALESCE_INTERVAL) {
uint32_t pointerCount = entry->pointerCount;
for (uint32_t i = 0; i < pointerCount; i++) {
lastSample->pointerCoords[i].copyFrom(pointerCoords[i]);
}
lastSample->eventTime = eventTime;
#if DEBUG_BATCHING
LOGD("Coalesced motion into last sample of batch for %s, events were %0.3f ms apart",
eventDescription, interval * 0.000001f);
#endif
return;
}
// Append the sample.
mAllocator.appendMotionSample(entry, eventTime, pointerCoords);
#if DEBUG_BATCHING
LOGD("Appended motion sample onto batch for %s, events were %0.3f ms apart",
eventDescription, interval * 0.000001f);
#endif
}
void InputDispatcher::notifySwitch(nsecs_t when, int32_t switchCode, int32_t switchValue,
uint32_t policyFlags) {
#if DEBUG_INBOUND_EVENT_DETAILS
@@ -3755,6 +3791,7 @@ InputDispatcher::MotionEntry* InputDispatcher::Allocator::obtainMotionEntry(nsec
entry->downTime = downTime;
entry->pointerCount = pointerCount;
entry->firstSample.eventTime = eventTime;
entry->firstSample.eventTimeBeforeCoalescing = eventTime;
entry->firstSample.next = NULL;
entry->lastSample = & entry->firstSample;
for (uint32_t i = 0; i < pointerCount; i++) {
@@ -3864,6 +3901,7 @@ void InputDispatcher::Allocator::appendMotionSample(MotionEntry* motionEntry,
nsecs_t eventTime, const PointerCoords* pointerCoords) {
MotionSample* sample = mMotionSamplePool.alloc();
sample->eventTime = eventTime;
sample->eventTimeBeforeCoalescing = eventTime;
uint32_t pointerCount = motionEntry->pointerCount;
for (uint32_t i = 0; i < pointerCount; i++) {
sample->pointerCoords[i].copyFrom(pointerCoords[i]);
@@ -3893,6 +3931,21 @@ uint32_t InputDispatcher::MotionEntry::countSamples() const {
return count;
}
bool InputDispatcher::MotionEntry::canAppendSamples(int32_t action, uint32_t pointerCount,
const int32_t* pointerIds) const {
if (this->action != action
|| this->pointerCount != pointerCount
|| this->isInjected()) {
return false;
}
for (uint32_t i = 0; i < pointerCount; i++) {
if (this->pointerIds[i] != pointerIds[i]) {
return false;
}
}
return true;
}
// --- InputDispatcher::InputState ---

14
services/input/InputDispatcher.h
View File

@@ -409,7 +409,7 @@ private:
bool dispatchInProgress; // initially false, set to true while dispatching
inline bool isInjected() { return injectionState != NULL; }
inline bool isInjected() const { return injectionState != NULL; }
};
struct ConfigurationChangedEntry : EventEntry {
@@ -439,7 +439,8 @@ private:
struct MotionSample {
MotionSample* next;
nsecs_t eventTime;
nsecs_t eventTime; // may be updated during coalescing
nsecs_t eventTimeBeforeCoalescing; // not updated during coalescing
PointerCoords pointerCoords[MAX_POINTERS];
};
@@ -461,6 +462,10 @@ private:
MotionSample* lastSample;
uint32_t countSamples() const;
// Checks whether we can append samples, assuming the device id and source are the same.
bool canAppendSamples(int32_t action, uint32_t pointerCount,
const int32_t* pointerIds) const;
};
// Tracks the progress of dispatching a particular event to a particular connection.
@@ -802,6 +807,11 @@ private:
void dispatchOnceInnerLocked(nsecs_t keyRepeatTimeout, nsecs_t keyRepeatDelay,
nsecs_t* nextWakeupTime);
// Batches a new sample onto a motion entry.
// Assumes that the we have already checked that we can append samples.
void batchMotionLocked(MotionEntry* entry, nsecs_t eventTime, int32_t metaState,
const PointerCoords* pointerCoords, const char* eventDescription);
// Enqueues an inbound event. Returns true if mLooper->wake() should be called.
bool enqueueInboundEventLocked(EventEntry* entry);