Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 1 | /* |
| 2 | * Copyright 2018 The Android Open Source Project |
| 3 | * |
| 4 | * Licensed under the Apache License, Version 2.0 (the "License"); |
| 5 | * you may not use this file except in compliance with the License. |
| 6 | * You may obtain a copy of the License at |
| 7 | * |
| 8 | * http://www.apache.org/licenses/LICENSE-2.0 |
| 9 | * |
| 10 | * Unless required by applicable law or agreed to in writing, software |
| 11 | * distributed under the License is distributed on an "AS IS" BASIS, |
| 12 | * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| 13 | * See the License for the specific language governing permissions and |
| 14 | * limitations under the License. |
| 15 | */ |
| 16 | #undef LOG_TAG |
| 17 | #define LOG_TAG "TimeStats" |
| 18 | #define ATRACE_TAG ATRACE_TAG_GRAPHICS |
| 19 | |
| 20 | #include "TimeStats.h" |
| 21 | |
| 22 | #include <android-base/stringprintf.h> |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 23 | #include <log/log.h> |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 24 | #include <utils/String8.h> |
Yiwei Zhang | 3a226d2 | 2018-10-16 09:23:03 -0700 | [diff] [blame] | 25 | #include <utils/Timers.h> |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 26 | #include <utils/Trace.h> |
| 27 | |
| 28 | #include <algorithm> |
Alec Mouri | 9519bf1 | 2019-11-15 16:54:44 -0800 | [diff] [blame] | 29 | #include <chrono> |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 30 | |
| 31 | namespace android { |
| 32 | |
Alec Mouri | fb571ea | 2019-01-24 18:42:10 -0800 | [diff] [blame] | 33 | namespace impl { |
| 34 | |
Alec Mouri | d506545 | 2019-12-07 18:18:48 -0800 | [diff] [blame^] | 35 | bool TimeStats::pullGlobalAtomCallback(int32_t atom_tag, pulled_stats_event_list* data, |
| 36 | const void* cookie) { |
| 37 | impl::TimeStats* timeStats = |
| 38 | const_cast<impl::TimeStats*>(reinterpret_cast<const impl::TimeStats*>(cookie)); |
| 39 | if (atom_tag != android::util::SURFACEFLINGER_STATS_GLOBAL_INFO) { |
| 40 | return false; |
| 41 | } |
| 42 | |
| 43 | std::lock_guard<std::mutex> lock(timeStats->mMutex); |
| 44 | |
| 45 | const auto& stats = timeStats->mTimeStats; |
| 46 | if (stats.statsStart == 0) { |
| 47 | return false; |
| 48 | } |
| 49 | timeStats->flushPowerTimeLocked(); |
| 50 | |
| 51 | struct stats_event* event = timeStats->mStatsDelegate->addStatsEventToPullData(data); |
| 52 | timeStats->mStatsDelegate->statsEventSetAtomId(event, |
| 53 | android::util::SURFACEFLINGER_STATS_GLOBAL_INFO); |
| 54 | timeStats->mStatsDelegate->statsEventWriteInt64(event, stats.totalFrames); |
| 55 | timeStats->mStatsDelegate->statsEventWriteInt64(event, stats.missedFrames); |
| 56 | timeStats->mStatsDelegate->statsEventWriteInt64(event, stats.clientCompositionFrames); |
| 57 | timeStats->mStatsDelegate->statsEventWriteInt64(event, stats.displayOnTime); |
| 58 | timeStats->mStatsDelegate->statsEventWriteInt64(event, stats.presentToPresent.totalTime()); |
| 59 | timeStats->mStatsDelegate->statsEventBuild(event); |
| 60 | timeStats->clearGlobalLocked(); |
| 61 | |
| 62 | return true; |
| 63 | } |
| 64 | |
Alec Mouri | b3885ad | 2019-09-06 17:08:55 -0700 | [diff] [blame] | 65 | TimeStats::TimeStats() { |
| 66 | // Temporarily enable TimeStats by default. Telemetry is disabled while |
| 67 | // we move onto statsd, so TimeStats is currently not exercised at all |
Alec Mouri | d506545 | 2019-12-07 18:18:48 -0800 | [diff] [blame^] | 68 | // during testing without enabling by default. |
| 69 | // TODO: remove this, as we should only be paying this overhead on devices |
| 70 | // where statsd exists. |
Alec Mouri | b3885ad | 2019-09-06 17:08:55 -0700 | [diff] [blame] | 71 | enable(); |
| 72 | } |
| 73 | |
Alec Mouri | d506545 | 2019-12-07 18:18:48 -0800 | [diff] [blame^] | 74 | TimeStats::TimeStats(std::unique_ptr<StatsEventDelegate> statsDelegate) : TimeStats() { |
| 75 | mStatsDelegate = std::move(statsDelegate); |
| 76 | } |
| 77 | |
| 78 | void TimeStats::onBootFinished() { |
| 79 | std::lock_guard<std::mutex> lock(mMutex); |
| 80 | mRegisteredCallback = false; |
| 81 | } |
| 82 | |
Dominik Laskowski | c286714 | 2019-01-21 11:33:38 -0800 | [diff] [blame] | 83 | void TimeStats::parseArgs(bool asProto, const Vector<String16>& args, std::string& result) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 84 | ATRACE_CALL(); |
| 85 | |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 86 | std::unordered_map<std::string, int32_t> argsMap; |
Dominik Laskowski | c286714 | 2019-01-21 11:33:38 -0800 | [diff] [blame] | 87 | for (size_t index = 0; index < args.size(); ++index) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 88 | argsMap[std::string(String8(args[index]).c_str())] = index; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 89 | } |
| 90 | |
| 91 | if (argsMap.count("-disable")) { |
| 92 | disable(); |
| 93 | } |
| 94 | |
| 95 | if (argsMap.count("-dump")) { |
Yiwei Zhang | 8a4015c | 2018-05-08 16:03:47 -0700 | [diff] [blame] | 96 | std::optional<uint32_t> maxLayers = std::nullopt; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 97 | auto iter = argsMap.find("-maxlayers"); |
| 98 | if (iter != argsMap.end() && iter->second + 1 < static_cast<int32_t>(args.size())) { |
Yiwei Zhang | 8a4015c | 2018-05-08 16:03:47 -0700 | [diff] [blame] | 99 | int64_t value = strtol(String8(args[iter->second + 1]).c_str(), nullptr, 10); |
| 100 | value = std::clamp(value, int64_t(0), int64_t(UINT32_MAX)); |
| 101 | maxLayers = static_cast<uint32_t>(value); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 102 | } |
| 103 | |
Yiwei Zhang | 8a4015c | 2018-05-08 16:03:47 -0700 | [diff] [blame] | 104 | dump(asProto, maxLayers, result); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 105 | } |
| 106 | |
| 107 | if (argsMap.count("-clear")) { |
Alec Mouri | d506545 | 2019-12-07 18:18:48 -0800 | [diff] [blame^] | 108 | clearAll(); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 109 | } |
| 110 | |
| 111 | if (argsMap.count("-enable")) { |
| 112 | enable(); |
| 113 | } |
| 114 | } |
| 115 | |
Yiwei Zhang | 7eb58b7 | 2019-04-22 19:00:02 -0700 | [diff] [blame] | 116 | std::string TimeStats::miniDump() { |
| 117 | ATRACE_CALL(); |
| 118 | |
| 119 | std::string result = "TimeStats miniDump:\n"; |
| 120 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | e926ab5 | 2019-08-14 15:16:00 -0700 | [diff] [blame] | 121 | android::base::StringAppendF(&result, "Number of layers currently being tracked is %zu\n", |
Yiwei Zhang | 7eb58b7 | 2019-04-22 19:00:02 -0700 | [diff] [blame] | 122 | mTimeStatsTracker.size()); |
Yiwei Zhang | e926ab5 | 2019-08-14 15:16:00 -0700 | [diff] [blame] | 123 | android::base::StringAppendF(&result, "Number of layers in the stats pool is %zu\n", |
| 124 | mTimeStats.stats.size()); |
Yiwei Zhang | 7eb58b7 | 2019-04-22 19:00:02 -0700 | [diff] [blame] | 125 | return result; |
| 126 | } |
| 127 | |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 128 | void TimeStats::incrementTotalFrames() { |
| 129 | if (!mEnabled.load()) return; |
| 130 | |
| 131 | ATRACE_CALL(); |
| 132 | |
| 133 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | dc22404 | 2018-10-18 15:34:00 -0700 | [diff] [blame] | 134 | mTimeStats.totalFrames++; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 135 | } |
| 136 | |
Yiwei Zhang | 621f9d4 | 2018-05-07 10:40:55 -0700 | [diff] [blame] | 137 | void TimeStats::incrementMissedFrames() { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 138 | if (!mEnabled.load()) return; |
| 139 | |
| 140 | ATRACE_CALL(); |
| 141 | |
| 142 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | dc22404 | 2018-10-18 15:34:00 -0700 | [diff] [blame] | 143 | mTimeStats.missedFrames++; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 144 | } |
| 145 | |
| 146 | void TimeStats::incrementClientCompositionFrames() { |
| 147 | if (!mEnabled.load()) return; |
| 148 | |
| 149 | ATRACE_CALL(); |
| 150 | |
| 151 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | dc22404 | 2018-10-18 15:34:00 -0700 | [diff] [blame] | 152 | mTimeStats.clientCompositionFrames++; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 153 | } |
| 154 | |
Alec Mouri | 9519bf1 | 2019-11-15 16:54:44 -0800 | [diff] [blame] | 155 | static int32_t msBetween(nsecs_t start, nsecs_t end) { |
| 156 | int64_t delta = std::chrono::duration_cast<std::chrono::milliseconds>( |
| 157 | std::chrono::nanoseconds(end - start)) |
| 158 | .count(); |
| 159 | delta = std::clamp(delta, int64_t(INT32_MIN), int64_t(INT32_MAX)); |
| 160 | return static_cast<int32_t>(delta); |
| 161 | } |
| 162 | |
| 163 | void TimeStats::recordFrameDuration(nsecs_t startTime, nsecs_t endTime) { |
| 164 | if (!mEnabled.load()) return; |
| 165 | |
| 166 | std::lock_guard<std::mutex> lock(mMutex); |
| 167 | if (mPowerTime.powerMode == HWC_POWER_MODE_NORMAL) { |
| 168 | mTimeStats.frameDuration.insert(msBetween(startTime, endTime)); |
| 169 | } |
| 170 | } |
| 171 | |
Alec Mouri | e4034bb | 2019-11-19 12:45:54 -0800 | [diff] [blame] | 172 | void TimeStats::recordRenderEngineDuration(nsecs_t startTime, nsecs_t endTime) { |
| 173 | if (!mEnabled.load()) return; |
| 174 | |
| 175 | std::lock_guard<std::mutex> lock(mMutex); |
| 176 | if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) { |
| 177 | ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS); |
| 178 | mGlobalRecord.renderEngineDurations.pop_front(); |
| 179 | } |
| 180 | mGlobalRecord.renderEngineDurations.push_back({startTime, endTime}); |
| 181 | } |
| 182 | |
| 183 | void TimeStats::recordRenderEngineDuration(nsecs_t startTime, |
| 184 | const std::shared_ptr<FenceTime>& endTime) { |
| 185 | if (!mEnabled.load()) return; |
| 186 | |
| 187 | std::lock_guard<std::mutex> lock(mMutex); |
| 188 | if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) { |
| 189 | ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS); |
| 190 | mGlobalRecord.renderEngineDurations.pop_front(); |
| 191 | } |
| 192 | mGlobalRecord.renderEngineDurations.push_back({startTime, endTime}); |
| 193 | } |
| 194 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 195 | bool TimeStats::recordReadyLocked(int32_t layerId, TimeRecord* timeRecord) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 196 | if (!timeRecord->ready) { |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 197 | ALOGV("[%d]-[%" PRIu64 "]-presentFence is still not received", layerId, |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 198 | timeRecord->frameTime.frameNumber); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 199 | return false; |
| 200 | } |
| 201 | |
| 202 | if (timeRecord->acquireFence != nullptr) { |
| 203 | if (timeRecord->acquireFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) { |
| 204 | return false; |
| 205 | } |
| 206 | if (timeRecord->acquireFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) { |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 207 | timeRecord->frameTime.acquireTime = timeRecord->acquireFence->getSignalTime(); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 208 | timeRecord->acquireFence = nullptr; |
| 209 | } else { |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 210 | ALOGV("[%d]-[%" PRIu64 "]-acquireFence signal time is invalid", layerId, |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 211 | timeRecord->frameTime.frameNumber); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 212 | } |
| 213 | } |
| 214 | |
| 215 | if (timeRecord->presentFence != nullptr) { |
| 216 | if (timeRecord->presentFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) { |
| 217 | return false; |
| 218 | } |
| 219 | if (timeRecord->presentFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) { |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 220 | timeRecord->frameTime.presentTime = timeRecord->presentFence->getSignalTime(); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 221 | timeRecord->presentFence = nullptr; |
| 222 | } else { |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 223 | ALOGV("[%d]-[%" PRIu64 "]-presentFence signal time invalid", layerId, |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 224 | timeRecord->frameTime.frameNumber); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 225 | } |
| 226 | } |
| 227 | |
| 228 | return true; |
| 229 | } |
| 230 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 231 | void TimeStats::flushAvailableRecordsToStatsLocked(int32_t layerId) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 232 | ATRACE_CALL(); |
| 233 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 234 | LayerRecord& layerRecord = mTimeStatsTracker[layerId]; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 235 | TimeRecord& prevTimeRecord = layerRecord.prevTimeRecord; |
Yiwei Zhang | c5f2c45 | 2018-05-08 16:31:56 -0700 | [diff] [blame] | 236 | std::deque<TimeRecord>& timeRecords = layerRecord.timeRecords; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 237 | while (!timeRecords.empty()) { |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 238 | if (!recordReadyLocked(layerId, &timeRecords[0])) break; |
| 239 | ALOGV("[%d]-[%" PRIu64 "]-presentFenceTime[%" PRId64 "]", layerId, |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 240 | timeRecords[0].frameTime.frameNumber, timeRecords[0].frameTime.presentTime); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 241 | |
| 242 | if (prevTimeRecord.ready) { |
Yiwei Zhang | eafa5cc | 2019-07-26 15:06:25 -0700 | [diff] [blame] | 243 | const std::string& layerName = layerRecord.layerName; |
Yiwei Zhang | dc22404 | 2018-10-18 15:34:00 -0700 | [diff] [blame] | 244 | if (!mTimeStats.stats.count(layerName)) { |
| 245 | mTimeStats.stats[layerName].layerName = layerName; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 246 | } |
Yiwei Zhang | dc22404 | 2018-10-18 15:34:00 -0700 | [diff] [blame] | 247 | TimeStatsHelper::TimeStatsLayer& timeStatsLayer = mTimeStats.stats[layerName]; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 248 | timeStatsLayer.totalFrames++; |
Yiwei Zhang | eaeea06 | 2018-06-28 14:46:51 -0700 | [diff] [blame] | 249 | timeStatsLayer.droppedFrames += layerRecord.droppedFrames; |
| 250 | layerRecord.droppedFrames = 0; |
| 251 | |
| 252 | const int32_t postToAcquireMs = msBetween(timeRecords[0].frameTime.postTime, |
| 253 | timeRecords[0].frameTime.acquireTime); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 254 | ALOGV("[%d]-[%" PRIu64 "]-post2acquire[%d]", layerId, |
Yiwei Zhang | eaeea06 | 2018-06-28 14:46:51 -0700 | [diff] [blame] | 255 | timeRecords[0].frameTime.frameNumber, postToAcquireMs); |
| 256 | timeStatsLayer.deltas["post2acquire"].insert(postToAcquireMs); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 257 | |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 258 | const int32_t postToPresentMs = msBetween(timeRecords[0].frameTime.postTime, |
| 259 | timeRecords[0].frameTime.presentTime); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 260 | ALOGV("[%d]-[%" PRIu64 "]-post2present[%d]", layerId, |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 261 | timeRecords[0].frameTime.frameNumber, postToPresentMs); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 262 | timeStatsLayer.deltas["post2present"].insert(postToPresentMs); |
| 263 | |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 264 | const int32_t acquireToPresentMs = msBetween(timeRecords[0].frameTime.acquireTime, |
| 265 | timeRecords[0].frameTime.presentTime); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 266 | ALOGV("[%d]-[%" PRIu64 "]-acquire2present[%d]", layerId, |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 267 | timeRecords[0].frameTime.frameNumber, acquireToPresentMs); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 268 | timeStatsLayer.deltas["acquire2present"].insert(acquireToPresentMs); |
| 269 | |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 270 | const int32_t latchToPresentMs = msBetween(timeRecords[0].frameTime.latchTime, |
| 271 | timeRecords[0].frameTime.presentTime); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 272 | ALOGV("[%d]-[%" PRIu64 "]-latch2present[%d]", layerId, |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 273 | timeRecords[0].frameTime.frameNumber, latchToPresentMs); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 274 | timeStatsLayer.deltas["latch2present"].insert(latchToPresentMs); |
| 275 | |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 276 | const int32_t desiredToPresentMs = msBetween(timeRecords[0].frameTime.desiredTime, |
| 277 | timeRecords[0].frameTime.presentTime); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 278 | ALOGV("[%d]-[%" PRIu64 "]-desired2present[%d]", layerId, |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 279 | timeRecords[0].frameTime.frameNumber, desiredToPresentMs); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 280 | timeStatsLayer.deltas["desired2present"].insert(desiredToPresentMs); |
| 281 | |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 282 | const int32_t presentToPresentMs = msBetween(prevTimeRecord.frameTime.presentTime, |
| 283 | timeRecords[0].frameTime.presentTime); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 284 | ALOGV("[%d]-[%" PRIu64 "]-present2present[%d]", layerId, |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 285 | timeRecords[0].frameTime.frameNumber, presentToPresentMs); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 286 | timeStatsLayer.deltas["present2present"].insert(presentToPresentMs); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 287 | } |
| 288 | prevTimeRecord = timeRecords[0]; |
Yiwei Zhang | c5f2c45 | 2018-05-08 16:31:56 -0700 | [diff] [blame] | 289 | timeRecords.pop_front(); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 290 | layerRecord.waitData--; |
| 291 | } |
| 292 | } |
| 293 | |
Yiwei Zhang | 8bec7e8 | 2019-10-07 18:08:26 -0700 | [diff] [blame] | 294 | static constexpr const char* kPopupWindowPrefix = "PopupWindow"; |
| 295 | static const size_t kMinLenLayerName = std::strlen(kPopupWindowPrefix); |
Yiwei Zhang | bd40832 | 2018-10-15 18:31:53 -0700 | [diff] [blame] | 296 | |
Yiwei Zhang | 8bec7e8 | 2019-10-07 18:08:26 -0700 | [diff] [blame] | 297 | // Avoid tracking the "PopupWindow:<random hash>#<number>" layers |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 298 | static bool layerNameIsValid(const std::string& layerName) { |
Yiwei Zhang | 8bec7e8 | 2019-10-07 18:08:26 -0700 | [diff] [blame] | 299 | return layerName.length() >= kMinLenLayerName && |
| 300 | layerName.compare(0, kMinLenLayerName, kPopupWindowPrefix) != 0; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 301 | } |
| 302 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 303 | void TimeStats::setPostTime(int32_t layerId, uint64_t frameNumber, const std::string& layerName, |
Yiwei Zhang | 8e8fe52 | 2018-11-02 18:34:07 -0700 | [diff] [blame] | 304 | nsecs_t postTime) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 305 | if (!mEnabled.load()) return; |
| 306 | |
| 307 | ATRACE_CALL(); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 308 | ALOGV("[%d]-[%" PRIu64 "]-[%s]-PostTime[%" PRId64 "]", layerId, frameNumber, layerName.c_str(), |
Yiwei Zhang | 8e8fe52 | 2018-11-02 18:34:07 -0700 | [diff] [blame] | 309 | postTime); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 310 | |
| 311 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | e926ab5 | 2019-08-14 15:16:00 -0700 | [diff] [blame] | 312 | if (!mTimeStats.stats.count(layerName) && mTimeStats.stats.size() >= MAX_NUM_LAYER_STATS) { |
| 313 | return; |
| 314 | } |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 315 | if (!mTimeStatsTracker.count(layerId) && mTimeStatsTracker.size() < MAX_NUM_LAYER_RECORDS && |
Yiwei Zhang | 7eb58b7 | 2019-04-22 19:00:02 -0700 | [diff] [blame] | 316 | layerNameIsValid(layerName)) { |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 317 | mTimeStatsTracker[layerId].layerName = layerName; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 318 | } |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 319 | if (!mTimeStatsTracker.count(layerId)) return; |
| 320 | LayerRecord& layerRecord = mTimeStatsTracker[layerId]; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 321 | if (layerRecord.timeRecords.size() == MAX_NUM_TIME_RECORDS) { |
Yiwei Zhang | af8ee94 | 2018-11-22 00:15:23 -0800 | [diff] [blame] | 322 | ALOGE("[%d]-[%s]-timeRecords is at its maximum size[%zu]. Ignore this when unittesting.", |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 323 | layerId, layerRecord.layerName.c_str(), MAX_NUM_TIME_RECORDS); |
| 324 | mTimeStatsTracker.erase(layerId); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 325 | return; |
| 326 | } |
| 327 | // For most media content, the acquireFence is invalid because the buffer is |
| 328 | // ready at the queueBuffer stage. In this case, acquireTime should be given |
| 329 | // a default value as postTime. |
| 330 | TimeRecord timeRecord = { |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 331 | .frameTime = |
| 332 | { |
| 333 | .frameNumber = frameNumber, |
| 334 | .postTime = postTime, |
Yiwei Zhang | af8ee94 | 2018-11-22 00:15:23 -0800 | [diff] [blame] | 335 | .latchTime = postTime, |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 336 | .acquireTime = postTime, |
Yiwei Zhang | af8ee94 | 2018-11-22 00:15:23 -0800 | [diff] [blame] | 337 | .desiredTime = postTime, |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 338 | }, |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 339 | }; |
| 340 | layerRecord.timeRecords.push_back(timeRecord); |
| 341 | if (layerRecord.waitData < 0 || |
| 342 | layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size())) |
| 343 | layerRecord.waitData = layerRecord.timeRecords.size() - 1; |
| 344 | } |
| 345 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 346 | void TimeStats::setLatchTime(int32_t layerId, uint64_t frameNumber, nsecs_t latchTime) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 347 | if (!mEnabled.load()) return; |
| 348 | |
| 349 | ATRACE_CALL(); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 350 | ALOGV("[%d]-[%" PRIu64 "]-LatchTime[%" PRId64 "]", layerId, frameNumber, latchTime); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 351 | |
| 352 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 353 | if (!mTimeStatsTracker.count(layerId)) return; |
| 354 | LayerRecord& layerRecord = mTimeStatsTracker[layerId]; |
Yiwei Zhang | cb7dd00 | 2019-04-16 11:03:01 -0700 | [diff] [blame] | 355 | if (layerRecord.waitData < 0 || |
| 356 | layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size())) |
| 357 | return; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 358 | TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData]; |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 359 | if (timeRecord.frameTime.frameNumber == frameNumber) { |
| 360 | timeRecord.frameTime.latchTime = latchTime; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 361 | } |
| 362 | } |
| 363 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 364 | void TimeStats::setDesiredTime(int32_t layerId, uint64_t frameNumber, nsecs_t desiredTime) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 365 | if (!mEnabled.load()) return; |
| 366 | |
| 367 | ATRACE_CALL(); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 368 | ALOGV("[%d]-[%" PRIu64 "]-DesiredTime[%" PRId64 "]", layerId, frameNumber, desiredTime); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 369 | |
| 370 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 371 | if (!mTimeStatsTracker.count(layerId)) return; |
| 372 | LayerRecord& layerRecord = mTimeStatsTracker[layerId]; |
Yiwei Zhang | cb7dd00 | 2019-04-16 11:03:01 -0700 | [diff] [blame] | 373 | if (layerRecord.waitData < 0 || |
| 374 | layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size())) |
| 375 | return; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 376 | TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData]; |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 377 | if (timeRecord.frameTime.frameNumber == frameNumber) { |
| 378 | timeRecord.frameTime.desiredTime = desiredTime; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 379 | } |
| 380 | } |
| 381 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 382 | void TimeStats::setAcquireTime(int32_t layerId, uint64_t frameNumber, nsecs_t acquireTime) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 383 | if (!mEnabled.load()) return; |
| 384 | |
| 385 | ATRACE_CALL(); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 386 | ALOGV("[%d]-[%" PRIu64 "]-AcquireTime[%" PRId64 "]", layerId, frameNumber, acquireTime); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 387 | |
| 388 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 389 | if (!mTimeStatsTracker.count(layerId)) return; |
| 390 | LayerRecord& layerRecord = mTimeStatsTracker[layerId]; |
Yiwei Zhang | cb7dd00 | 2019-04-16 11:03:01 -0700 | [diff] [blame] | 391 | if (layerRecord.waitData < 0 || |
| 392 | layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size())) |
| 393 | return; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 394 | TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData]; |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 395 | if (timeRecord.frameTime.frameNumber == frameNumber) { |
| 396 | timeRecord.frameTime.acquireTime = acquireTime; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 397 | } |
| 398 | } |
| 399 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 400 | void TimeStats::setAcquireFence(int32_t layerId, uint64_t frameNumber, |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 401 | const std::shared_ptr<FenceTime>& acquireFence) { |
| 402 | if (!mEnabled.load()) return; |
| 403 | |
| 404 | ATRACE_CALL(); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 405 | ALOGV("[%d]-[%" PRIu64 "]-AcquireFenceTime[%" PRId64 "]", layerId, frameNumber, |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 406 | acquireFence->getSignalTime()); |
| 407 | |
| 408 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 409 | if (!mTimeStatsTracker.count(layerId)) return; |
| 410 | LayerRecord& layerRecord = mTimeStatsTracker[layerId]; |
Yiwei Zhang | cb7dd00 | 2019-04-16 11:03:01 -0700 | [diff] [blame] | 411 | if (layerRecord.waitData < 0 || |
| 412 | layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size())) |
| 413 | return; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 414 | TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData]; |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 415 | if (timeRecord.frameTime.frameNumber == frameNumber) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 416 | timeRecord.acquireFence = acquireFence; |
| 417 | } |
| 418 | } |
| 419 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 420 | void TimeStats::setPresentTime(int32_t layerId, uint64_t frameNumber, nsecs_t presentTime) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 421 | if (!mEnabled.load()) return; |
| 422 | |
| 423 | ATRACE_CALL(); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 424 | ALOGV("[%d]-[%" PRIu64 "]-PresentTime[%" PRId64 "]", layerId, frameNumber, presentTime); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 425 | |
| 426 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 427 | if (!mTimeStatsTracker.count(layerId)) return; |
| 428 | LayerRecord& layerRecord = mTimeStatsTracker[layerId]; |
Yiwei Zhang | cb7dd00 | 2019-04-16 11:03:01 -0700 | [diff] [blame] | 429 | if (layerRecord.waitData < 0 || |
| 430 | layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size())) |
| 431 | return; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 432 | TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData]; |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 433 | if (timeRecord.frameTime.frameNumber == frameNumber) { |
| 434 | timeRecord.frameTime.presentTime = presentTime; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 435 | timeRecord.ready = true; |
| 436 | layerRecord.waitData++; |
| 437 | } |
| 438 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 439 | flushAvailableRecordsToStatsLocked(layerId); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 440 | } |
| 441 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 442 | void TimeStats::setPresentFence(int32_t layerId, uint64_t frameNumber, |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 443 | const std::shared_ptr<FenceTime>& presentFence) { |
| 444 | if (!mEnabled.load()) return; |
| 445 | |
| 446 | ATRACE_CALL(); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 447 | ALOGV("[%d]-[%" PRIu64 "]-PresentFenceTime[%" PRId64 "]", layerId, frameNumber, |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 448 | presentFence->getSignalTime()); |
| 449 | |
| 450 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 451 | if (!mTimeStatsTracker.count(layerId)) return; |
| 452 | LayerRecord& layerRecord = mTimeStatsTracker[layerId]; |
Yiwei Zhang | cb7dd00 | 2019-04-16 11:03:01 -0700 | [diff] [blame] | 453 | if (layerRecord.waitData < 0 || |
| 454 | layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size())) |
| 455 | return; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 456 | TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData]; |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 457 | if (timeRecord.frameTime.frameNumber == frameNumber) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 458 | timeRecord.presentFence = presentFence; |
| 459 | timeRecord.ready = true; |
| 460 | layerRecord.waitData++; |
| 461 | } |
| 462 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 463 | flushAvailableRecordsToStatsLocked(layerId); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 464 | } |
| 465 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 466 | void TimeStats::onDestroy(int32_t layerId) { |
Yiwei Zhang | dc22404 | 2018-10-18 15:34:00 -0700 | [diff] [blame] | 467 | ATRACE_CALL(); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 468 | ALOGV("[%d]-onDestroy", layerId); |
Mikael Pessa | 90092f4 | 2019-08-26 17:22:04 -0700 | [diff] [blame] | 469 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 470 | mTimeStatsTracker.erase(layerId); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 471 | } |
| 472 | |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 473 | void TimeStats::removeTimeRecord(int32_t layerId, uint64_t frameNumber) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 474 | if (!mEnabled.load()) return; |
| 475 | |
| 476 | ATRACE_CALL(); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 477 | ALOGV("[%d]-[%" PRIu64 "]-removeTimeRecord", layerId, frameNumber); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 478 | |
| 479 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | 1a88c40 | 2019-11-18 10:43:58 -0800 | [diff] [blame] | 480 | if (!mTimeStatsTracker.count(layerId)) return; |
| 481 | LayerRecord& layerRecord = mTimeStatsTracker[layerId]; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 482 | size_t removeAt = 0; |
| 483 | for (const TimeRecord& record : layerRecord.timeRecords) { |
Yiwei Zhang | cf50ab9 | 2018-06-14 10:50:12 -0700 | [diff] [blame] | 484 | if (record.frameTime.frameNumber == frameNumber) break; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 485 | removeAt++; |
| 486 | } |
| 487 | if (removeAt == layerRecord.timeRecords.size()) return; |
| 488 | layerRecord.timeRecords.erase(layerRecord.timeRecords.begin() + removeAt); |
| 489 | if (layerRecord.waitData > static_cast<int32_t>(removeAt)) { |
Yiwei Zhang | eaeea06 | 2018-06-28 14:46:51 -0700 | [diff] [blame] | 490 | layerRecord.waitData--; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 491 | } |
Yiwei Zhang | eaeea06 | 2018-06-28 14:46:51 -0700 | [diff] [blame] | 492 | layerRecord.droppedFrames++; |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 493 | } |
| 494 | |
Yiwei Zhang | 3a226d2 | 2018-10-16 09:23:03 -0700 | [diff] [blame] | 495 | void TimeStats::flushPowerTimeLocked() { |
Yiwei Zhang | e5c49d5 | 2018-10-29 00:15:31 -0700 | [diff] [blame] | 496 | if (!mEnabled.load()) return; |
| 497 | |
Yiwei Zhang | 3a226d2 | 2018-10-16 09:23:03 -0700 | [diff] [blame] | 498 | nsecs_t curTime = systemTime(); |
| 499 | // elapsedTime is in milliseconds. |
| 500 | int64_t elapsedTime = (curTime - mPowerTime.prevTime) / 1000000; |
| 501 | |
| 502 | switch (mPowerTime.powerMode) { |
| 503 | case HWC_POWER_MODE_NORMAL: |
| 504 | mTimeStats.displayOnTime += elapsedTime; |
| 505 | break; |
| 506 | case HWC_POWER_MODE_OFF: |
| 507 | case HWC_POWER_MODE_DOZE: |
| 508 | case HWC_POWER_MODE_DOZE_SUSPEND: |
| 509 | default: |
| 510 | break; |
| 511 | } |
| 512 | |
| 513 | mPowerTime.prevTime = curTime; |
| 514 | } |
| 515 | |
| 516 | void TimeStats::setPowerMode(int32_t powerMode) { |
| 517 | if (!mEnabled.load()) { |
| 518 | std::lock_guard<std::mutex> lock(mMutex); |
| 519 | mPowerTime.powerMode = powerMode; |
| 520 | return; |
| 521 | } |
| 522 | |
| 523 | std::lock_guard<std::mutex> lock(mMutex); |
| 524 | if (powerMode == mPowerTime.powerMode) return; |
| 525 | |
| 526 | flushPowerTimeLocked(); |
| 527 | mPowerTime.powerMode = powerMode; |
| 528 | } |
| 529 | |
Alec Mouri | fb571ea | 2019-01-24 18:42:10 -0800 | [diff] [blame] | 530 | void TimeStats::recordRefreshRate(uint32_t fps, nsecs_t duration) { |
| 531 | std::lock_guard<std::mutex> lock(mMutex); |
| 532 | if (mTimeStats.refreshRateStats.count(fps)) { |
| 533 | mTimeStats.refreshRateStats[fps] += duration; |
| 534 | } else { |
| 535 | mTimeStats.refreshRateStats.insert({fps, duration}); |
| 536 | } |
| 537 | } |
| 538 | |
Yiwei Zhang | ce6ebc0 | 2018-10-20 12:42:38 -0700 | [diff] [blame] | 539 | void TimeStats::flushAvailableGlobalRecordsToStatsLocked() { |
| 540 | ATRACE_CALL(); |
| 541 | |
| 542 | while (!mGlobalRecord.presentFences.empty()) { |
| 543 | const nsecs_t curPresentTime = mGlobalRecord.presentFences.front()->getSignalTime(); |
| 544 | if (curPresentTime == Fence::SIGNAL_TIME_PENDING) break; |
| 545 | |
| 546 | if (curPresentTime == Fence::SIGNAL_TIME_INVALID) { |
| 547 | ALOGE("GlobalPresentFence is invalid!"); |
| 548 | mGlobalRecord.prevPresentTime = 0; |
| 549 | mGlobalRecord.presentFences.pop_front(); |
| 550 | continue; |
| 551 | } |
| 552 | |
| 553 | ALOGV("GlobalPresentFenceTime[%" PRId64 "]", |
| 554 | mGlobalRecord.presentFences.front()->getSignalTime()); |
| 555 | |
Yiwei Zhang | e5c49d5 | 2018-10-29 00:15:31 -0700 | [diff] [blame] | 556 | if (mGlobalRecord.prevPresentTime != 0) { |
| 557 | const int32_t presentToPresentMs = |
| 558 | msBetween(mGlobalRecord.prevPresentTime, curPresentTime); |
| 559 | ALOGV("Global present2present[%d] prev[%" PRId64 "] curr[%" PRId64 "]", |
| 560 | presentToPresentMs, mGlobalRecord.prevPresentTime, curPresentTime); |
| 561 | mTimeStats.presentToPresent.insert(presentToPresentMs); |
| 562 | } |
Yiwei Zhang | ce6ebc0 | 2018-10-20 12:42:38 -0700 | [diff] [blame] | 563 | |
Yiwei Zhang | ce6ebc0 | 2018-10-20 12:42:38 -0700 | [diff] [blame] | 564 | mGlobalRecord.prevPresentTime = curPresentTime; |
| 565 | mGlobalRecord.presentFences.pop_front(); |
| 566 | } |
Alec Mouri | e4034bb | 2019-11-19 12:45:54 -0800 | [diff] [blame] | 567 | while (!mGlobalRecord.renderEngineDurations.empty()) { |
| 568 | const auto duration = mGlobalRecord.renderEngineDurations.front(); |
| 569 | const auto& endTime = duration.endTime; |
| 570 | |
| 571 | nsecs_t endNs = -1; |
| 572 | |
| 573 | if (auto val = std::get_if<nsecs_t>(&endTime)) { |
| 574 | endNs = *val; |
| 575 | } else { |
| 576 | endNs = std::get<std::shared_ptr<FenceTime>>(endTime)->getSignalTime(); |
| 577 | } |
| 578 | |
| 579 | if (endNs == Fence::SIGNAL_TIME_PENDING) break; |
| 580 | |
| 581 | if (endNs < 0) { |
| 582 | ALOGE("RenderEngineTiming is invalid!"); |
| 583 | mGlobalRecord.renderEngineDurations.pop_front(); |
| 584 | continue; |
| 585 | } |
| 586 | |
| 587 | const int32_t renderEngineMs = msBetween(duration.startTime, endNs); |
| 588 | mTimeStats.renderEngineTiming.insert(renderEngineMs); |
| 589 | |
| 590 | mGlobalRecord.renderEngineDurations.pop_front(); |
| 591 | } |
Alec Mouri | d506545 | 2019-12-07 18:18:48 -0800 | [diff] [blame^] | 592 | // Try to register to statsd at the end of every global flush, if we haven't |
| 593 | // yet. |
| 594 | registerToStatsdIfNeededLocked(); |
| 595 | } |
| 596 | |
| 597 | bool TimeStats::StatsEventDelegate::checkStatsService() { |
| 598 | ATRACE_CALL(); |
| 599 | bool ret = |
| 600 | android::defaultServiceManager()->checkService(android::String16("stats")) != nullptr; |
| 601 | return ret; |
| 602 | } |
| 603 | |
| 604 | void TimeStats::registerToStatsdIfNeededLocked() { |
| 605 | if (!mRegisteredCallback && mStatsDelegate->checkStatsService()) { |
| 606 | // Note that this assumes that statsd will never crash. To be absolutely |
| 607 | // correct we would need to register a DeathRecipient ourselves, but to |
| 608 | // minimize the cost on the rendering path let's only register once as |
| 609 | // soon as we know that statd has booted up. |
| 610 | ALOGD("Registering statsd callback"); |
| 611 | mStatsDelegate |
| 612 | ->registerStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO, |
| 613 | TimeStats::pullGlobalAtomCallback, nullptr, this); |
| 614 | mRegisteredCallback = true; |
| 615 | } |
Yiwei Zhang | ce6ebc0 | 2018-10-20 12:42:38 -0700 | [diff] [blame] | 616 | } |
| 617 | |
| 618 | void TimeStats::setPresentFenceGlobal(const std::shared_ptr<FenceTime>& presentFence) { |
| 619 | if (!mEnabled.load()) return; |
| 620 | |
| 621 | ATRACE_CALL(); |
| 622 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | e5c49d5 | 2018-10-29 00:15:31 -0700 | [diff] [blame] | 623 | if (presentFence == nullptr || !presentFence->isValid()) { |
| 624 | mGlobalRecord.prevPresentTime = 0; |
| 625 | return; |
| 626 | } |
| 627 | |
| 628 | if (mPowerTime.powerMode != HWC_POWER_MODE_NORMAL) { |
| 629 | // Try flushing the last present fence on HWC_POWER_MODE_NORMAL. |
| 630 | flushAvailableGlobalRecordsToStatsLocked(); |
| 631 | mGlobalRecord.presentFences.clear(); |
Yiwei Zhang | ce6ebc0 | 2018-10-20 12:42:38 -0700 | [diff] [blame] | 632 | mGlobalRecord.prevPresentTime = 0; |
| 633 | return; |
| 634 | } |
| 635 | |
| 636 | if (mGlobalRecord.presentFences.size() == MAX_NUM_TIME_RECORDS) { |
| 637 | // The front presentFence must be trapped in pending status in this |
| 638 | // case. Try dequeuing the front one to recover. |
| 639 | ALOGE("GlobalPresentFences is already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS); |
| 640 | mGlobalRecord.prevPresentTime = 0; |
| 641 | mGlobalRecord.presentFences.pop_front(); |
| 642 | } |
| 643 | |
| 644 | mGlobalRecord.presentFences.emplace_back(presentFence); |
| 645 | flushAvailableGlobalRecordsToStatsLocked(); |
| 646 | } |
| 647 | |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 648 | void TimeStats::enable() { |
| 649 | if (mEnabled.load()) return; |
| 650 | |
| 651 | ATRACE_CALL(); |
| 652 | |
| 653 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 654 | mEnabled.store(true); |
Yiwei Zhang | dc22404 | 2018-10-18 15:34:00 -0700 | [diff] [blame] | 655 | mTimeStats.statsStart = static_cast<int64_t>(std::time(0)); |
Yiwei Zhang | 3a226d2 | 2018-10-16 09:23:03 -0700 | [diff] [blame] | 656 | mPowerTime.prevTime = systemTime(); |
Yiwei Zhang | e5c49d5 | 2018-10-29 00:15:31 -0700 | [diff] [blame] | 657 | ALOGD("Enabled"); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 658 | } |
| 659 | |
| 660 | void TimeStats::disable() { |
| 661 | if (!mEnabled.load()) return; |
| 662 | |
| 663 | ATRACE_CALL(); |
| 664 | |
| 665 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | e5c49d5 | 2018-10-29 00:15:31 -0700 | [diff] [blame] | 666 | flushPowerTimeLocked(); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 667 | mEnabled.store(false); |
Yiwei Zhang | dc22404 | 2018-10-18 15:34:00 -0700 | [diff] [blame] | 668 | mTimeStats.statsEnd = static_cast<int64_t>(std::time(0)); |
Yiwei Zhang | e5c49d5 | 2018-10-29 00:15:31 -0700 | [diff] [blame] | 669 | ALOGD("Disabled"); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 670 | } |
| 671 | |
Alec Mouri | d506545 | 2019-12-07 18:18:48 -0800 | [diff] [blame^] | 672 | void TimeStats::clearAll() { |
| 673 | std::lock_guard<std::mutex> lock(mMutex); |
| 674 | clearGlobalLocked(); |
| 675 | clearLayersLocked(); |
| 676 | } |
| 677 | |
| 678 | void TimeStats::clearGlobalLocked() { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 679 | ATRACE_CALL(); |
| 680 | |
Yiwei Zhang | dc22404 | 2018-10-18 15:34:00 -0700 | [diff] [blame] | 681 | mTimeStats.statsStart = (mEnabled.load() ? static_cast<int64_t>(std::time(0)) : 0); |
| 682 | mTimeStats.statsEnd = 0; |
| 683 | mTimeStats.totalFrames = 0; |
| 684 | mTimeStats.missedFrames = 0; |
| 685 | mTimeStats.clientCompositionFrames = 0; |
Yiwei Zhang | 3a226d2 | 2018-10-16 09:23:03 -0700 | [diff] [blame] | 686 | mTimeStats.displayOnTime = 0; |
Yiwei Zhang | ce6ebc0 | 2018-10-20 12:42:38 -0700 | [diff] [blame] | 687 | mTimeStats.presentToPresent.hist.clear(); |
Alec Mouri | 31ac64a | 2020-01-09 09:26:22 -0800 | [diff] [blame] | 688 | mTimeStats.frameDuration.hist.clear(); |
| 689 | mTimeStats.renderEngineTiming.hist.clear(); |
Alec Mouri | fb571ea | 2019-01-24 18:42:10 -0800 | [diff] [blame] | 690 | mTimeStats.refreshRateStats.clear(); |
Yiwei Zhang | 3a226d2 | 2018-10-16 09:23:03 -0700 | [diff] [blame] | 691 | mPowerTime.prevTime = systemTime(); |
Yiwei Zhang | e5c49d5 | 2018-10-29 00:15:31 -0700 | [diff] [blame] | 692 | mGlobalRecord.prevPresentTime = 0; |
| 693 | mGlobalRecord.presentFences.clear(); |
Alec Mouri | d506545 | 2019-12-07 18:18:48 -0800 | [diff] [blame^] | 694 | ALOGD("Cleared global stats"); |
| 695 | } |
| 696 | |
| 697 | void TimeStats::clearLayersLocked() { |
| 698 | ATRACE_CALL(); |
| 699 | |
| 700 | mTimeStatsTracker.clear(); |
| 701 | mTimeStats.stats.clear(); |
| 702 | ALOGD("Cleared layer stats"); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 703 | } |
| 704 | |
| 705 | bool TimeStats::isEnabled() { |
| 706 | return mEnabled.load(); |
| 707 | } |
| 708 | |
Yiwei Zhang | 5434a78 | 2018-12-05 18:06:32 -0800 | [diff] [blame] | 709 | void TimeStats::dump(bool asProto, std::optional<uint32_t> maxLayers, std::string& result) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 710 | ATRACE_CALL(); |
| 711 | |
| 712 | std::lock_guard<std::mutex> lock(mMutex); |
Yiwei Zhang | dc22404 | 2018-10-18 15:34:00 -0700 | [diff] [blame] | 713 | if (mTimeStats.statsStart == 0) { |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 714 | return; |
| 715 | } |
| 716 | |
Yiwei Zhang | dc22404 | 2018-10-18 15:34:00 -0700 | [diff] [blame] | 717 | mTimeStats.statsEnd = static_cast<int64_t>(std::time(0)); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 718 | |
Yiwei Zhang | 3a226d2 | 2018-10-16 09:23:03 -0700 | [diff] [blame] | 719 | flushPowerTimeLocked(); |
| 720 | |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 721 | if (asProto) { |
Yiwei Zhang | 8a4015c | 2018-05-08 16:03:47 -0700 | [diff] [blame] | 722 | ALOGD("Dumping TimeStats as proto"); |
Yiwei Zhang | dc22404 | 2018-10-18 15:34:00 -0700 | [diff] [blame] | 723 | SFTimeStatsGlobalProto timeStatsProto = mTimeStats.toProto(maxLayers); |
Dominik Laskowski | 4647011 | 2019-08-02 13:13:11 -0700 | [diff] [blame] | 724 | result.append(timeStatsProto.SerializeAsString()); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 725 | } else { |
Yiwei Zhang | 8a4015c | 2018-05-08 16:03:47 -0700 | [diff] [blame] | 726 | ALOGD("Dumping TimeStats as text"); |
Yiwei Zhang | 5434a78 | 2018-12-05 18:06:32 -0800 | [diff] [blame] | 727 | result.append(mTimeStats.toString(maxLayers)); |
Yiwei Zhang | 8a4015c | 2018-05-08 16:03:47 -0700 | [diff] [blame] | 728 | result.append("\n"); |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 729 | } |
| 730 | } |
| 731 | |
Alec Mouri | fb571ea | 2019-01-24 18:42:10 -0800 | [diff] [blame] | 732 | } // namespace impl |
| 733 | |
Yiwei Zhang | 0102ad2 | 2018-05-02 17:37:17 -0700 | [diff] [blame] | 734 | } // namespace android |