Pass latency information from app to input
Once the app learns about the frame's timeline, it will tell
inputdispatcher about it. We are adding a new callback similar to
'finishInputEvent', called 'reportLatencyInfo'.
This will tell inputdispatcher about the queue time and the present time
of each frame that was caused by input.
InputDispatcher will then be able to reconstruct the input event
timeline and report the end-to-end latency metrics.
In a separate CL, we will add LatencyTracker, which will eventually
receive this data.
Using the event id and the provided queue time and present time, we will
be able to reconstruct the end-to-end latency inside LatencyTracker.
Bug: 167947340
Test: atest inputflinger_tests libinput_tests
Change-Id: I181532a01b34eecd186bc3c74db289fc59c5955c
diff --git a/include/input/Input.h b/include/input/Input.h
index f9fe6b9..bb5ca0e 100644
--- a/include/input/Input.h
+++ b/include/input/Input.h
@@ -266,6 +266,20 @@
const char* motionClassificationToString(MotionClassification classification);
/**
+ * Portion of FrameMetrics timeline of interest to input code.
+ */
+enum GraphicsTimeline : size_t {
+ /** Time when the app sent the buffer to SurfaceFlinger. */
+ GPU_COMPLETED_TIME = 0,
+
+ /** Time when the frame was presented on the display */
+ PRESENT_TIME = 1,
+
+ /** Total size of the 'GraphicsTimeline' array. Must always be last. */
+ SIZE = 2
+};
+
+/**
* Generator of unique numbers used to identify input events.
*
* Layout of ID:
diff --git a/include/input/InputTransport.h b/include/input/InputTransport.h
index 3e5674e..898d1a9 100644
--- a/include/input/InputTransport.h
+++ b/include/input/InputTransport.h
@@ -71,6 +71,7 @@
FOCUS,
CAPTURE,
DRAG,
+ TIMELINE,
};
struct Header {
@@ -195,6 +196,14 @@
inline size_t size() const { return sizeof(Drag); }
} drag;
+
+ struct Timeline {
+ int32_t eventId;
+ uint32_t empty;
+ std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline;
+
+ inline size_t size() const { return sizeof(Timeline); }
+ } timeline;
} __attribute__((aligned(8))) body;
bool isValid(size_t actualSize) const;
@@ -381,10 +390,25 @@
nsecs_t consumeTime;
};
- /* Receives the finished signal from the consumer in reply to the original dispatch signal.
- * If a signal was received, returns a Finished object.
+ struct Timeline {
+ int32_t inputEventId;
+ std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline;
+ };
+
+ typedef std::variant<Finished, Timeline> ConsumerResponse;
+ /* Receive a signal from the consumer in reply to the original dispatch signal.
+ * If a signal was received, returns a Finished or a Timeline object.
+ * The InputConsumer should return a Finished object for every InputMessage that it is sent
+ * to confirm that it has been processed and that the InputConsumer is responsive.
+ * If several InputMessages are sent to InputConsumer, it's possible to receive Finished
+ * events out of order for those messages.
*
- * The returned sequence number is never 0 unless the operation failed.
+ * The Timeline object is returned whenever the receiving end has processed a graphical frame
+ * and is returning the timeline of the frame. Not all input events will cause a Timeline
+ * object to be returned, and there is not guarantee about when it will arrive.
+ *
+ * If an object of Finished is returned, the returned sequence number is never 0 unless the
+ * operation failed.
*
* Returned error codes:
* OK on success.
@@ -392,7 +416,7 @@
* DEAD_OBJECT if the channel's peer has been closed.
* Other errors probably indicate that the channel is broken.
*/
- android::base::Result<Finished> receiveFinishedSignal();
+ android::base::Result<ConsumerResponse> receiveConsumerResponse();
private:
std::shared_ptr<InputChannel> mChannel;
@@ -448,6 +472,9 @@
*/
status_t sendFinishedSignal(uint32_t seq, bool handled);
+ status_t sendTimeline(int32_t inputEventId,
+ std::array<nsecs_t, GraphicsTimeline::SIZE> timeline);
+
/* Returns true if there is a deferred event waiting.
*
* Should be called after calling consume() to determine whether the consumer
diff --git a/libs/input/InputTransport.cpp b/libs/input/InputTransport.cpp
index c2a3cf1..f7962e0 100644
--- a/libs/input/InputTransport.cpp
+++ b/libs/input/InputTransport.cpp
@@ -110,6 +110,12 @@
return true;
case Type::DRAG:
return true;
+ case Type::TIMELINE:
+ const nsecs_t gpuCompletedTime =
+ body.timeline.graphicsTimeline[GraphicsTimeline::GPU_COMPLETED_TIME];
+ const nsecs_t presentTime =
+ body.timeline.graphicsTimeline[GraphicsTimeline::PRESENT_TIME];
+ return presentTime > gpuCompletedTime;
}
}
return false;
@@ -129,6 +135,8 @@
return sizeof(Header) + body.capture.size();
case Type::DRAG:
return sizeof(Header) + body.drag.size();
+ case Type::TIMELINE:
+ return sizeof(Header) + body.timeline.size();
}
return sizeof(Header);
}
@@ -260,6 +268,11 @@
msg->body.drag.isExiting = body.drag.isExiting;
break;
}
+ case InputMessage::Type::TIMELINE: {
+ msg->body.timeline.eventId = body.timeline.eventId;
+ msg->body.timeline.graphicsTimeline = body.timeline.graphicsTimeline;
+ break;
+ }
}
}
@@ -629,7 +642,7 @@
return mChannel->sendMessage(&msg);
}
-android::base::Result<InputPublisher::Finished> InputPublisher::receiveFinishedSignal() {
+android::base::Result<InputPublisher::ConsumerResponse> InputPublisher::receiveConsumerResponse() {
if (DEBUG_TRANSPORT_ACTIONS) {
ALOGD("channel '%s' publisher ~ %s", mChannel->getName().c_str(), __func__);
}
@@ -639,16 +652,24 @@
if (result) {
return android::base::Error(result);
}
- if (msg.header.type != InputMessage::Type::FINISHED) {
- ALOGE("channel '%s' publisher ~ Received unexpected %s message from consumer",
- mChannel->getName().c_str(), NamedEnum::string(msg.header.type).c_str());
- return android::base::Error(UNKNOWN_ERROR);
+ if (msg.header.type == InputMessage::Type::FINISHED) {
+ return Finished{
+ .seq = msg.header.seq,
+ .handled = msg.body.finished.handled,
+ .consumeTime = msg.body.finished.consumeTime,
+ };
}
- return Finished{
- .seq = msg.header.seq,
- .handled = msg.body.finished.handled,
- .consumeTime = msg.body.finished.consumeTime,
- };
+
+ if (msg.header.type == InputMessage::Type::TIMELINE) {
+ return Timeline{
+ .inputEventId = msg.body.timeline.eventId,
+ .graphicsTimeline = msg.body.timeline.graphicsTimeline,
+ };
+ }
+
+ ALOGE("channel '%s' publisher ~ Received unexpected %s message from consumer",
+ mChannel->getName().c_str(), NamedEnum::string(msg.header.type).c_str());
+ return android::base::Error(UNKNOWN_ERROR);
}
// --- InputConsumer ---
@@ -785,7 +806,8 @@
break;
}
- case InputMessage::Type::FINISHED: {
+ case InputMessage::Type::FINISHED:
+ case InputMessage::Type::TIMELINE: {
LOG_ALWAYS_FATAL("Consumed a %s message, which should never be seen by "
"InputConsumer!",
NamedEnum::string(mMsg.header.type).c_str());
@@ -1193,6 +1215,24 @@
return sendUnchainedFinishedSignal(seq, handled);
}
+status_t InputConsumer::sendTimeline(int32_t inputEventId,
+ std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline) {
+ if (DEBUG_TRANSPORT_ACTIONS) {
+ ALOGD("channel '%s' consumer ~ sendTimeline: inputEventId=%" PRId32
+ ", gpuCompletedTime=%" PRId64 ", presentTime=%" PRId64,
+ mChannel->getName().c_str(), inputEventId,
+ graphicsTimeline[GraphicsTimeline::GPU_COMPLETED_TIME],
+ graphicsTimeline[GraphicsTimeline::PRESENT_TIME]);
+ }
+
+ InputMessage msg;
+ msg.header.type = InputMessage::Type::TIMELINE;
+ msg.header.seq = 0;
+ msg.body.timeline.eventId = inputEventId;
+ msg.body.timeline.graphicsTimeline = std::move(graphicsTimeline);
+ return mChannel->sendMessage(&msg);
+}
+
nsecs_t InputConsumer::getConsumeTime(uint32_t seq) const {
auto it = mConsumeTimes.find(seq);
// Consume time will be missing if either 'finishInputEvent' is called twice, or if it was
@@ -1399,6 +1439,19 @@
toString(msg.body.drag.isExiting));
break;
}
+ case InputMessage::Type::TIMELINE: {
+ const nsecs_t gpuCompletedTime =
+ msg.body.timeline
+ .graphicsTimeline[GraphicsTimeline::GPU_COMPLETED_TIME];
+ const nsecs_t presentTime =
+ msg.body.timeline.graphicsTimeline[GraphicsTimeline::PRESENT_TIME];
+ out += android::base::StringPrintf("inputEventId=%" PRId32
+ ", gpuCompletedTime=%" PRId64
+ ", presentTime=%" PRId64,
+ msg.body.timeline.eventId, gpuCompletedTime,
+ presentTime);
+ break;
+ }
}
out += "\n";
}
diff --git a/libs/input/tests/InputPublisherAndConsumer_test.cpp b/libs/input/tests/InputPublisherAndConsumer_test.cpp
index fc31715..088e00b 100644
--- a/libs/input/tests/InputPublisherAndConsumer_test.cpp
+++ b/libs/input/tests/InputPublisherAndConsumer_test.cpp
@@ -124,13 +124,15 @@
ASSERT_EQ(OK, status)
<< "consumer sendFinishedSignal should return OK";
- Result<InputPublisher::Finished> result = mPublisher->receiveFinishedSignal();
- ASSERT_TRUE(result.ok()) << "publisher receiveFinishedSignal should return OK";
- ASSERT_EQ(seq, result->seq)
- << "receiveFinishedSignal should have returned the original sequence number";
- ASSERT_TRUE(result->handled)
- << "receiveFinishedSignal should have set handled to consumer's reply";
- ASSERT_GE(result->consumeTime, publishTime)
+ Result<InputPublisher::ConsumerResponse> result = mPublisher->receiveConsumerResponse();
+ ASSERT_TRUE(result.ok()) << "receiveConsumerResponse should return OK";
+ ASSERT_TRUE(std::holds_alternative<InputPublisher::Finished>(*result));
+ const InputPublisher::Finished& finish = std::get<InputPublisher::Finished>(*result);
+ ASSERT_EQ(seq, finish.seq)
+ << "receiveConsumerResponse should have returned the original sequence number";
+ ASSERT_TRUE(finish.handled)
+ << "receiveConsumerResponse should have set handled to consumer's reply";
+ ASSERT_GE(finish.consumeTime, publishTime)
<< "finished signal's consume time should be greater than publish time";
}
@@ -264,13 +266,15 @@
ASSERT_EQ(OK, status)
<< "consumer sendFinishedSignal should return OK";
- Result<InputPublisher::Finished> result = mPublisher->receiveFinishedSignal();
- ASSERT_TRUE(result.ok()) << "receiveFinishedSignal should return OK";
- ASSERT_EQ(seq, result->seq)
- << "receiveFinishedSignal should have returned the original sequence number";
- ASSERT_FALSE(result->handled)
- << "receiveFinishedSignal should have set handled to consumer's reply";
- ASSERT_GE(result->consumeTime, publishTime)
+ Result<InputPublisher::ConsumerResponse> result = mPublisher->receiveConsumerResponse();
+ ASSERT_TRUE(result.ok()) << "receiveConsumerResponse should return OK";
+ ASSERT_TRUE(std::holds_alternative<InputPublisher::Finished>(*result));
+ const InputPublisher::Finished& finish = std::get<InputPublisher::Finished>(*result);
+ ASSERT_EQ(seq, finish.seq)
+ << "receiveConsumerResponse should have returned the original sequence number";
+ ASSERT_FALSE(finish.handled)
+ << "receiveConsumerResponse should have set handled to consumer's reply";
+ ASSERT_GE(finish.consumeTime, publishTime)
<< "finished signal's consume time should be greater than publish time";
}
@@ -304,14 +308,16 @@
status = mConsumer->sendFinishedSignal(seq, true);
ASSERT_EQ(OK, status) << "consumer sendFinishedSignal should return OK";
- Result<InputPublisher::Finished> result = mPublisher->receiveFinishedSignal();
+ Result<InputPublisher::ConsumerResponse> result = mPublisher->receiveConsumerResponse();
+ ASSERT_TRUE(result.ok()) << "receiveConsumerResponse should return OK";
+ ASSERT_TRUE(std::holds_alternative<InputPublisher::Finished>(*result));
+ const InputPublisher::Finished& finish = std::get<InputPublisher::Finished>(*result);
- ASSERT_TRUE(result.ok()) << "receiveFinishedSignal should return OK";
- ASSERT_EQ(seq, result->seq)
- << "receiveFinishedSignal should have returned the original sequence number";
- ASSERT_TRUE(result->handled)
- << "receiveFinishedSignal should have set handled to consumer's reply";
- ASSERT_GE(result->consumeTime, publishTime)
+ ASSERT_EQ(seq, finish.seq)
+ << "receiveConsumerResponse should have returned the original sequence number";
+ ASSERT_TRUE(finish.handled)
+ << "receiveConsumerResponse should have set handled to consumer's reply";
+ ASSERT_GE(finish.consumeTime, publishTime)
<< "finished signal's consume time should be greater than publish time";
}
@@ -343,13 +349,15 @@
status = mConsumer->sendFinishedSignal(seq, true);
ASSERT_EQ(OK, status) << "consumer sendFinishedSignal should return OK";
- android::base::Result<InputPublisher::Finished> result = mPublisher->receiveFinishedSignal();
- ASSERT_TRUE(result.ok()) << "publisher receiveFinishedSignal should return OK";
- ASSERT_EQ(seq, result->seq)
- << "receiveFinishedSignal should have returned the original sequence number";
- ASSERT_TRUE(result->handled)
- << "receiveFinishedSignal should have set handled to consumer's reply";
- ASSERT_GE(result->consumeTime, publishTime)
+ Result<InputPublisher::ConsumerResponse> result = mPublisher->receiveConsumerResponse();
+ ASSERT_TRUE(result.ok()) << "receiveConsumerResponse should return OK";
+ ASSERT_TRUE(std::holds_alternative<InputPublisher::Finished>(*result));
+ const InputPublisher::Finished& finish = std::get<InputPublisher::Finished>(*result);
+ ASSERT_EQ(seq, finish.seq)
+ << "receiveConsumerResponse should have returned the original sequence number";
+ ASSERT_TRUE(finish.handled)
+ << "receiveConsumerResponse should have set handled to consumer's reply";
+ ASSERT_GE(finish.consumeTime, publishTime)
<< "finished signal's consume time should be greater than publish time";
}
@@ -385,16 +393,34 @@
status = mConsumer->sendFinishedSignal(seq, true);
ASSERT_EQ(OK, status) << "consumer sendFinishedSignal should return OK";
- android::base::Result<InputPublisher::Finished> result = mPublisher->receiveFinishedSignal();
- ASSERT_TRUE(result.ok()) << "publisher receiveFinishedSignal should return OK";
- ASSERT_EQ(seq, result->seq)
- << "publisher receiveFinishedSignal should have returned the original sequence number";
- ASSERT_TRUE(result->handled)
- << "publisher receiveFinishedSignal should have set handled to consumer's reply";
- ASSERT_GE(result->consumeTime, publishTime)
+ Result<InputPublisher::ConsumerResponse> result = mPublisher->receiveConsumerResponse();
+ ASSERT_TRUE(result.ok()) << "receiveConsumerResponse should return OK";
+ ASSERT_TRUE(std::holds_alternative<InputPublisher::Finished>(*result));
+ const InputPublisher::Finished& finish = std::get<InputPublisher::Finished>(*result);
+ ASSERT_EQ(seq, finish.seq)
+ << "receiveConsumerResponse should have returned the original sequence number";
+ ASSERT_TRUE(finish.handled)
+ << "receiveConsumerResponse should have set handled to consumer's reply";
+ ASSERT_GE(finish.consumeTime, publishTime)
<< "finished signal's consume time should be greater than publish time";
}
+TEST_F(InputPublisherAndConsumerTest, SendTimeline) {
+ const int32_t inputEventId = 20;
+ std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline;
+ graphicsTimeline[GraphicsTimeline::GPU_COMPLETED_TIME] = 30;
+ graphicsTimeline[GraphicsTimeline::PRESENT_TIME] = 40;
+ status_t status = mConsumer->sendTimeline(inputEventId, graphicsTimeline);
+ ASSERT_EQ(OK, status);
+
+ Result<InputPublisher::ConsumerResponse> result = mPublisher->receiveConsumerResponse();
+ ASSERT_TRUE(result.ok()) << "receiveConsumerResponse should return OK";
+ ASSERT_TRUE(std::holds_alternative<InputPublisher::Timeline>(*result));
+ const InputPublisher::Timeline& timeline = std::get<InputPublisher::Timeline>(*result);
+ ASSERT_EQ(inputEventId, timeline.inputEventId);
+ ASSERT_EQ(graphicsTimeline, timeline.graphicsTimeline);
+}
+
TEST_F(InputPublisherAndConsumerTest, PublishKeyEvent_EndToEnd) {
ASSERT_NO_FATAL_FAILURE(PublishAndConsumeKeyEvent());
}
diff --git a/libs/input/tests/StructLayout_test.cpp b/libs/input/tests/StructLayout_test.cpp
index 3d80b38..585779e 100644
--- a/libs/input/tests/StructLayout_test.cpp
+++ b/libs/input/tests/StructLayout_test.cpp
@@ -96,6 +96,10 @@
CHECK_OFFSET(InputMessage::Body::Finished, handled, 0);
CHECK_OFFSET(InputMessage::Body::Finished, empty, 1);
CHECK_OFFSET(InputMessage::Body::Finished, consumeTime, 8);
+
+ CHECK_OFFSET(InputMessage::Body::Timeline, eventId, 0);
+ CHECK_OFFSET(InputMessage::Body::Timeline, empty, 4);
+ CHECK_OFFSET(InputMessage::Body::Timeline, graphicsTimeline, 8);
}
void TestHeaderSize() {
@@ -117,6 +121,9 @@
static_assert(sizeof(InputMessage::Body::Focus) == 8);
static_assert(sizeof(InputMessage::Body::Capture) == 8);
static_assert(sizeof(InputMessage::Body::Drag) == 16);
+ // Timeline
+ static_assert(GraphicsTimeline::SIZE == 2);
+ static_assert(sizeof(InputMessage::Body::Timeline) == 24);
}
// --- VerifiedInputEvent ---
diff --git a/services/inputflinger/dispatcher/InputDispatcher.cpp b/services/inputflinger/dispatcher/InputDispatcher.cpp
index 397a9d7..de7acf9 100644
--- a/services/inputflinger/dispatcher/InputDispatcher.cpp
+++ b/services/inputflinger/dispatcher/InputDispatcher.cpp
@@ -3290,15 +3290,21 @@
bool gotOne = false;
status_t status = OK;
for (;;) {
- Result<InputPublisher::Finished> result =
- connection->inputPublisher.receiveFinishedSignal();
+ Result<InputPublisher::ConsumerResponse> result =
+ connection->inputPublisher.receiveConsumerResponse();
if (!result.ok()) {
status = result.error().code();
break;
}
- const InputPublisher::Finished& finished = *result;
- d->finishDispatchCycleLocked(currentTime, connection, finished.seq,
- finished.handled, finished.consumeTime);
+
+ if (std::holds_alternative<InputPublisher::Finished>(*result)) {
+ const InputPublisher::Finished& finish =
+ std::get<InputPublisher::Finished>(*result);
+ d->finishDispatchCycleLocked(currentTime, connection, finish.seq,
+ finish.handled, finish.consumeTime);
+ } else if (std::holds_alternative<InputPublisher::Timeline>(*result)) {
+ // TODO(b/167947340): Report this data to LatencyTracker
+ }
gotOne = true;
}
if (gotOne) {
diff --git a/services/inputflinger/tests/InputDispatcher_test.cpp b/services/inputflinger/tests/InputDispatcher_test.cpp
index cedda6e..d1bd38e 100644
--- a/services/inputflinger/tests/InputDispatcher_test.cpp
+++ b/services/inputflinger/tests/InputDispatcher_test.cpp
@@ -740,6 +740,11 @@
ASSERT_EQ(OK, status) << mName.c_str() << ": consumer sendFinishedSignal should return OK.";
}
+ void sendTimeline(int32_t inputEventId, std::array<nsecs_t, GraphicsTimeline::SIZE> timeline) {
+ const status_t status = mConsumer->sendTimeline(inputEventId, timeline);
+ ASSERT_EQ(OK, status);
+ }
+
void consumeEvent(int32_t expectedEventType, int32_t expectedAction,
std::optional<int32_t> expectedDisplayId,
std::optional<int32_t> expectedFlags) {
@@ -1052,6 +1057,11 @@
mInputReceiver->finishEvent(sequenceNum);
}
+ void sendTimeline(int32_t inputEventId, std::array<nsecs_t, GraphicsTimeline::SIZE> timeline) {
+ ASSERT_NE(mInputReceiver, nullptr) << "Invalid receive event on window with no receiver";
+ mInputReceiver->sendTimeline(inputEventId, timeline);
+ }
+
InputEvent* consume() {
if (mInputReceiver == nullptr) {
return nullptr;
@@ -1954,6 +1964,21 @@
secondWindow->assertNoEvents();
}
+TEST_F(InputDispatcherTest, SendTimeline_DoesNotCrashDispatcher) {
+ std::shared_ptr<FakeApplicationHandle> application = std::make_shared<FakeApplicationHandle>();
+
+ sp<FakeWindowHandle> window =
+ new FakeWindowHandle(application, mDispatcher, "Window", ADISPLAY_ID_DEFAULT);
+ mDispatcher->setInputWindows({{ADISPLAY_ID_DEFAULT, {window}}});
+ std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline;
+ graphicsTimeline[GraphicsTimeline::GPU_COMPLETED_TIME] = 2;
+ graphicsTimeline[GraphicsTimeline::PRESENT_TIME] = 3;
+
+ window->sendTimeline(1 /*inputEventId*/, graphicsTimeline);
+ window->assertNoEvents();
+ mDispatcher->waitForIdle();
+}
+
class FakeMonitorReceiver {
public:
FakeMonitorReceiver(const sp<InputDispatcher>& dispatcher, const std::string name,