1 /*
2 * Copyright (c) 2023 Huawei Device Co., Ltd.
3 * Licensed under the Apache License, Version 2.0 (the "License");
4 * you may not use this file except in compliance with the License.
5 * You may obtain a copy of the License at
6 *
7 * http://www.apache.org/licenses/LICENSE-2.0
8 *
9 * Unless required by applicable law or agreed to in writing, software
10 * distributed under the License is distributed on an "AS IS" BASIS,
11 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12 * See the License for the specific language governing permissions and
13 * limitations under the License.
14 */
15
16 #include "platform/ohos/rs_jank_stats.h"
17
18 #include <algorithm>
19 #include <chrono>
20 #include <sstream>
21 #include <sys/time.h>
22 #include <unistd.h>
23
24 #include "hisysevent.h"
25 #include "rs_trace.h"
26
27 #include "common/rs_common_def.h"
28 #include "platform/common/rs_log.h"
29
30 namespace OHOS {
31 namespace Rosen {
32 namespace {
33 constexpr float VSYNC_PERIOD = 16.6f; // 16.6ms
34 constexpr float S_TO_MS = 1000.f; // s to ms
35 constexpr int64_t ANIMATION_TIMEOUT = 5000; // 5s
36 constexpr int64_t S_TO_NS = 1000000000; // s to ns
37 constexpr int64_t VSYNC_JANK_LOG_THRESHOLED = 6; // 6 times vsync
38 }
39
GetInstance()40 RSJankStats& RSJankStats::GetInstance()
41 {
42 static RSJankStats instance;
43 return instance;
44 }
45
SetStartTime()46 void RSJankStats::SetStartTime()
47 {
48 std::lock_guard<std::mutex> lock(mutex_);
49 startTime_ = GetCurrentSystimeMs();
50 startTimeSteady_ = GetCurrentSteadyTimeMs();
51 if (isFirstSetStart_) {
52 lastReportTime_ = startTime_;
53 lastReportTimeSteady_ = startTimeSteady_;
54 }
55 for (auto &[animationId, jankFrames] : animateJankFrames_) {
56 jankFrames.isReportEventResponse_ = jankFrames.isSetReportEventResponse_;
57 jankFrames.isSetReportEventResponse_ = false;
58 jankFrames.isReportEventComplete_ = jankFrames.isSetReportEventComplete_;
59 jankFrames.isSetReportEventComplete_ = false;
60 jankFrames.isReportEventJankFrame_ = jankFrames.isSetReportEventJankFrame_;
61 jankFrames.isSetReportEventJankFrame_ = false;
62 }
63 isSkipDisplayNode_ = false;
64 isFirstSetStart_ = false;
65 }
66
SetEndTime(bool discardJankFrames)67 void RSJankStats::SetEndTime(bool discardJankFrames)
68 {
69 std::lock_guard<std::mutex> lock(mutex_);
70 if (startTime_ == TIMESTAMP_INITIAL || startTimeSteady_ == TIMESTAMP_INITIAL) {
71 ROSEN_LOGE("RSJankStats::SetEndTime startTime is not initialized");
72 return;
73 }
74 UpdateEndTime();
75 if (discardJankFrames) {
76 ClearAllAnimation();
77 }
78 SetRSJankStats();
79 RecordJankFrameInit();
80 RecordJankFrame();
81 for (auto &[animationId, jankFrames] : animateJankFrames_) {
82 if (jankFrames.isReportEventResponse_) {
83 ReportEventResponse(jankFrames);
84 jankFrames.isUpdateJankFrame_ = true;
85 }
86 // do not consider jank frame at the first frame of explicit/implicit animation
87 // do not consider jank frame at the end frame of implicit animation
88 // do not consider jank frame when isSkipDisplayNode_ is true in explicit animation
89 if (jankFrames.isUpdateJankFrame_ && !jankFrames.isFirstFrame_ && !(!jankFrames.isDisplayAnimator_ &&
90 (jankFrames.isReportEventComplete_ || jankFrames.isReportEventJankFrame_)) &&
91 !(jankFrames.isDisplayAnimator_ && isSkipDisplayNode_)) {
92 UpdateJankFrame(jankFrames);
93 }
94 if (jankFrames.isReportEventComplete_) {
95 ReportEventComplete(jankFrames);
96 }
97 if (jankFrames.isReportEventJankFrame_) {
98 ReportEventJankFrame(jankFrames, false);
99 }
100 if (jankFrames.isReportEventResponse_ && !jankFrames.isAnimationEnded_) {
101 SetAnimationTraceBegin(animationId, jankFrames);
102 }
103 if (jankFrames.isReportEventJankFrame_) {
104 RecordAnimationDynamicFrameRate(jankFrames, false);
105 }
106 if (jankFrames.isReportEventComplete_ || jankFrames.isReportEventJankFrame_) {
107 SetAnimationTraceEnd(jankFrames);
108 jankFrames.isUpdateJankFrame_ = false;
109 jankFrames.isAnimationEnded_ = true;
110 }
111 jankFrames.isFirstFrame_ = false;
112 }
113 ReportEventFirstFrame();
114 CheckAnimationTraceTimeout();
115 isFirstSetEnd_ = false;
116 }
117
UpdateEndTime()118 void RSJankStats::UpdateEndTime()
119 {
120 if (isFirstSetEnd_) {
121 lastEndTime_ = GetCurrentSystimeMs();
122 endTime_ = lastEndTime_;
123 lastEndTimeSteady_ = GetCurrentSteadyTimeMs();
124 endTimeSteady_ = lastEndTimeSteady_;
125 return;
126 }
127 lastEndTime_ = endTime_;
128 endTime_ = GetCurrentSystimeMs();
129 lastEndTimeSteady_ = endTimeSteady_;
130 endTimeSteady_ = GetCurrentSteadyTimeMs();
131 }
132
SetRSJankStats()133 void RSJankStats::SetRSJankStats()
134 {
135 const int64_t missedVsync = static_cast<int64_t>((endTimeSteady_ - startTimeSteady_) / VSYNC_PERIOD);
136 if (missedVsync <= 0) {
137 return;
138 }
139 if (missedVsync >= VSYNC_JANK_LOG_THRESHOLED) {
140 ROSEN_LOGI("RSJankStats::SetJankStats jank frames %{public}lld", missedVsync);
141 }
142 size_t type = JANK_FRAME_INVALID;
143 if (missedVsync < 6) { // JANK_FRAME_6_FREQ : (0,6)
144 type = JANK_FRAME_6_FREQ;
145 } else if (missedVsync < 15) { // JANK_FRAME_15_FREQ : [6,15)
146 type = JANK_FRAME_15_FREQ;
147 } else if (missedVsync < 20) { // JANK_FRAME_20_FREQ : [15,20)
148 type = JANK_FRAME_20_FREQ;
149 } else if (missedVsync < 36) { // JANK_FRAME_36_FREQ : [20,36)
150 type = JANK_FRAME_36_FREQ;
151 } else if (missedVsync < 48) { // JANK_FRAME_48_FREQ : [36,48)
152 type = JANK_FRAME_48_FREQ;
153 } else if (missedVsync < 60) { // JANK_FRAME_60_FREQ : [48,60)
154 type = JANK_FRAME_60_FREQ;
155 } else if (missedVsync < 120) { // JANK_FRAME_120_FREQ : [60,120)
156 type = JANK_FRAME_120_FREQ;
157 } else if (missedVsync < 180) { // JANK_FRAME_180_FREQ : [120,180)
158 type = JANK_FRAME_180_FREQ;
159 } else {
160 ROSEN_LOGW("RSJankStats::SetJankStats jank frames over 180");
161 return;
162 }
163 if (rsJankStats_[type] == USHRT_MAX) {
164 ROSEN_LOGW("RSJankStats::SetJankStats rsJankStats_ value oversteps USHRT_MAX");
165 return;
166 }
167 if (type != JANK_FRAME_6_FREQ) {
168 RS_TRACE_INT(JANK_FRAME_6F_COUNT_TRACE_NAME, missedVsync);
169 lastJankFrame6FreqTimeSteady_ = endTimeSteady_;
170 }
171 rsJankStats_[type]++;
172 isNeedReportJankStats_ = true;
173 if (type != JANK_FRAME_6_FREQ) {
174 RS_TRACE_INT(JANK_FRAME_6F_COUNT_TRACE_NAME, 0);
175 }
176 }
177
UpdateJankFrame(JankFrames & jankFrames)178 void RSJankStats::UpdateJankFrame(JankFrames& jankFrames)
179 {
180 if (jankFrames.startTimeSteady_ == TIMESTAMP_INITIAL) {
181 jankFrames.startTimeSteady_ = startTimeSteady_;
182 }
183 jankFrames.lastEndTimeSteady_ = jankFrames.endTimeSteady_;
184 jankFrames.endTimeSteady_ = endTimeSteady_;
185 jankFrames.lastTotalFrames_ = jankFrames.totalFrames_;
186 jankFrames.lastTotalFrameTimeSteady_ = jankFrames.totalFrameTimeSteady_;
187 jankFrames.lastTotalMissedFrames_ = jankFrames.totalMissedFrames_;
188 jankFrames.lastMaxFrameTimeSteady_ = jankFrames.maxFrameTimeSteady_;
189 jankFrames.lastMaxSeqMissedFrames_ = jankFrames.maxSeqMissedFrames_;
190 const bool isCalculateOnVsyncTime =
191 jankFrames.isDisplayAnimator_ || jankFrames.isFirstFrame_ || isFirstSetEnd_;
192 const int64_t frameDuration =
193 (isCalculateOnVsyncTime ? (endTimeSteady_ - startTimeSteady_) : (endTimeSteady_ - lastEndTimeSteady_));
194 const int32_t missedFrames = static_cast<int32_t>(frameDuration / VSYNC_PERIOD);
195 const int32_t missedFramesToReport =
196 (isCalculateOnVsyncTime ? missedFrames : std::max<int32_t>(0, missedFrames - 1));
197 jankFrames.totalFrames_++;
198 jankFrames.totalFrameTimeSteady_ += frameDuration;
199 jankFrames.maxFrameTimeSteady_ = std::max<int64_t>(jankFrames.maxFrameTimeSteady_, frameDuration);
200 if (missedFramesToReport > 0) {
201 jankFrames.totalMissedFrames_ += missedFramesToReport;
202 jankFrames.seqMissedFrames_ += missedFramesToReport;
203 jankFrames.maxSeqMissedFrames_ =
204 std::max<int32_t>(jankFrames.maxSeqMissedFrames_, jankFrames.seqMissedFrames_);
205 } else {
206 jankFrames.seqMissedFrames_ = 0;
207 }
208 }
209
ReportJankStats()210 void RSJankStats::ReportJankStats()
211 {
212 std::lock_guard<std::mutex> lock(mutex_);
213 if (lastReportTime_ == TIMESTAMP_INITIAL || lastReportTimeSteady_ == TIMESTAMP_INITIAL) {
214 ROSEN_LOGE("RSJankStats::ReportJankStats lastReportTime is not initialized");
215 return;
216 }
217 int64_t reportTime = GetCurrentSystimeMs();
218 int64_t reportTimeSteady = GetCurrentSteadyTimeMs();
219 if (!isNeedReportJankStats_) {
220 ROSEN_LOGD("RSJankStats::ReportJankStats Nothing need to report");
221 lastReportTime_ = reportTime;
222 lastReportTimeSteady_ = reportTimeSteady;
223 lastJankFrame6FreqTimeSteady_ = TIMESTAMP_INITIAL;
224 std::fill(rsJankStats_.begin(), rsJankStats_.end(), 0);
225 return;
226 }
227 int64_t lastJankFrame6FreqTime = ((lastJankFrame6FreqTimeSteady_ == TIMESTAMP_INITIAL) ? 0 :
228 (reportTime - (reportTimeSteady - lastJankFrame6FreqTimeSteady_)));
229 RS_TRACE_NAME("RSJankStats::ReportJankStats receive notification: reportTime " + std::to_string(reportTime) +
230 ", lastJankFrame6FreqTime " + std::to_string(lastJankFrame6FreqTime));
231 int64_t reportDuration = reportTimeSteady - lastReportTimeSteady_;
232 auto reportName = "JANK_STATS_RS";
233 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
234 OHOS::HiviewDFX::HiSysEvent::EventType::STATISTIC, "STARTTIME", static_cast<uint64_t>(lastReportTime_),
235 "DURATION", static_cast<uint64_t>(reportDuration), "JANK_STATS", rsJankStats_,
236 "JANK_STATS_VER", JANK_RANGE_VERSION);
237 lastReportTime_ = reportTime;
238 lastReportTimeSteady_ = reportTimeSteady;
239 lastJankFrame6FreqTimeSteady_ = TIMESTAMP_INITIAL;
240 std::fill(rsJankStats_.begin(), rsJankStats_.end(), 0);
241 isNeedReportJankStats_ = false;
242 }
243
SetReportEventResponse(const DataBaseRs & info)244 void RSJankStats::SetReportEventResponse(const DataBaseRs& info)
245 {
246 std::lock_guard<std::mutex> lock(mutex_);
247 RS_TRACE_NAME("RSJankStats::SetReportEventResponse receive notification: " + GetSceneDescription(info));
248 int64_t setTimeSteady = GetCurrentSteadyTimeMs();
249 EraseIf(animateJankFrames_, [setTimeSteady](const auto& pair) -> bool {
250 return setTimeSteady - pair.second.setTimeSteady_ > ANIMATION_TIMEOUT;
251 });
252 EraseIf(traceIdRemainder_, [setTimeSteady](const auto& pair) -> bool {
253 return setTimeSteady - pair.second.setTimeSteady_ > ANIMATION_TIMEOUT;
254 });
255 const auto animationId = GetAnimationId(info);
256 if (animateJankFrames_.find(animationId) == animateJankFrames_.end()) {
257 JankFrames jankFrames;
258 jankFrames.info_ = info;
259 jankFrames.isSetReportEventResponse_ = true;
260 jankFrames.setTimeSteady_ = setTimeSteady;
261 jankFrames.isFirstFrame_ = true;
262 jankFrames.traceId_ = GetTraceIdInit(info, setTimeSteady);
263 jankFrames.isDisplayAnimator_ = info.isDisplayAnimator;
264 animateJankFrames_.emplace(animationId, jankFrames);
265 } else {
266 animateJankFrames_[animationId].info_ = info;
267 animateJankFrames_[animationId].isSetReportEventResponse_ = true;
268 if (animateJankFrames_.at(animationId).isDisplayAnimator_ != info.isDisplayAnimator) {
269 ROSEN_LOGW("RSJankStats::SetReportEventResponse isDisplayAnimator not consistent");
270 }
271 }
272 }
273
SetReportEventComplete(const DataBaseRs & info)274 void RSJankStats::SetReportEventComplete(const DataBaseRs& info)
275 {
276 std::lock_guard<std::mutex> lock(mutex_);
277 RS_TRACE_NAME("RSJankStats::SetReportEventComplete receive notification: " + GetSceneDescription(info));
278 const auto animationId = GetAnimationId(info);
279 if (animateJankFrames_.find(animationId) == animateJankFrames_.end()) {
280 ROSEN_LOGD("RSJankStats::SetReportEventComplete Not find exited animationId");
281 } else {
282 animateJankFrames_[animationId].info_ = info;
283 animateJankFrames_[animationId].isSetReportEventComplete_ = true;
284 if (animateJankFrames_.at(animationId).isDisplayAnimator_ != info.isDisplayAnimator) {
285 ROSEN_LOGW("RSJankStats::SetReportEventComplete isDisplayAnimator not consistent");
286 }
287 HandleImplicitAnimationEndInAdvance(animateJankFrames_[animationId], false);
288 }
289 }
290
SetReportEventJankFrame(const DataBaseRs & info,bool isReportTaskDelayed)291 void RSJankStats::SetReportEventJankFrame(const DataBaseRs& info, bool isReportTaskDelayed)
292 {
293 std::lock_guard<std::mutex> lock(mutex_);
294 RS_TRACE_NAME("RSJankStats::SetReportEventJankFrame receive notification: " + GetSceneDescription(info));
295 const auto animationId = GetAnimationId(info);
296 if (animateJankFrames_.find(animationId) == animateJankFrames_.end()) {
297 ROSEN_LOGD("RSJankStats::SetReportEventJankFrame Not find exited animationId");
298 } else {
299 animateJankFrames_[animationId].info_ = info;
300 animateJankFrames_[animationId].isSetReportEventJankFrame_ = true;
301 if (animateJankFrames_.at(animationId).isDisplayAnimator_ != info.isDisplayAnimator) {
302 ROSEN_LOGW("RSJankStats::SetReportEventJankFrame isDisplayAnimator not consistent");
303 }
304 HandleImplicitAnimationEndInAdvance(animateJankFrames_[animationId], isReportTaskDelayed);
305 }
306 }
307
HandleImplicitAnimationEndInAdvance(JankFrames & jankFrames,bool isReportTaskDelayed)308 void RSJankStats::HandleImplicitAnimationEndInAdvance(JankFrames& jankFrames, bool isReportTaskDelayed)
309 {
310 if (jankFrames.isDisplayAnimator_) {
311 return;
312 }
313 if (jankFrames.isSetReportEventComplete_) {
314 ReportEventComplete(jankFrames);
315 }
316 if (jankFrames.isSetReportEventJankFrame_) {
317 ReportEventJankFrame(jankFrames, isReportTaskDelayed);
318 }
319 if (jankFrames.isSetReportEventJankFrame_) {
320 RecordAnimationDynamicFrameRate(jankFrames, isReportTaskDelayed);
321 }
322 if (jankFrames.isSetReportEventComplete_ || jankFrames.isSetReportEventJankFrame_) {
323 SetAnimationTraceEnd(jankFrames);
324 jankFrames.isUpdateJankFrame_ = false;
325 jankFrames.isAnimationEnded_ = true;
326 }
327 jankFrames.isSetReportEventComplete_ = false;
328 jankFrames.isSetReportEventJankFrame_ = false;
329 }
330
SetAppFirstFrame(pid_t appPid)331 void RSJankStats::SetAppFirstFrame(pid_t appPid)
332 {
333 std::lock_guard<std::mutex> lock(mutex_);
334 firstFrameAppPids_.push(appPid);
335 }
336
SetSkipDisplayNode()337 void RSJankStats::SetSkipDisplayNode()
338 {
339 std::lock_guard<std::mutex> lock(mutex_);
340 isSkipDisplayNode_ = true;
341 }
342
ReportEventResponse(const JankFrames & jankFrames) const343 void RSJankStats::ReportEventResponse(const JankFrames& jankFrames) const
344 {
345 auto reportName = "INTERACTION_RESPONSE_LATENCY";
346 const auto &info = jankFrames.info_;
347 int64_t inputTime = ConvertTimeToSystime(info.inputTime);
348 int64_t beginVsyncTime = ConvertTimeToSystime(info.beginVsyncTime);
349 int64_t responseLatency = endTime_ - inputTime;
350 RS_TRACE_NAME_FMT("RSJankStats::ReportEventResponse %s", GetSceneDescription(info).c_str());
351 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
352 OHOS::HiviewDFX::HiSysEvent::EventType::BEHAVIOR, "APP_PID", info.appPid, "VERSION_CODE", info.versionCode,
353 "VERSION_NAME", info.versionName, "BUNDLE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
354 "PROCESS_NAME", info.processName, "PAGE_URL", info.pageUrl, "SCENE_ID", info.sceneId,
355 "SOURCE_TYPE", info.sourceType, "NOTE", info.note, "INPUT_TIME", static_cast<uint64_t>(inputTime),
356 "ANIMATION_START_TIME", static_cast<uint64_t>(beginVsyncTime), "RENDER_TIME", static_cast<uint64_t>(endTime_),
357 "RESPONSE_LATENCY", static_cast<uint64_t>(responseLatency));
358 }
359
ReportEventComplete(const JankFrames & jankFrames) const360 void RSJankStats::ReportEventComplete(const JankFrames& jankFrames) const
361 {
362 auto reportName = "INTERACTION_COMPLETED_LATENCY";
363 const auto &info = jankFrames.info_;
364 int64_t inputTime = ConvertTimeToSystime(info.inputTime);
365 int64_t beginVsyncTime = ConvertTimeToSystime(info.beginVsyncTime);
366 int64_t endVsyncTime = ConvertTimeToSystime(info.endVsyncTime);
367 int64_t animationStartLatency = beginVsyncTime - inputTime;
368 int64_t animationEndLatency = endVsyncTime - beginVsyncTime;
369 int64_t completedLatency = GetCurrentSystimeMs() - inputTime;
370 RS_TRACE_NAME_FMT("RSJankStats::ReportEventComplete %s", GetSceneDescription(info).c_str());
371 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
372 OHOS::HiviewDFX::HiSysEvent::EventType::BEHAVIOR, "APP_PID", info.appPid, "VERSION_CODE", info.versionCode,
373 "VERSION_NAME", info.versionName, "BUNDLE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
374 "PROCESS_NAME", info.processName, "PAGE_URL", info.pageUrl, "SCENE_ID", info.sceneId,
375 "SOURCE_TYPE", info.sourceType, "NOTE", info.note, "INPUT_TIME", static_cast<uint64_t>(inputTime),
376 "ANIMATION_START_LATENCY", static_cast<uint64_t>(animationStartLatency), "ANIMATION_END_LATENCY",
377 static_cast<uint64_t>(animationEndLatency), "E2E_LATENCY", static_cast<uint64_t>(completedLatency));
378 }
379
ReportEventJankFrame(const JankFrames & jankFrames,bool isReportTaskDelayed) const380 void RSJankStats::ReportEventJankFrame(const JankFrames& jankFrames, bool isReportTaskDelayed) const
381 {
382 auto reportName = "INTERACTION_RENDER_JANK";
383 const auto &info = jankFrames.info_;
384 if (!isReportTaskDelayed) {
385 if (jankFrames.totalFrames_ <= 0) {
386 ROSEN_LOGD("RSJankStats::ReportEventJankFrame totalFrames is zero, nothing need to report");
387 return;
388 }
389 float aveFrameTimeSteady = jankFrames.totalFrameTimeSteady_ / static_cast<float>(jankFrames.totalFrames_);
390 RS_TRACE_NAME_FMT("RSJankStats::ReportEventJankFrame maxFrameTime is %" PRId64 "ms: %s",
391 jankFrames.maxFrameTimeSteady_, GetSceneDescription(info).c_str());
392 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
393 OHOS::HiviewDFX::HiSysEvent::EventType::STATISTIC, "UNIQUE_ID", info.uniqueId, "SCENE_ID", info.sceneId,
394 "PROCESS_NAME", info.processName, "MODULE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
395 "PAGE_URL", info.pageUrl, "TOTAL_FRAMES", jankFrames.totalFrames_, "TOTAL_MISSED_FRAMES",
396 jankFrames.totalMissedFrames_, "MAX_FRAMETIME", static_cast<uint64_t>(jankFrames.maxFrameTimeSteady_),
397 "AVERAGE_FRAMETIME", aveFrameTimeSteady, "MAX_SEQ_MISSED_FRAMES", jankFrames.maxSeqMissedFrames_,
398 "IS_FOLD_DISP", IS_FOLD_DISP, "BUNDLE_NAME_EX", info.note);
399 } else {
400 if (jankFrames.lastTotalFrames_ <= 0) {
401 ROSEN_LOGD("RSJankStats::ReportEventJankFrame totalFrames is zero, nothing need to report");
402 return;
403 }
404 float aveFrameTimeSteady =
405 jankFrames.lastTotalFrameTimeSteady_ / static_cast<float>(jankFrames.lastTotalFrames_);
406 RS_TRACE_NAME_FMT("RSJankStats::ReportEventJankFrame maxFrameTime is %" PRId64 "ms: %s",
407 jankFrames.lastMaxFrameTimeSteady_, GetSceneDescription(info).c_str());
408 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
409 OHOS::HiviewDFX::HiSysEvent::EventType::STATISTIC, "UNIQUE_ID", info.uniqueId, "SCENE_ID", info.sceneId,
410 "PROCESS_NAME", info.processName, "MODULE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
411 "PAGE_URL", info.pageUrl, "TOTAL_FRAMES", jankFrames.lastTotalFrames_, "TOTAL_MISSED_FRAMES",
412 jankFrames.lastTotalMissedFrames_, "MAX_FRAMETIME", static_cast<uint64_t>(
413 jankFrames.lastMaxFrameTimeSteady_), "AVERAGE_FRAMETIME", aveFrameTimeSteady,
414 "MAX_SEQ_MISSED_FRAMES", jankFrames.lastMaxSeqMissedFrames_, "IS_FOLD_DISP", IS_FOLD_DISP,
415 "BUNDLE_NAME_EX", info.note);
416 }
417 }
418
ReportEventFirstFrame()419 void RSJankStats::ReportEventFirstFrame()
420 {
421 while (!firstFrameAppPids_.empty()) {
422 pid_t appPid = firstFrameAppPids_.front();
423 ReportEventFirstFrameByPid(appPid);
424 firstFrameAppPids_.pop();
425 }
426 }
427
ReportEventFirstFrameByPid(pid_t appPid) const428 void RSJankStats::ReportEventFirstFrameByPid(pid_t appPid) const
429 {
430 RS_TRACE_NAME_FMT("RSJankStats::ReportEventFirstFrame app pid %d", appPid);
431 auto reportName = "FIRST_FRAME_DRAWN";
432 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
433 OHOS::HiviewDFX::HiSysEvent::EventType::BEHAVIOR, "APP_PID", static_cast<int32_t>(appPid));
434 }
435
RecordJankFrameInit()436 void RSJankStats::RecordJankFrameInit()
437 {
438 for (auto& recordStats : jankExplicitAnimatorFrameRecorder_) {
439 recordStats.isRecorded_ = false;
440 }
441 for (auto& recordStats : jankImplicitAnimatorFrameRecorder_) {
442 recordStats.isRecorded_ = false;
443 }
444 }
445
RecordJankFrame()446 void RSJankStats::RecordJankFrame()
447 {
448 const int64_t missedFramesByDuration = static_cast<int64_t>((endTimeSteady_ - startTimeSteady_) / VSYNC_PERIOD);
449 if (missedFramesByDuration > 0 && explicitAnimationTotal_ > 0) {
450 for (auto& recordStats : jankExplicitAnimatorFrameRecorder_) {
451 RecordJankFrameSingle(missedFramesByDuration, recordStats);
452 }
453 }
454 const int64_t missedFramesByInterval = static_cast<int64_t>(
455 (isFirstSetEnd_ ? (endTimeSteady_ - startTimeSteady_) : (endTimeSteady_ - lastEndTimeSteady_)) / VSYNC_PERIOD);
456 if (missedFramesByInterval > 0 && implicitAnimationTotal_ > 0) {
457 for (auto& recordStats : jankImplicitAnimatorFrameRecorder_) {
458 RecordJankFrameSingle(missedFramesByInterval, recordStats);
459 }
460 }
461 }
462
RecordJankFrameSingle(int64_t missedFrames,JankFrameRecordStats & recordStats)463 void RSJankStats::RecordJankFrameSingle(int64_t missedFrames, JankFrameRecordStats& recordStats)
464 {
465 if (recordStats.isRecorded_) {
466 return;
467 }
468 if (missedFrames >= recordStats.recordThreshold_) {
469 RS_TRACE_INT(recordStats.countTraceName_, missedFrames);
470 recordStats.isRecorded_ = true;
471 RS_TRACE_INT(recordStats.countTraceName_, 0);
472 }
473 }
474
RecordAnimationDynamicFrameRate(JankFrames & jankFrames,bool isReportTaskDelayed)475 void RSJankStats::RecordAnimationDynamicFrameRate(JankFrames& jankFrames, bool isReportTaskDelayed)
476 {
477 if (jankFrames.isFrameRateRecorded_) {
478 return;
479 }
480 const int32_t traceId = jankFrames.traceId_;
481 if (traceId == TRACE_ID_INITIAL) {
482 ROSEN_LOGE("RSJankStats::RecordAnimationDynamicFrameRate traceId not initialized");
483 return;
484 }
485 if (!isReportTaskDelayed) {
486 if (animationAsyncTraces_.find(traceId) == animationAsyncTraces_.end() || jankFrames.totalFrames_ <= 0 ||
487 jankFrames.startTimeSteady_ == TIMESTAMP_INITIAL || jankFrames.endTimeSteady_ == TIMESTAMP_INITIAL ||
488 jankFrames.endTimeSteady_ <= jankFrames.startTimeSteady_) {
489 return;
490 }
491 float animationDuration = static_cast<float>(jankFrames.endTimeSteady_ - jankFrames.startTimeSteady_) / S_TO_MS;
492 float animationTotalFrames = static_cast<float>(jankFrames.totalFrames_);
493 float animationDynamicFrameRate = animationTotalFrames / animationDuration;
494 RS_TRACE_NAME_FMT("RSJankStats::RecordAnimationDynamicFrameRate frame rate is %.2f: %s",
495 animationDynamicFrameRate, animationAsyncTraces_.at(traceId).traceName_.c_str());
496 } else {
497 if (animationAsyncTraces_.find(traceId) == animationAsyncTraces_.end() || jankFrames.lastTotalFrames_ <= 0 ||
498 jankFrames.startTimeSteady_ == TIMESTAMP_INITIAL || jankFrames.lastEndTimeSteady_ == TIMESTAMP_INITIAL ||
499 jankFrames.lastEndTimeSteady_ <= jankFrames.startTimeSteady_) {
500 return;
501 }
502 float animationDuration =
503 static_cast<float>(jankFrames.lastEndTimeSteady_ - jankFrames.startTimeSteady_) / S_TO_MS;
504 float animationTotalFrames = static_cast<float>(jankFrames.lastTotalFrames_);
505 float animationDynamicFrameRate = animationTotalFrames / animationDuration;
506 RS_TRACE_NAME_FMT("RSJankStats::RecordAnimationDynamicFrameRate frame rate is %.2f: %s",
507 animationDynamicFrameRate, animationAsyncTraces_.at(traceId).traceName_.c_str());
508 }
509 jankFrames.isFrameRateRecorded_ = true;
510 }
511
SetAnimationTraceBegin(std::pair<int64_t,std::string> animationId,const JankFrames & jankFrames)512 void RSJankStats::SetAnimationTraceBegin(std::pair<int64_t, std::string> animationId, const JankFrames& jankFrames)
513 {
514 const int32_t traceId = jankFrames.traceId_;
515 if (traceId == TRACE_ID_INITIAL) {
516 ROSEN_LOGE("RSJankStats::SetAnimationTraceBegin traceId not initialized");
517 return;
518 }
519 if (animationAsyncTraces_.find(traceId) != animationAsyncTraces_.end()) {
520 return;
521 }
522 const auto &info = jankFrames.info_;
523 const std::string traceName = GetSceneDescription(info);
524 AnimationTraceStats traceStat = {.animationId_ = animationId,
525 .traceName_ = traceName,
526 .traceCreateTimeSteady_ = endTimeSteady_,
527 .isDisplayAnimator_ = info.isDisplayAnimator};
528 animationAsyncTraces_.emplace(traceId, traceStat);
529 if (info.isDisplayAnimator) {
530 explicitAnimationTotal_++;
531 } else {
532 implicitAnimationTotal_++;
533 }
534 RS_ASYNC_TRACE_BEGIN(traceName, traceId);
535 }
536
SetAnimationTraceEnd(const JankFrames & jankFrames)537 void RSJankStats::SetAnimationTraceEnd(const JankFrames& jankFrames)
538 {
539 const int32_t traceId = jankFrames.traceId_;
540 if (traceId == TRACE_ID_INITIAL) {
541 ROSEN_LOGE("RSJankStats::SetAnimationTraceEnd traceId not initialized");
542 return;
543 }
544 if (animationAsyncTraces_.find(traceId) == animationAsyncTraces_.end()) {
545 return;
546 }
547 const bool isDisplayAnimator = animationAsyncTraces_.at(traceId).isDisplayAnimator_;
548 RS_ASYNC_TRACE_END(animationAsyncTraces_.at(traceId).traceName_, traceId);
549 animationAsyncTraces_.erase(traceId);
550 if (isDisplayAnimator) {
551 explicitAnimationTotal_--;
552 } else {
553 implicitAnimationTotal_--;
554 }
555 }
556
CheckAnimationTraceTimeout()557 void RSJankStats::CheckAnimationTraceTimeout()
558 {
559 if (++animationTraceCheckCnt_ < ANIMATION_TRACE_CHECK_FREQ) {
560 return;
561 }
562 EraseIf(animationAsyncTraces_, [this](const auto& pair) -> bool {
563 bool needErase = endTimeSteady_ - pair.second.traceCreateTimeSteady_ > ANIMATION_TIMEOUT;
564 if (needErase) {
565 RS_ASYNC_TRACE_END(pair.second.traceName_, pair.first);
566 if (pair.second.isDisplayAnimator_) {
567 explicitAnimationTotal_--;
568 } else {
569 implicitAnimationTotal_--;
570 }
571 animateJankFrames_.erase(pair.second.animationId_);
572 }
573 return needErase;
574 });
575 animationTraceCheckCnt_ = 0;
576 }
577
ClearAllAnimation()578 void RSJankStats::ClearAllAnimation()
579 {
580 RS_TRACE_NAME("RSJankStats::ClearAllAnimation");
581 EraseIf(animationAsyncTraces_, [](const auto& pair) -> bool {
582 RS_ASYNC_TRACE_END(pair.second.traceName_, pair.first);
583 return true;
584 });
585 explicitAnimationTotal_ = 0;
586 implicitAnimationTotal_ = 0;
587 animateJankFrames_.clear();
588 }
589
GetSceneDescription(const DataBaseRs & info) const590 std::string RSJankStats::GetSceneDescription(const DataBaseRs& info) const
591 {
592 std::stringstream sceneDescription;
593 int64_t inputTime = ConvertTimeToSystime(info.inputTime);
594 std::string animatorType = (info.isDisplayAnimator ? "EXPLICIT_ANIMATOR" : "IMPLICIT_ANIMATOR");
595 sceneDescription << info.sceneId << ", " << info.bundleName << ", " << info.pageUrl
596 << ", " << inputTime << ", " << animatorType << ", uid" << info.uniqueId;
597 return sceneDescription.str();
598 }
599
GetAnimationId(const DataBaseRs & info) const600 std::pair<int64_t, std::string> RSJankStats::GetAnimationId(const DataBaseRs& info) const
601 {
602 std::pair<int64_t, std::string> animationId(info.uniqueId, info.sceneId);
603 return animationId;
604 }
605
GetTraceIdInit(const DataBaseRs & info,int64_t setTimeSteady)606 int32_t RSJankStats::GetTraceIdInit(const DataBaseRs& info, int64_t setTimeSteady)
607 {
608 if (traceIdRemainder_.find(info.uniqueId) == traceIdRemainder_.end()) {
609 TraceIdRemainderStats traceIdStat;
610 traceIdRemainder_.emplace(info.uniqueId, traceIdStat);
611 }
612 if (traceIdRemainder_.at(info.uniqueId).remainder_ >= TRACE_ID_SCALE_PARAM) {
613 traceIdRemainder_[info.uniqueId].remainder_ = 0;
614 }
615 traceIdRemainder_[info.uniqueId].setTimeSteady_ = setTimeSteady;
616 int64_t mappedUniqueId = info.uniqueId * TRACE_ID_SCALE_PARAM + (traceIdRemainder_[info.uniqueId].remainder_++);
617 int32_t traceId = static_cast<int32_t>(mappedUniqueId);
618 return traceId;
619 }
620
ConvertTimeToSystime(int64_t time) const621 int64_t RSJankStats::ConvertTimeToSystime(int64_t time) const
622 {
623 if (time <= 0) {
624 ROSEN_LOGW("RSJankStats::ConvertTimeToSystime, time is error");
625 return 0;
626 }
627 struct timespec ts = { 0, 0 };
628 if (clock_gettime(CLOCK_MONOTONIC, &ts) != 0) {
629 return 0;
630 }
631 int64_t nowTime = static_cast<int64_t>(ts.tv_sec) * S_TO_NS + static_cast<int64_t>(ts.tv_nsec);
632 int64_t curSysTime = GetCurrentSystimeMs();
633 int64_t sysTime = curSysTime - (nowTime - time) / MS_TO_NS;
634 return sysTime;
635 }
636
GetCurrentSystimeMs() const637 int64_t RSJankStats::GetCurrentSystimeMs() const
638 {
639 auto curTime = std::chrono::system_clock::now().time_since_epoch();
640 int64_t curSysTime = std::chrono::duration_cast<std::chrono::milliseconds>(curTime).count();
641 return curSysTime;
642 }
643
GetCurrentSteadyTimeMs() const644 int64_t RSJankStats::GetCurrentSteadyTimeMs() const
645 {
646 auto curTime = std::chrono::steady_clock::now().time_since_epoch();
647 int64_t curSteadyTime = std::chrono::duration_cast<std::chrono::milliseconds>(curTime).count();
648 return curSteadyTime;
649 }
650
651 } // namespace Rosen
652 } // namespace OHOS
653