184 lines
7.6 KiB
C++
184 lines
7.6 KiB
C++
/*
|
|
* Copyright (C) 2021 The Android Open Source Project
|
|
*
|
|
* Licensed under the Apache License, Version 2.0 (the "License");
|
|
* you may not use this file except in compliance with the License.
|
|
* You may obtain a copy of the License at
|
|
*
|
|
* http://www.apache.org/licenses/LICENSE-2.0
|
|
*
|
|
* Unless required by applicable law or agreed to in writing, software
|
|
* distributed under the License is distributed on an "AS IS" BASIS,
|
|
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
|
|
* See the License for the specific language governing permissions and
|
|
* limitations under the License.
|
|
*/
|
|
|
|
#define LOG_TAG "LatencyTracker"
|
|
#include "LatencyTracker.h"
|
|
|
|
#include <inttypes.h>
|
|
|
|
#include <android-base/properties.h>
|
|
#include <android-base/stringprintf.h>
|
|
#include <android/os/IInputConstants.h>
|
|
#include <input/Input.h>
|
|
#include <log/log.h>
|
|
|
|
using android::base::HwTimeoutMultiplier;
|
|
using android::base::StringPrintf;
|
|
|
|
namespace android::inputdispatcher {
|
|
|
|
/**
|
|
* Events that are older than this time will be considered mature, at which point we will stop
|
|
* waiting for the apps to provide further information about them.
|
|
* It's likely that the apps will ANR if the events are not received by this deadline, and we
|
|
* already track ANR metrics separately.
|
|
*/
|
|
const std::chrono::duration ANR_TIMEOUT = std::chrono::milliseconds(
|
|
android::os::IInputConstants::UNMULTIPLIED_DEFAULT_DISPATCHING_TIMEOUT_MILLIS *
|
|
HwTimeoutMultiplier());
|
|
|
|
static bool isMatureEvent(nsecs_t eventTime, nsecs_t now) {
|
|
std::chrono::duration age = std::chrono::nanoseconds(now) - std::chrono::nanoseconds(eventTime);
|
|
return age > ANR_TIMEOUT;
|
|
}
|
|
|
|
/**
|
|
* A multimap allows to have several entries with the same key. This function just erases a specific
|
|
* key-value pair. Equivalent to the imaginary std api std::multimap::erase(key, value).
|
|
*/
|
|
template <typename K, typename V>
|
|
static void eraseByKeyAndValue(std::multimap<K, V>& map, K key, V value) {
|
|
auto iterpair = map.equal_range(key);
|
|
|
|
for (auto it = iterpair.first; it != iterpair.second; ++it) {
|
|
if (it->second == value) {
|
|
map.erase(it);
|
|
break;
|
|
}
|
|
}
|
|
}
|
|
|
|
LatencyTracker::LatencyTracker(InputEventTimelineProcessor* processor)
|
|
: mTimelineProcessor(processor) {
|
|
LOG_ALWAYS_FATAL_IF(processor == nullptr);
|
|
}
|
|
|
|
void LatencyTracker::trackListener(int32_t inputEventId, bool isDown, nsecs_t eventTime,
|
|
nsecs_t readTime) {
|
|
reportAndPruneMatureRecords(eventTime);
|
|
const auto it = mTimelines.find(inputEventId);
|
|
if (it != mTimelines.end()) {
|
|
// Input event ids are randomly generated, so it's possible that two events have the same
|
|
// event id. Drop this event, and also drop the existing event because the apps would
|
|
// confuse us by reporting the rest of the timeline for one of them. This should happen
|
|
// rarely, so we won't lose much data
|
|
mTimelines.erase(it);
|
|
// In case we have another input event with a different id and at the same eventTime,
|
|
// only erase this specific inputEventId.
|
|
eraseByKeyAndValue(mEventTimes, eventTime, inputEventId);
|
|
return;
|
|
}
|
|
mTimelines.emplace(inputEventId, InputEventTimeline(isDown, eventTime, readTime));
|
|
mEventTimes.emplace(eventTime, inputEventId);
|
|
}
|
|
|
|
void LatencyTracker::trackFinishedEvent(int32_t inputEventId, const sp<IBinder>& connectionToken,
|
|
nsecs_t deliveryTime, nsecs_t consumeTime,
|
|
nsecs_t finishTime) {
|
|
const auto it = mTimelines.find(inputEventId);
|
|
if (it == mTimelines.end()) {
|
|
// It's possible that an app sends a bad (or late)'Finish' signal, since it's free to do
|
|
// anything in its process. Just drop the report and move on.
|
|
return;
|
|
}
|
|
|
|
InputEventTimeline& timeline = it->second;
|
|
const auto connectionIt = timeline.connectionTimelines.find(connectionToken);
|
|
if (connectionIt == timeline.connectionTimelines.end()) {
|
|
// Most likely case: app calls 'finishInputEvent' before it reports the graphics timeline
|
|
timeline.connectionTimelines.emplace(connectionToken,
|
|
ConnectionTimeline{deliveryTime, consumeTime,
|
|
finishTime});
|
|
} else {
|
|
// Already have a record for this connectionToken
|
|
ConnectionTimeline& connectionTimeline = connectionIt->second;
|
|
const bool success =
|
|
connectionTimeline.setDispatchTimeline(deliveryTime, consumeTime, finishTime);
|
|
if (!success) {
|
|
// We are receiving unreliable data from the app. Just delete the entire connection
|
|
// timeline for this event
|
|
timeline.connectionTimelines.erase(connectionIt);
|
|
}
|
|
}
|
|
}
|
|
|
|
void LatencyTracker::trackGraphicsLatency(
|
|
int32_t inputEventId, const sp<IBinder>& connectionToken,
|
|
std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline) {
|
|
const auto it = mTimelines.find(inputEventId);
|
|
if (it == mTimelines.end()) {
|
|
// It's possible that an app sends a bad (or late) 'Timeline' signal, since it's free to do
|
|
// anything in its process. Just drop the report and move on.
|
|
return;
|
|
}
|
|
|
|
InputEventTimeline& timeline = it->second;
|
|
const auto connectionIt = timeline.connectionTimelines.find(connectionToken);
|
|
if (connectionIt == timeline.connectionTimelines.end()) {
|
|
timeline.connectionTimelines.emplace(connectionToken, std::move(graphicsTimeline));
|
|
} else {
|
|
// Most likely case
|
|
ConnectionTimeline& connectionTimeline = connectionIt->second;
|
|
const bool success = connectionTimeline.setGraphicsTimeline(std::move(graphicsTimeline));
|
|
if (!success) {
|
|
// We are receiving unreliable data from the app. Just delete the entire connection
|
|
// timeline for this event
|
|
timeline.connectionTimelines.erase(connectionIt);
|
|
}
|
|
}
|
|
}
|
|
|
|
/**
|
|
* We should use the current time 'now()' here to determine the age of the event, but instead we
|
|
* are using the latest 'eventTime' for efficiency since this time is already acquired, and
|
|
* 'trackListener' should happen soon after the event occurs.
|
|
*/
|
|
void LatencyTracker::reportAndPruneMatureRecords(nsecs_t newEventTime) {
|
|
while (!mEventTimes.empty()) {
|
|
const auto& [oldestEventTime, oldestInputEventId] = *mEventTimes.begin();
|
|
if (isMatureEvent(oldestEventTime, newEventTime /*now*/)) {
|
|
// Report and drop this event
|
|
const auto it = mTimelines.find(oldestInputEventId);
|
|
LOG_ALWAYS_FATAL_IF(it == mTimelines.end(),
|
|
"Event %" PRId32 " is in mEventTimes, but not in mTimelines",
|
|
oldestInputEventId);
|
|
const InputEventTimeline& timeline = it->second;
|
|
mTimelineProcessor->processTimeline(timeline);
|
|
mTimelines.erase(it);
|
|
mEventTimes.erase(mEventTimes.begin());
|
|
} else {
|
|
// If the oldest event does not need to be pruned, no events should be pruned.
|
|
return;
|
|
}
|
|
}
|
|
}
|
|
|
|
void LatencyTracker::reportNow() {
|
|
for (const auto& [inputEventId, timeline] : mTimelines) {
|
|
mTimelineProcessor->processTimeline(timeline);
|
|
}
|
|
mTimelines.clear();
|
|
mEventTimes.clear();
|
|
}
|
|
|
|
std::string LatencyTracker::dump(const char* prefix) {
|
|
return StringPrintf("%sLatencyTracker:\n", prefix) +
|
|
StringPrintf("%s mTimelines.size() = %zu\n", prefix, mTimelines.size()) +
|
|
StringPrintf("%s mEventTimes.size() = %zu\n", prefix, mEventTimes.size());
|
|
}
|
|
|
|
} // namespace android::inputdispatcher
|