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_background_thread.h"
28 #include "common/rs_common_def.h"
29 #include "platform/common/rs_log.h"
30
31 namespace OHOS {
32 namespace Rosen {
33 namespace {
34 constexpr float HITCH_TIME_EPSILON = 0.0001f; // 0.0001ms
35 constexpr float VSYNC_PERIOD = 16.6f; // 16.6ms
36 constexpr float S_TO_MS = 1000.f; // s to ms
37 constexpr int64_t ANIMATION_TIMEOUT = 5000; // 5s
38 constexpr int64_t S_TO_NS = 1000000000; // s to ns
39 constexpr int64_t VSYNC_JANK_LOG_THRESHOLED = 6; // 6 times vsync
40 }
41
GetInstance()42 RSJankStats& RSJankStats::GetInstance()
43 {
44 static RSJankStats instance;
45 return instance;
46 }
47
SetOnVsyncStartTime(int64_t onVsyncStartTime,int64_t onVsyncStartTimeSteady,float onVsyncStartTimeSteadyFloat)48 void RSJankStats::SetOnVsyncStartTime(int64_t onVsyncStartTime, int64_t onVsyncStartTimeSteady,
49 float onVsyncStartTimeSteadyFloat)
50 {
51 std::lock_guard<std::mutex> lock(mutex_);
52 rsStartTime_ = onVsyncStartTime;
53 rsStartTimeSteady_ = onVsyncStartTimeSteady;
54 if (IS_CALCULATE_PRECISE_HITCH_TIME) {
55 rsStartTimeSteadyFloat_ = onVsyncStartTimeSteadyFloat;
56 }
57 }
58
SetAccumulatedBufferCount(int accumulatedBufferCount)59 void RSJankStats::SetAccumulatedBufferCount(int accumulatedBufferCount)
60 {
61 std::lock_guard<std::mutex> lock(mutex_);
62 accumulatedBufferCount_ = accumulatedBufferCount;
63 }
64
SetStartTime(bool doDirectComposition)65 void RSJankStats::SetStartTime(bool doDirectComposition)
66 {
67 std::lock_guard<std::mutex> lock(mutex_);
68 if (!doDirectComposition) {
69 rtStartTime_ = GetCurrentSystimeMs();
70 rtStartTimeSteady_ = GetCurrentSteadyTimeMs();
71 }
72 if (isFirstSetStart_) {
73 lastReportTime_ = rtStartTime_;
74 lastReportTimeSteady_ = rtStartTimeSteady_;
75 }
76 for (auto &[animationId, jankFrames] : animateJankFrames_) {
77 jankFrames.isReportEventResponse_ = jankFrames.isSetReportEventResponseTemp_;
78 jankFrames.isSetReportEventResponseTemp_ = jankFrames.isSetReportEventResponse_;
79 jankFrames.isSetReportEventResponse_ = false;
80 jankFrames.isReportEventComplete_ = jankFrames.isSetReportEventComplete_;
81 jankFrames.isSetReportEventComplete_ = false;
82 jankFrames.isReportEventJankFrame_ = jankFrames.isSetReportEventJankFrame_;
83 jankFrames.isSetReportEventJankFrame_ = false;
84 }
85 isFirstSetStart_ = false;
86 }
87
SetEndTime(bool skipJankAnimatorFrame,bool discardJankFrames,uint32_t dynamicRefreshRate,bool doDirectComposition,bool isReportTaskDelayed)88 void RSJankStats::SetEndTime(bool skipJankAnimatorFrame, bool discardJankFrames, uint32_t dynamicRefreshRate,
89 bool doDirectComposition, bool isReportTaskDelayed)
90 {
91 std::lock_guard<std::mutex> lock(mutex_);
92 if (rtStartTime_ == TIMESTAMP_INITIAL || rtStartTimeSteady_ == TIMESTAMP_INITIAL ||
93 rsStartTime_ == TIMESTAMP_INITIAL || rsStartTimeSteady_ == TIMESTAMP_INITIAL) {
94 ROSEN_LOGE("RSJankStats::SetEndTime startTime is not initialized");
95 return;
96 }
97 isCurrentFrameSwitchToNotDoDirectComposition_ = isLastFrameDoDirectComposition_ && !doDirectComposition;
98 if (!doDirectComposition) { UpdateEndTime(); }
99 if (discardJankFrames) { ClearAllAnimation(); }
100 SetRSJankStats(skipJankAnimatorFrame || discardJankFrames, dynamicRefreshRate);
101 RecordJankFrame(dynamicRefreshRate);
102 for (auto &[animationId, jankFrames] : animateJankFrames_) {
103 if (jankFrames.isReportEventResponse_) {
104 ReportEventResponse(jankFrames);
105 jankFrames.isUpdateJankFrame_ = true;
106 }
107 // skip jank frame statistics at the first frame of animation && at the end frame of implicit animation
108 if (jankFrames.isUpdateJankFrame_ && !jankFrames.isFirstFrame_ && !(!jankFrames.isDisplayAnimator_ &&
109 (jankFrames.isReportEventComplete_ || jankFrames.isReportEventJankFrame_))) {
110 UpdateJankFrame(jankFrames, skipJankAnimatorFrame, dynamicRefreshRate);
111 }
112 if (jankFrames.isReportEventResponse_ && !jankFrames.isAnimationEnded_) {
113 SetAnimationTraceBegin(animationId, jankFrames);
114 }
115 if (jankFrames.isReportEventJankFrame_) {
116 RecordAnimationDynamicFrameRate(jankFrames, isReportTaskDelayed);
117 }
118 if (jankFrames.isReportEventComplete_ || jankFrames.isReportEventJankFrame_) {
119 SetAnimationTraceEnd(jankFrames);
120 jankFrames.isUpdateJankFrame_ = false;
121 jankFrames.isAnimationEnded_ = true;
122 }
123 if (jankFrames.isReportEventComplete_) {
124 ReportEventComplete(jankFrames);
125 }
126 if (jankFrames.isReportEventJankFrame_) {
127 ReportEventJankFrame(jankFrames, isReportTaskDelayed);
128 ReportEventHitchTimeRatio(jankFrames, isReportTaskDelayed);
129 }
130 jankFrames.isFirstFrame_ = jankFrames.isFirstFrameTemp_;
131 jankFrames.isFirstFrameTemp_ = false;
132 }
133 ReportEventFirstFrame();
134 CheckAnimationTraceTimeout();
135 isLastFrameDoDirectComposition_ = doDirectComposition;
136 isFirstSetEnd_ = false;
137 }
138
UpdateEndTime()139 void RSJankStats::UpdateEndTime()
140 {
141 if (isFirstSetEnd_) {
142 rtLastEndTime_ = GetCurrentSystimeMs();
143 rtEndTime_ = rtLastEndTime_;
144 rtLastEndTimeSteady_ = GetCurrentSteadyTimeMs();
145 rtEndTimeSteady_ = rtLastEndTimeSteady_;
146 if (IS_CALCULATE_PRECISE_HITCH_TIME) {
147 rtLastEndTimeSteadyFloat_ = GetCurrentSteadyTimeMsFloat();
148 rtEndTimeSteadyFloat_ = rtLastEndTimeSteadyFloat_;
149 }
150 return;
151 }
152 rtLastEndTime_ = rtEndTime_;
153 rtEndTime_ = GetCurrentSystimeMs();
154 rtLastEndTimeSteady_ = rtEndTimeSteady_;
155 rtEndTimeSteady_ = GetCurrentSteadyTimeMs();
156 if (IS_CALCULATE_PRECISE_HITCH_TIME) {
157 rtLastEndTimeSteadyFloat_ = rtEndTimeSteadyFloat_;
158 rtEndTimeSteadyFloat_ = GetCurrentSteadyTimeMsFloat();
159 }
160 }
161
HandleDirectComposition(const JankDurationParams & rsParams,bool isReportTaskDelayed)162 void RSJankStats::HandleDirectComposition(const JankDurationParams& rsParams, bool isReportTaskDelayed)
163 {
164 {
165 std::lock_guard<std::mutex> lock(mutex_);
166 rsStartTime_ = rsParams.timeStart_;
167 rsStartTimeSteady_ = rsParams.timeStartSteady_;
168 rtStartTime_ = rsParams.timeEnd_;
169 rtStartTimeSteady_ = rsParams.timeEndSteady_;
170 rtLastEndTime_ = rtEndTime_;
171 rtEndTime_ = rsParams.timeEnd_;
172 rtLastEndTimeSteady_ = rtEndTimeSteady_;
173 rtEndTimeSteady_ = rsParams.timeEndSteady_;
174 if (IS_CALCULATE_PRECISE_HITCH_TIME) {
175 rsStartTimeSteadyFloat_ = rsParams.timeStartSteadyFloat_;
176 rtLastEndTimeSteadyFloat_ = rtEndTimeSteadyFloat_;
177 rtEndTimeSteadyFloat_ = rsParams.timeEndSteadyFloat_;
178 }
179 }
180 SetStartTime(true);
181 SetEndTime(rsParams.skipJankAnimatorFrame_, rsParams.discardJankFrames_,
182 rsParams.refreshRate_, true, isReportTaskDelayed);
183 }
184
185 // dynamicRefreshRate is retained for future algorithm adjustment, keep it unused currently
SetRSJankStats(bool skipJankStats,uint32_t)186 void RSJankStats::SetRSJankStats(bool skipJankStats, uint32_t /* dynamicRefreshRate */)
187 {
188 if (skipJankStats) {
189 RS_TRACE_NAME("RSJankStats::SetRSJankStats skip jank frame statistics");
190 return;
191 }
192 const int64_t frameTime = GetEffectiveFrameTime(true);
193 const int64_t missedVsync = static_cast<int64_t>(frameTime / VSYNC_PERIOD);
194 if (missedVsync <= 0) {
195 return;
196 }
197 RS_TRACE_NAME_FMT("RSJankStats::SetRSJankStats missedVsync %" PRId64 " frameTime %" PRId64, missedVsync, frameTime);
198 if (missedVsync >= VSYNC_JANK_LOG_THRESHOLED) {
199 ROSEN_LOGW("RSJankStats::SetJankStats jank frames %{public}" PRId64, missedVsync);
200 }
201 const size_t type = GetJankRangeType(missedVsync);
202 if (type == JANK_FRAME_INVALID) {
203 return;
204 }
205 if (rsJankStats_[type] == USHRT_MAX) {
206 ROSEN_LOGD("RSJankStats::SetJankStats rsJankStats_ value oversteps USHRT_MAX");
207 return;
208 }
209 if (type == JANK_FRAME_6_FREQ) {
210 RS_TRACE_INT(JANK_FRAME_1_TO_5F_COUNT_TRACE_NAME, missedVsync);
211 } else {
212 RS_TRACE_INT(JANK_FRAME_6F_COUNT_TRACE_NAME, missedVsync);
213 lastJankFrame6FreqTimeSteady_ = rtEndTimeSteady_;
214 }
215 rsJankStats_[type]++;
216 isNeedReportJankStats_ = true;
217 if (type == JANK_FRAME_6_FREQ) {
218 RS_TRACE_INT(JANK_FRAME_1_TO_5F_COUNT_TRACE_NAME, 0);
219 } else {
220 RS_TRACE_INT(JANK_FRAME_6F_COUNT_TRACE_NAME, 0);
221 }
222 }
223
GetJankRangeType(int64_t missedVsync) const224 size_t RSJankStats::GetJankRangeType(int64_t missedVsync) const
225 {
226 size_t type = JANK_FRAME_INVALID;
227 if (missedVsync < 6) { // JANK_FRAME_6_FREQ : (0,6)
228 type = JANK_FRAME_6_FREQ;
229 } else if (missedVsync < 15) { // JANK_FRAME_15_FREQ : [6,15)
230 type = JANK_FRAME_15_FREQ;
231 } else if (missedVsync < 20) { // JANK_FRAME_20_FREQ : [15,20)
232 type = JANK_FRAME_20_FREQ;
233 } else if (missedVsync < 36) { // JANK_FRAME_36_FREQ : [20,36)
234 type = JANK_FRAME_36_FREQ;
235 } else if (missedVsync < 48) { // JANK_FRAME_48_FREQ : [36,48)
236 type = JANK_FRAME_48_FREQ;
237 } else if (missedVsync < 60) { // JANK_FRAME_60_FREQ : [48,60)
238 type = JANK_FRAME_60_FREQ;
239 } else if (missedVsync < 120) { // JANK_FRAME_120_FREQ : [60,120)
240 type = JANK_FRAME_120_FREQ;
241 } else if (missedVsync < 180) { // JANK_FRAME_180_FREQ : [120,180)
242 type = JANK_FRAME_180_FREQ;
243 } else {
244 ROSEN_LOGW("RSJankStats::SetJankStats jank frames over 180");
245 }
246 return type;
247 }
248
UpdateJankFrame(JankFrames & jankFrames,bool skipJankStats,uint32_t dynamicRefreshRate)249 void RSJankStats::UpdateJankFrame(JankFrames& jankFrames, bool skipJankStats, uint32_t dynamicRefreshRate)
250 {
251 if (skipJankStats) {
252 RS_TRACE_NAME("RSJankStats::UpdateJankFrame skip jank animator frame");
253 return;
254 }
255 if (jankFrames.startTime_ == TIMESTAMP_INITIAL || jankFrames.startTimeSteady_ == TIMESTAMP_INITIAL) {
256 jankFrames.startTime_ = rsStartTime_;
257 jankFrames.startTimeSteady_ = rsStartTimeSteady_;
258 }
259 jankFrames.lastEndTimeSteady_ = jankFrames.endTimeSteady_;
260 jankFrames.endTimeSteady_ = rtEndTimeSteady_;
261 jankFrames.lastTotalFrames_ = jankFrames.totalFrames_;
262 jankFrames.lastTotalFrameTimeSteady_ = jankFrames.totalFrameTimeSteady_;
263 jankFrames.lastTotalMissedFrames_ = jankFrames.totalMissedFrames_;
264 jankFrames.lastMaxFrameTimeSteady_ = jankFrames.maxFrameTimeSteady_;
265 jankFrames.lastMaxSeqMissedFrames_ = jankFrames.maxSeqMissedFrames_;
266 jankFrames.lastMaxFrameOccurenceTimeSteady_ = jankFrames.maxFrameOccurenceTimeSteady_;
267 if (dynamicRefreshRate == 0) {
268 dynamicRefreshRate = STANDARD_REFRESH_RATE;
269 }
270 const float standardFrameTime = S_TO_MS / dynamicRefreshRate;
271 const bool isConsiderRsStartTime =
272 jankFrames.isDisplayAnimator_ || jankFrames.isFirstFrame_ || isFirstSetEnd_;
273 const float accumulatedTime = accumulatedBufferCount_ * standardFrameTime;
274 const int64_t frameDuration = std::max<int64_t>(0, GetEffectiveFrameTime(isConsiderRsStartTime) - accumulatedTime);
275 const int32_t missedFramesToReport = static_cast<int32_t>(frameDuration / VSYNC_PERIOD);
276 jankFrames.totalFrames_++;
277 jankFrames.totalFrameTimeSteady_ += frameDuration;
278 if (frameDuration > jankFrames.maxFrameTimeSteady_) {
279 jankFrames.maxFrameOccurenceTimeSteady_ = rtEndTimeSteady_;
280 jankFrames.maxFrameTimeSteady_ = frameDuration;
281 }
282 if (missedFramesToReport > 0) {
283 jankFrames.totalMissedFrames_ += missedFramesToReport;
284 jankFrames.seqMissedFrames_ += missedFramesToReport;
285 jankFrames.maxSeqMissedFrames_ = std::max<int32_t>(jankFrames.maxSeqMissedFrames_, jankFrames.seqMissedFrames_);
286 } else {
287 jankFrames.seqMissedFrames_ = 0;
288 }
289 UpdateHitchTime(jankFrames, standardFrameTime);
290 }
291
UpdateHitchTime(JankFrames & jankFrames,float standardFrameTime)292 void RSJankStats::UpdateHitchTime(JankFrames& jankFrames, float standardFrameTime)
293 {
294 jankFrames.lastMaxHitchTime_ = jankFrames.maxHitchTime_;
295 jankFrames.lastTotalHitchTimeSteady_ = jankFrames.totalHitchTimeSteady_;
296 jankFrames.lastTotalFrameTimeSteadyForHTR_ = jankFrames.totalFrameTimeSteadyForHTR_;
297 jankFrames.lastMaxHitchOccurenceTimeSteady_ = jankFrames.maxHitchOccurenceTimeSteady_;
298 const float frameTimeForHTR = (IS_CALCULATE_PRECISE_HITCH_TIME ? GetEffectiveFrameTimeFloat(true) :
299 static_cast<float>(GetEffectiveFrameTime(true)));
300 const float frameHitchTime = std::max<float>(0.f, frameTimeForHTR - standardFrameTime);
301 const bool isConsiderRsStartTimeForHTR = jankFrames.isFirstFrame_ || isFirstSetEnd_;
302 const int64_t frameDurationForHTR = (isConsiderRsStartTimeForHTR ?
303 (rtEndTimeSteady_ - rsStartTimeSteady_) : (rtEndTimeSteady_ - rtLastEndTimeSteady_));
304 if (frameHitchTime - jankFrames.maxHitchTime_ > HITCH_TIME_EPSILON) {
305 jankFrames.maxHitchOccurenceTimeSteady_ = rtEndTimeSteady_;
306 jankFrames.maxHitchTime_ = frameHitchTime;
307 }
308 jankFrames.totalHitchTimeSteady_ += frameHitchTime;
309 jankFrames.totalFrameTimeSteadyForHTR_ += frameDurationForHTR;
310 }
311
ReportJankStats()312 void RSJankStats::ReportJankStats()
313 {
314 std::lock_guard<std::mutex> lock(mutex_);
315 if (lastReportTime_ == TIMESTAMP_INITIAL || lastReportTimeSteady_ == TIMESTAMP_INITIAL) {
316 ROSEN_LOGE("RSJankStats::ReportJankStats lastReportTime is not initialized");
317 return;
318 }
319 int64_t reportTime = GetCurrentSystimeMs();
320 int64_t reportTimeSteady = GetCurrentSteadyTimeMs();
321 if (!isNeedReportJankStats_) {
322 ROSEN_LOGD("RSJankStats::ReportJankStats Nothing need to report");
323 lastReportTime_ = reportTime;
324 lastReportTimeSteady_ = reportTimeSteady;
325 lastJankFrame6FreqTimeSteady_ = TIMESTAMP_INITIAL;
326 std::fill(rsJankStats_.begin(), rsJankStats_.end(), 0);
327 return;
328 }
329 int64_t lastJankFrame6FreqTime = ((lastJankFrame6FreqTimeSteady_ == TIMESTAMP_INITIAL) ? 0 :
330 (reportTime - (reportTimeSteady - lastJankFrame6FreqTimeSteady_)));
331 int64_t reportDuration = reportTimeSteady - lastReportTimeSteady_;
332 int64_t lastReportTime = lastReportTime_;
333 std::vector<uint16_t> rsJankStats = rsJankStats_;
334 RS_TRACE_NAME("RSJankStats::ReportJankStats receive notification: reportTime " + std::to_string(reportTime) +
335 ", lastJankFrame6FreqTime " + std::to_string(lastJankFrame6FreqTime));
336 RSBackgroundThread::Instance().PostTask([reportDuration, lastReportTime, rsJankStats]() {
337 auto reportName = "JANK_STATS_RS";
338 RS_TRACE_NAME("RSJankStats::ReportJankStats in RSBackgroundThread");
339 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
340 OHOS::HiviewDFX::HiSysEvent::EventType::STATISTIC, "STARTTIME", static_cast<uint64_t>(lastReportTime),
341 "DURATION", static_cast<uint64_t>(reportDuration), "JANK_STATS", rsJankStats,
342 "JANK_STATS_VER", JANK_RANGE_VERSION);
343 });
344 lastReportTime_ = reportTime;
345 lastReportTimeSteady_ = reportTimeSteady;
346 lastJankFrame6FreqTimeSteady_ = TIMESTAMP_INITIAL;
347 std::fill(rsJankStats_.begin(), rsJankStats_.end(), 0);
348 isNeedReportJankStats_ = false;
349 }
350
SetReportEventResponse(const DataBaseRs & info)351 void RSJankStats::SetReportEventResponse(const DataBaseRs& info)
352 {
353 std::lock_guard<std::mutex> lock(mutex_);
354 RS_TRACE_NAME("RSJankStats::SetReportEventResponse receive notification: " + GetSceneDescription(info));
355 int64_t setTimeSteady = GetCurrentSteadyTimeMs();
356 EraseIf(animateJankFrames_, [setTimeSteady](const auto& pair) -> bool {
357 return setTimeSteady - pair.second.setTimeSteady_ > ANIMATION_TIMEOUT;
358 });
359 EraseIf(traceIdRemainder_, [setTimeSteady](const auto& pair) -> bool {
360 return setTimeSteady - pair.second.setTimeSteady_ > ANIMATION_TIMEOUT;
361 });
362 const auto animationId = GetAnimationId(info);
363 if (animateJankFrames_.find(animationId) == animateJankFrames_.end()) {
364 JankFrames jankFrames;
365 jankFrames.info_ = info;
366 jankFrames.isSetReportEventResponse_ = true;
367 jankFrames.setTimeSteady_ = setTimeSteady;
368 jankFrames.isFirstFrame_ = true;
369 jankFrames.isFirstFrameTemp_ = true;
370 jankFrames.traceId_ = GetTraceIdInit(info, setTimeSteady);
371 jankFrames.isDisplayAnimator_ = info.isDisplayAnimator;
372 animateJankFrames_.emplace(animationId, jankFrames);
373 } else {
374 animateJankFrames_[animationId].info_ = info;
375 animateJankFrames_[animationId].isSetReportEventResponse_ = true;
376 if (animateJankFrames_.at(animationId).isDisplayAnimator_ != info.isDisplayAnimator) {
377 ROSEN_LOGW("RSJankStats::SetReportEventResponse isDisplayAnimator not consistent");
378 }
379 }
380 }
381
SetReportEventComplete(const DataBaseRs & info)382 void RSJankStats::SetReportEventComplete(const DataBaseRs& info)
383 {
384 std::lock_guard<std::mutex> lock(mutex_);
385 RS_TRACE_NAME("RSJankStats::SetReportEventComplete receive notification: " + GetSceneDescription(info));
386 const auto animationId = GetAnimationId(info);
387 if (animateJankFrames_.find(animationId) == animateJankFrames_.end()) {
388 ROSEN_LOGD("RSJankStats::SetReportEventComplete Not find exited animationId");
389 } else {
390 animateJankFrames_[animationId].info_ = info;
391 animateJankFrames_[animationId].isSetReportEventComplete_ = true;
392 if (animateJankFrames_.at(animationId).isDisplayAnimator_ != info.isDisplayAnimator) {
393 ROSEN_LOGW("RSJankStats::SetReportEventComplete isDisplayAnimator not consistent");
394 }
395 HandleImplicitAnimationEndInAdvance(animateJankFrames_[animationId], false);
396 }
397 }
398
SetReportEventJankFrame(const DataBaseRs & info,bool isReportTaskDelayed)399 void RSJankStats::SetReportEventJankFrame(const DataBaseRs& info, bool isReportTaskDelayed)
400 {
401 std::lock_guard<std::mutex> lock(mutex_);
402 RS_TRACE_NAME("RSJankStats::SetReportEventJankFrame receive notification: " + GetSceneDescription(info));
403 const auto animationId = GetAnimationId(info);
404 if (animateJankFrames_.find(animationId) == animateJankFrames_.end()) {
405 ROSEN_LOGD("RSJankStats::SetReportEventJankFrame Not find exited animationId");
406 } else {
407 animateJankFrames_[animationId].info_ = info;
408 animateJankFrames_[animationId].isSetReportEventJankFrame_ = true;
409 if (animateJankFrames_.at(animationId).isDisplayAnimator_ != info.isDisplayAnimator) {
410 ROSEN_LOGW("RSJankStats::SetReportEventJankFrame isDisplayAnimator not consistent");
411 }
412 HandleImplicitAnimationEndInAdvance(animateJankFrames_[animationId], isReportTaskDelayed);
413 }
414 }
415
HandleImplicitAnimationEndInAdvance(JankFrames & jankFrames,bool isReportTaskDelayed)416 void RSJankStats::HandleImplicitAnimationEndInAdvance(JankFrames& jankFrames, bool isReportTaskDelayed)
417 {
418 if (jankFrames.isDisplayAnimator_) {
419 return;
420 }
421 if (jankFrames.isSetReportEventJankFrame_) {
422 RecordAnimationDynamicFrameRate(jankFrames, isReportTaskDelayed);
423 }
424 if (jankFrames.isSetReportEventComplete_ || jankFrames.isSetReportEventJankFrame_) {
425 SetAnimationTraceEnd(jankFrames);
426 jankFrames.isUpdateJankFrame_ = false;
427 jankFrames.isAnimationEnded_ = true;
428 }
429 if (jankFrames.isSetReportEventComplete_) {
430 ReportEventComplete(jankFrames);
431 }
432 if (jankFrames.isSetReportEventJankFrame_) {
433 ReportEventJankFrame(jankFrames, isReportTaskDelayed);
434 ReportEventHitchTimeRatio(jankFrames, isReportTaskDelayed);
435 }
436 jankFrames.isSetReportEventComplete_ = false;
437 jankFrames.isSetReportEventJankFrame_ = false;
438 }
439
SetAppFirstFrame(pid_t appPid)440 void RSJankStats::SetAppFirstFrame(pid_t appPid)
441 {
442 std::lock_guard<std::mutex> lock(mutex_);
443 firstFrameAppPids_.push(appPid);
444 }
445
SetImplicitAnimationEnd(bool isImplicitAnimationEnd)446 void RSJankStats::SetImplicitAnimationEnd(bool isImplicitAnimationEnd)
447 {
448 std::lock_guard<std::mutex> lock(mutex_);
449 if (!isImplicitAnimationEnd) {
450 return;
451 }
452 RS_TRACE_NAME("RSJankStats::SetImplicitAnimationEnd");
453 for (auto &[animationId, jankFrames] : animateJankFrames_) {
454 if (jankFrames.isDisplayAnimator_) {
455 continue;
456 }
457 SetAnimationTraceEnd(jankFrames);
458 jankFrames.isUpdateJankFrame_ = false;
459 jankFrames.isAnimationEnded_ = true;
460 }
461 }
462
ReportEventResponse(const JankFrames & jankFrames) const463 void RSJankStats::ReportEventResponse(const JankFrames& jankFrames) const
464 {
465 const auto &info = jankFrames.info_;
466 int64_t inputTime = ConvertTimeToSystime(info.inputTime);
467 int64_t beginVsyncTime = ConvertTimeToSystime(info.beginVsyncTime);
468 int64_t responseLatency = rtEndTime_ - inputTime;
469 uint64_t rtEndTime = static_cast<uint64_t>(rtEndTime_);
470 RS_TRACE_NAME_FMT("RSJankStats::ReportEventResponse responseLatency is %" PRId64 "ms: %s",
471 responseLatency, GetSceneDescription(info).c_str());
472 RSBackgroundThread::Instance().PostTask([info, inputTime, beginVsyncTime, responseLatency, rtEndTime]() {
473 auto reportName = "INTERACTION_RESPONSE_LATENCY";
474 RS_TRACE_NAME("RSJankStats::ReportEventResponse in RSBackgroundThread");
475 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
476 OHOS::HiviewDFX::HiSysEvent::EventType::BEHAVIOR, "SCENE_ID", info.sceneId, "APP_PID", info.appPid,
477 "VERSION_CODE", info.versionCode, "VERSION_NAME", info.versionName, "BUNDLE_NAME", info.bundleName,
478 "ABILITY_NAME", info.abilityName, "PROCESS_NAME", info.processName, "PAGE_URL", info.pageUrl,
479 "SOURCE_TYPE", info.sourceType, "NOTE", info.note, "INPUT_TIME", static_cast<uint64_t>(inputTime),
480 "ANIMATION_START_TIME", static_cast<uint64_t>(beginVsyncTime), "RENDER_TIME", rtEndTime,
481 "RESPONSE_LATENCY", static_cast<uint64_t>(responseLatency));
482 });
483 }
484
ReportEventComplete(const JankFrames & jankFrames) const485 void RSJankStats::ReportEventComplete(const JankFrames& jankFrames) const
486 {
487 const auto &info = jankFrames.info_;
488 int64_t inputTime = ConvertTimeToSystime(info.inputTime);
489 int64_t beginVsyncTime = ConvertTimeToSystime(info.beginVsyncTime);
490 int64_t endVsyncTime = ConvertTimeToSystime(info.endVsyncTime);
491 int64_t animationStartLatency = beginVsyncTime - inputTime;
492 int64_t animationEndLatency = endVsyncTime - beginVsyncTime;
493 int64_t completedLatency = GetCurrentSystimeMs() - inputTime;
494 RS_TRACE_NAME_FMT("RSJankStats::ReportEventComplete e2eLatency is %" PRId64 "ms: %s",
495 completedLatency, GetSceneDescription(info).c_str());
496 RSBackgroundThread::Instance().PostTask([
497 info, inputTime, animationStartLatency, animationEndLatency, completedLatency]() {
498 auto reportName = "INTERACTION_COMPLETED_LATENCY";
499 RS_TRACE_NAME("RSJankStats::ReportEventComplete in RSBackgroundThread");
500 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
501 OHOS::HiviewDFX::HiSysEvent::EventType::BEHAVIOR, "APP_PID", info.appPid, "VERSION_CODE", info.versionCode,
502 "VERSION_NAME", info.versionName, "BUNDLE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
503 "PROCESS_NAME", info.processName, "PAGE_URL", info.pageUrl, "SCENE_ID", info.sceneId,
504 "SOURCE_TYPE", info.sourceType, "NOTE", info.note, "INPUT_TIME", static_cast<uint64_t>(inputTime),
505 "ANIMATION_START_LATENCY", static_cast<uint64_t>(animationStartLatency), "ANIMATION_END_LATENCY",
506 static_cast<uint64_t>(animationEndLatency), "E2E_LATENCY", static_cast<uint64_t>(completedLatency));
507 });
508 }
509
ReportEventJankFrame(const JankFrames & jankFrames,bool isReportTaskDelayed) const510 void RSJankStats::ReportEventJankFrame(const JankFrames& jankFrames, bool isReportTaskDelayed) const
511 {
512 if (!isReportTaskDelayed) {
513 ReportEventJankFrameWithoutDelay(jankFrames);
514 } else {
515 ReportEventJankFrameWithDelay(jankFrames);
516 }
517 }
518
ReportEventJankFrameWithoutDelay(const JankFrames & jankFrames) const519 void RSJankStats::ReportEventJankFrameWithoutDelay(const JankFrames& jankFrames) const
520 {
521 if (jankFrames.totalFrames_ <= 0) {
522 ROSEN_LOGD("RSJankStats::ReportEventJankFrame totalFrames is zero, nothing need to report");
523 return;
524 }
525 const auto &info = jankFrames.info_;
526 float aveFrameTimeSteady = jankFrames.totalFrameTimeSteady_ / static_cast<float>(jankFrames.totalFrames_);
527 bool isReportTaskDelayed = false;
528 int64_t maxFrameTimeFromStart = 0;
529 int64_t maxHitchTimeFromStart = 0;
530 int64_t duration = 0;
531 GetMaxJankInfo(jankFrames, isReportTaskDelayed, maxFrameTimeFromStart, maxHitchTimeFromStart, duration);
532 RS_TRACE_NAME_FMT(
533 "RSJankStats::ReportEventJankFrame maxFrameTime is %" PRId64 "ms, maxHitchTime is %" PRId64 "ms: %s",
534 jankFrames.maxFrameTimeSteady_, static_cast<int64_t>(jankFrames.maxHitchTime_),
535 GetSceneDescription(info).c_str());
536 RSBackgroundThread::Instance().PostTask([
537 jankFrames, info, aveFrameTimeSteady, maxFrameTimeFromStart, maxHitchTimeFromStart, duration]() {
538 auto reportName = "INTERACTION_RENDER_JANK";
539 RS_TRACE_NAME("RSJankStats::ReportEventJankFrame in RSBackgroundThread");
540 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
541 OHOS::HiviewDFX::HiSysEvent::EventType::STATISTIC, "UNIQUE_ID", info.uniqueId, "SCENE_ID", info.sceneId,
542 "PROCESS_NAME", info.processName, "MODULE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
543 "PAGE_URL", info.pageUrl, "TOTAL_FRAMES", jankFrames.totalFrames_, "TOTAL_MISSED_FRAMES",
544 jankFrames.totalMissedFrames_, "MAX_FRAMETIME", static_cast<uint64_t>(jankFrames.maxFrameTimeSteady_),
545 "MAX_FRAMETIME_SINCE_START", static_cast<uint64_t>(maxFrameTimeFromStart), "AVERAGE_FRAMETIME",
546 aveFrameTimeSteady, "MAX_SEQ_MISSED_FRAMES", jankFrames.maxSeqMissedFrames_, "IS_FOLD_DISP", IS_FOLD_DISP,
547 "BUNDLE_NAME_EX", info.note, "MAX_HITCH_TIME", static_cast<uint64_t>(jankFrames.maxHitchTime_),
548 "MAX_HITCH_TIME_SINCE_START", static_cast<uint64_t>(maxHitchTimeFromStart),
549 "DURATION", static_cast<uint64_t>(duration));
550 });
551 }
552
ReportEventJankFrameWithDelay(const JankFrames & jankFrames) const553 void RSJankStats::ReportEventJankFrameWithDelay(const JankFrames& jankFrames) const
554 {
555 if (jankFrames.lastTotalFrames_ <= 0) {
556 ROSEN_LOGD("RSJankStats::ReportEventJankFrame totalFrames is zero, nothing need to report");
557 return;
558 }
559 const auto &info = jankFrames.info_;
560 float aveFrameTimeSteady =
561 jankFrames.lastTotalFrameTimeSteady_ / static_cast<float>(jankFrames.lastTotalFrames_);
562 bool isReportTaskDelayed = true;
563 int64_t maxFrameTimeFromStart = 0;
564 int64_t maxHitchTimeFromStart = 0;
565 int64_t duration = 0;
566 GetMaxJankInfo(jankFrames, isReportTaskDelayed, maxFrameTimeFromStart, maxHitchTimeFromStart, duration);
567 RS_TRACE_NAME_FMT(
568 "RSJankStats::ReportEventJankFrame maxFrameTime is %" PRId64 "ms, maxHitchTime is %" PRId64 "ms: %s",
569 jankFrames.lastMaxFrameTimeSteady_, static_cast<int64_t>(jankFrames.lastMaxHitchTime_),
570 GetSceneDescription(info).c_str());
571 RSBackgroundThread::Instance().PostTask([
572 jankFrames, info, aveFrameTimeSteady, maxFrameTimeFromStart, maxHitchTimeFromStart, duration]() {
573 auto reportName = "INTERACTION_RENDER_JANK";
574 RS_TRACE_NAME("RSJankStats::ReportEventJankFrame in RSBackgroundThread");
575 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
576 OHOS::HiviewDFX::HiSysEvent::EventType::STATISTIC, "UNIQUE_ID", info.uniqueId, "SCENE_ID", info.sceneId,
577 "PROCESS_NAME", info.processName, "MODULE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
578 "PAGE_URL", info.pageUrl, "TOTAL_FRAMES", jankFrames.lastTotalFrames_, "TOTAL_MISSED_FRAMES",
579 jankFrames.lastTotalMissedFrames_, "MAX_FRAMETIME", static_cast<uint64_t>(
580 jankFrames.lastMaxFrameTimeSteady_), "MAX_FRAMETIME_SINCE_START", static_cast<uint64_t>(
581 maxFrameTimeFromStart), "AVERAGE_FRAMETIME", aveFrameTimeSteady, "MAX_SEQ_MISSED_FRAMES",
582 jankFrames.lastMaxSeqMissedFrames_, "IS_FOLD_DISP", IS_FOLD_DISP, "BUNDLE_NAME_EX", info.note,
583 "MAX_HITCH_TIME", static_cast<uint64_t>(jankFrames.lastMaxHitchTime_), "MAX_HITCH_TIME_SINCE_START",
584 static_cast<uint64_t>(maxHitchTimeFromStart), "DURATION", static_cast<uint64_t>(duration));
585 });
586 }
587
GetMaxJankInfo(const JankFrames & jankFrames,bool isReportTaskDelayed,int64_t & maxFrameTimeFromStart,int64_t & maxHitchTimeFromStart,int64_t & duration) const588 void RSJankStats::GetMaxJankInfo(const JankFrames& jankFrames, bool isReportTaskDelayed,
589 int64_t& maxFrameTimeFromStart, int64_t& maxHitchTimeFromStart, int64_t& duration) const
590 {
591 maxFrameTimeFromStart = 0;
592 maxHitchTimeFromStart = 0;
593 duration = 0;
594 const int64_t startTimeSteady = ((jankFrames.traceCreateTimeSteady_ == TIMESTAMP_INITIAL) ?
595 jankFrames.startTimeSteady_ : jankFrames.traceCreateTimeSteady_);
596 const int64_t endTimeSteady = ((jankFrames.traceTerminateTimeSteady_ == TIMESTAMP_INITIAL) ?
597 jankFrames.endTimeSteady_ : jankFrames.traceTerminateTimeSteady_);
598 if (startTimeSteady == TIMESTAMP_INITIAL || endTimeSteady == TIMESTAMP_INITIAL) {
599 return;
600 }
601 duration = std::max<int64_t>(0, endTimeSteady - startTimeSteady);
602 if (!isReportTaskDelayed) {
603 if (jankFrames.maxFrameOccurenceTimeSteady_ != TIMESTAMP_INITIAL) {
604 maxFrameTimeFromStart = std::max<int64_t>(0, jankFrames.maxFrameOccurenceTimeSteady_ - startTimeSteady);
605 }
606 if (jankFrames.maxHitchOccurenceTimeSteady_ != TIMESTAMP_INITIAL) {
607 maxHitchTimeFromStart = std::max<int64_t>(0, jankFrames.maxHitchOccurenceTimeSteady_ - startTimeSteady);
608 }
609 } else {
610 if (jankFrames.lastMaxFrameOccurenceTimeSteady_ != TIMESTAMP_INITIAL) {
611 maxFrameTimeFromStart = std::max<int64_t>(0, jankFrames.lastMaxFrameOccurenceTimeSteady_ - startTimeSteady);
612 }
613 if (jankFrames.lastMaxHitchOccurenceTimeSteady_ != TIMESTAMP_INITIAL) {
614 maxHitchTimeFromStart = std::max<int64_t>(0, jankFrames.lastMaxHitchOccurenceTimeSteady_ - startTimeSteady);
615 }
616 }
617 maxFrameTimeFromStart = std::min<int64_t>(maxFrameTimeFromStart, duration);
618 maxHitchTimeFromStart = std::min<int64_t>(maxHitchTimeFromStart, duration);
619 }
620
ReportEventHitchTimeRatio(const JankFrames & jankFrames,bool isReportTaskDelayed) const621 void RSJankStats::ReportEventHitchTimeRatio(const JankFrames& jankFrames, bool isReportTaskDelayed) const
622 {
623 if (!isReportTaskDelayed) {
624 ReportEventHitchTimeRatioWithoutDelay(jankFrames);
625 } else {
626 ReportEventHitchTimeRatioWithDelay(jankFrames);
627 }
628 }
629
ReportEventHitchTimeRatioWithoutDelay(const JankFrames & jankFrames) const630 void RSJankStats::ReportEventHitchTimeRatioWithoutDelay(const JankFrames& jankFrames) const
631 {
632 if (jankFrames.totalFrameTimeSteadyForHTR_ <= 0) {
633 ROSEN_LOGD("RSJankStats::ReportEventHitchTimeRatio duration is zero, nothing need to report");
634 return;
635 }
636 const auto &info = jankFrames.info_;
637 int64_t beginVsyncTime = ConvertTimeToSystime(info.beginVsyncTime);
638 float hitchTimeRatio = jankFrames.totalHitchTimeSteady_ / (jankFrames.totalFrameTimeSteadyForHTR_ / S_TO_MS);
639 RS_TRACE_NAME_FMT("RSJankStats::ReportEventHitchTimeRatio hitch time ratio is %g ms/s: %s",
640 hitchTimeRatio, GetSceneDescription(info).c_str());
641 RSBackgroundThread::Instance().PostTask([jankFrames, info, beginVsyncTime, hitchTimeRatio]() {
642 auto reportName = "INTERACTION_HITCH_TIME_RATIO";
643 RS_TRACE_NAME("RSJankStats::ReportEventHitchTimeRatio in RSBackgroundThread");
644 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
645 OHOS::HiviewDFX::HiSysEvent::EventType::STATISTIC, "UNIQUE_ID", info.uniqueId, "SCENE_ID", info.sceneId,
646 "PROCESS_NAME", info.processName, "MODULE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
647 "PAGE_URL", info.pageUrl, "UI_START_TIME", static_cast<uint64_t>(beginVsyncTime),
648 "RS_START_TIME", static_cast<uint64_t>(jankFrames.startTime_), "DURATION",
649 static_cast<uint64_t>(jankFrames.totalFrameTimeSteadyForHTR_), "HITCH_TIME",
650 static_cast<uint64_t>(jankFrames.totalHitchTimeSteady_), "HITCH_TIME_RATIO", hitchTimeRatio,
651 "IS_FOLD_DISP", IS_FOLD_DISP, "BUNDLE_NAME_EX", info.note);
652 });
653 }
654
ReportEventHitchTimeRatioWithDelay(const JankFrames & jankFrames) const655 void RSJankStats::ReportEventHitchTimeRatioWithDelay(const JankFrames& jankFrames) const
656 {
657 if (jankFrames.lastTotalFrameTimeSteadyForHTR_ <= 0) {
658 ROSEN_LOGD("RSJankStats::ReportEventHitchTimeRatio duration is zero, nothing need to report");
659 return;
660 }
661 const auto &info = jankFrames.info_;
662 int64_t beginVsyncTime = ConvertTimeToSystime(info.beginVsyncTime);
663 float hitchTimeRatio =
664 jankFrames.lastTotalHitchTimeSteady_ / (jankFrames.lastTotalFrameTimeSteadyForHTR_ / S_TO_MS);
665 RS_TRACE_NAME_FMT("RSJankStats::ReportEventHitchTimeRatio hitch time ratio is %g ms/s: %s",
666 hitchTimeRatio, GetSceneDescription(info).c_str());
667 RSBackgroundThread::Instance().PostTask([jankFrames, info, beginVsyncTime, hitchTimeRatio]() {
668 auto reportName = "INTERACTION_HITCH_TIME_RATIO";
669 RS_TRACE_NAME("RSJankStats::ReportEventHitchTimeRatio in RSBackgroundThread");
670 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
671 OHOS::HiviewDFX::HiSysEvent::EventType::STATISTIC, "UNIQUE_ID", info.uniqueId, "SCENE_ID", info.sceneId,
672 "PROCESS_NAME", info.processName, "MODULE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
673 "PAGE_URL", info.pageUrl, "UI_START_TIME", static_cast<uint64_t>(beginVsyncTime),
674 "RS_START_TIME", static_cast<uint64_t>(jankFrames.startTime_), "DURATION",
675 static_cast<uint64_t>(jankFrames.lastTotalFrameTimeSteadyForHTR_), "HITCH_TIME",
676 static_cast<uint64_t>(jankFrames.lastTotalHitchTimeSteady_), "HITCH_TIME_RATIO", hitchTimeRatio,
677 "IS_FOLD_DISP", IS_FOLD_DISP, "BUNDLE_NAME_EX", info.note);
678 });
679 }
680
ReportEventFirstFrame()681 void RSJankStats::ReportEventFirstFrame()
682 {
683 while (!firstFrameAppPids_.empty()) {
684 pid_t appPid = firstFrameAppPids_.front();
685 ReportEventFirstFrameByPid(appPid);
686 firstFrameAppPids_.pop();
687 }
688 }
689
ReportEventFirstFrameByPid(pid_t appPid) const690 void RSJankStats::ReportEventFirstFrameByPid(pid_t appPid) const
691 {
692 RS_TRACE_NAME_FMT("RSJankStats::ReportEventFirstFrame app pid %d", appPid);
693 RSBackgroundThread::Instance().PostTask([appPid]() {
694 auto reportName = "FIRST_FRAME_DRAWN";
695 RS_TRACE_NAME("RSJankStats::ReportEventFirstFrame in RSBackgroundThread");
696 HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::GRAPHIC, reportName,
697 OHOS::HiviewDFX::HiSysEvent::EventType::BEHAVIOR, "APP_PID", static_cast<int32_t>(appPid));
698 });
699 }
700
RecordJankFrame(uint32_t dynamicRefreshRate)701 void RSJankStats::RecordJankFrame(uint32_t dynamicRefreshRate)
702 {
703 RS_TRACE_INT(ACCUMULATED_BUFFER_COUNT_TRACE_NAME, accumulatedBufferCount_);
704 if (dynamicRefreshRate == 0) {
705 dynamicRefreshRate = STANDARD_REFRESH_RATE;
706 }
707 const float accumulatedTime = accumulatedBufferCount_ * S_TO_MS / dynamicRefreshRate;
708 for (auto& recordStats : jankExplicitAnimatorFrameRecorder_) {
709 recordStats.isRecorded_ = false;
710 }
711 const int64_t missedFramesByDuration = static_cast<int64_t>(
712 std::max<float>(0.f, GetEffectiveFrameTime(true) - accumulatedTime) / VSYNC_PERIOD);
713 if (missedFramesByDuration > 0 && explicitAnimationTotal_ > 0) {
714 for (auto& recordStats : jankExplicitAnimatorFrameRecorder_) {
715 RecordJankFrameSingle(missedFramesByDuration, recordStats);
716 }
717 }
718 for (auto& recordStats : jankImplicitAnimatorFrameRecorder_) {
719 recordStats.isRecorded_ = false;
720 }
721 const int64_t missedFramesByInterval = static_cast<int64_t>(
722 std::max<float>(0.f, GetEffectiveFrameTime(isFirstSetEnd_) - accumulatedTime) / VSYNC_PERIOD);
723 if (missedFramesByInterval > 0 && implicitAnimationTotal_ > 0) {
724 for (auto& recordStats : jankImplicitAnimatorFrameRecorder_) {
725 RecordJankFrameSingle(missedFramesByInterval, recordStats);
726 }
727 }
728 RS_TRACE_INT(ACCUMULATED_BUFFER_COUNT_TRACE_NAME, 0);
729 }
730
RecordJankFrameSingle(int64_t missedFrames,JankFrameRecordStats & recordStats)731 void RSJankStats::RecordJankFrameSingle(int64_t missedFrames, JankFrameRecordStats& recordStats)
732 {
733 if (recordStats.isRecorded_) {
734 return;
735 }
736 if (missedFrames >= recordStats.recordThreshold_) {
737 RS_TRACE_INT(recordStats.countTraceName_, missedFrames);
738 recordStats.isRecorded_ = true;
739 RS_TRACE_INT(recordStats.countTraceName_, 0);
740 }
741 }
742
RecordAnimationDynamicFrameRate(JankFrames & jankFrames,bool isReportTaskDelayed)743 void RSJankStats::RecordAnimationDynamicFrameRate(JankFrames& jankFrames, bool isReportTaskDelayed)
744 {
745 if (jankFrames.isFrameRateRecorded_) {
746 return;
747 }
748 const int32_t traceId = jankFrames.traceId_;
749 if (traceId == TRACE_ID_INITIAL) {
750 ROSEN_LOGE("RSJankStats::RecordAnimationDynamicFrameRate traceId not initialized");
751 return;
752 }
753 if (!isReportTaskDelayed) {
754 if (animationAsyncTraces_.find(traceId) == animationAsyncTraces_.end() || jankFrames.totalFrames_ <= 0 ||
755 jankFrames.totalFrameTimeSteadyForHTR_ <= 0) {
756 return;
757 }
758 float animationDuration = static_cast<float>(jankFrames.totalFrameTimeSteadyForHTR_) / S_TO_MS;
759 float animationTotalFrames = static_cast<float>(jankFrames.totalFrames_);
760 float animationDynamicFrameRate = animationTotalFrames / animationDuration;
761 RS_TRACE_NAME_FMT("RSJankStats::RecordAnimationDynamicFrameRate frame rate is %.2f: %s",
762 animationDynamicFrameRate, animationAsyncTraces_.at(traceId).traceName_.c_str());
763 } else {
764 if (animationAsyncTraces_.find(traceId) == animationAsyncTraces_.end() || jankFrames.lastTotalFrames_ <= 0 ||
765 jankFrames.lastTotalFrameTimeSteadyForHTR_ <= 0) {
766 return;
767 }
768 float animationDuration = static_cast<float>(jankFrames.lastTotalFrameTimeSteadyForHTR_) / S_TO_MS;
769 float animationTotalFrames = static_cast<float>(jankFrames.lastTotalFrames_);
770 float animationDynamicFrameRate = animationTotalFrames / animationDuration;
771 RS_TRACE_NAME_FMT("RSJankStats::RecordAnimationDynamicFrameRate frame rate is %.2f: %s",
772 animationDynamicFrameRate, animationAsyncTraces_.at(traceId).traceName_.c_str());
773 }
774 jankFrames.isFrameRateRecorded_ = true;
775 }
776
SetAnimationTraceBegin(std::pair<int64_t,std::string> animationId,JankFrames & jankFrames)777 void RSJankStats::SetAnimationTraceBegin(std::pair<int64_t, std::string> animationId, JankFrames& jankFrames)
778 {
779 const int32_t traceId = jankFrames.traceId_;
780 if (traceId == TRACE_ID_INITIAL) {
781 ROSEN_LOGE("RSJankStats::SetAnimationTraceBegin traceId not initialized");
782 return;
783 }
784 if (animationAsyncTraces_.find(traceId) != animationAsyncTraces_.end()) {
785 return;
786 }
787 jankFrames.traceCreateTimeSteady_ = rtEndTimeSteady_;
788 const auto &info = jankFrames.info_;
789 const std::string traceName = GetSceneDescription(info);
790 AnimationTraceStats traceStat = {.animationId_ = animationId,
791 .traceName_ = traceName,
792 .traceCreateTimeSteady_ = rtEndTimeSteady_,
793 .isDisplayAnimator_ = info.isDisplayAnimator};
794 animationAsyncTraces_.emplace(traceId, traceStat);
795 if (info.isDisplayAnimator) {
796 explicitAnimationTotal_++;
797 } else {
798 implicitAnimationTotal_++;
799 }
800 RS_ASYNC_TRACE_BEGIN(traceName, traceId);
801 }
802
SetAnimationTraceEnd(JankFrames & jankFrames)803 void RSJankStats::SetAnimationTraceEnd(JankFrames& jankFrames)
804 {
805 const int32_t traceId = jankFrames.traceId_;
806 if (traceId == TRACE_ID_INITIAL) {
807 ROSEN_LOGE("RSJankStats::SetAnimationTraceEnd traceId not initialized");
808 return;
809 }
810 if (animationAsyncTraces_.find(traceId) == animationAsyncTraces_.end()) {
811 return;
812 }
813 jankFrames.traceTerminateTimeSteady_ = rtEndTimeSteady_;
814 const bool isDisplayAnimator = animationAsyncTraces_.at(traceId).isDisplayAnimator_;
815 RS_ASYNC_TRACE_END(animationAsyncTraces_.at(traceId).traceName_, traceId);
816 animationAsyncTraces_.erase(traceId);
817 if (isDisplayAnimator) {
818 explicitAnimationTotal_--;
819 } else {
820 implicitAnimationTotal_--;
821 }
822 }
823
CheckAnimationTraceTimeout()824 void RSJankStats::CheckAnimationTraceTimeout()
825 {
826 if (++animationTraceCheckCnt_ < ANIMATION_TRACE_CHECK_FREQ) {
827 return;
828 }
829 EraseIf(animationAsyncTraces_, [this](const auto& pair) -> bool {
830 bool needErase = rtEndTimeSteady_ - pair.second.traceCreateTimeSteady_ > ANIMATION_TIMEOUT;
831 if (needErase) {
832 RS_ASYNC_TRACE_END(pair.second.traceName_, pair.first);
833 if (pair.second.isDisplayAnimator_) {
834 explicitAnimationTotal_--;
835 } else {
836 implicitAnimationTotal_--;
837 }
838 animateJankFrames_.erase(pair.second.animationId_);
839 }
840 return needErase;
841 });
842 animationTraceCheckCnt_ = 0;
843 }
844
ClearAllAnimation()845 void RSJankStats::ClearAllAnimation()
846 {
847 RS_TRACE_NAME("RSJankStats::ClearAllAnimation");
848 EraseIf(animationAsyncTraces_, [](const auto& pair) -> bool {
849 RS_ASYNC_TRACE_END(pair.second.traceName_, pair.first);
850 return true;
851 });
852 explicitAnimationTotal_ = 0;
853 implicitAnimationTotal_ = 0;
854 animateJankFrames_.clear();
855 }
856
GetSceneDescription(const DataBaseRs & info) const857 std::string RSJankStats::GetSceneDescription(const DataBaseRs& info) const
858 {
859 std::stringstream sceneDescription;
860 int64_t inputTime = ConvertTimeToSystime(info.inputTime);
861 std::string animatorType = (info.isDisplayAnimator ? "EXPLICIT_ANIMATOR" : "IMPLICIT_ANIMATOR");
862 sceneDescription << info.sceneId << ", " << info.bundleName << ", " << info.pageUrl
863 << ", " << inputTime << ", " << animatorType << ", uid" << info.uniqueId;
864 return sceneDescription.str();
865 }
866
GetAnimationId(const DataBaseRs & info) const867 std::pair<int64_t, std::string> RSJankStats::GetAnimationId(const DataBaseRs& info) const
868 {
869 std::pair<int64_t, std::string> animationId(info.uniqueId, info.sceneId);
870 return animationId;
871 }
872
GetTraceIdInit(const DataBaseRs & info,int64_t setTimeSteady)873 int32_t RSJankStats::GetTraceIdInit(const DataBaseRs& info, int64_t setTimeSteady)
874 {
875 if (traceIdRemainder_.find(info.uniqueId) == traceIdRemainder_.end()) {
876 TraceIdRemainderStats traceIdStat;
877 traceIdRemainder_.emplace(info.uniqueId, traceIdStat);
878 }
879 if (traceIdRemainder_.at(info.uniqueId).remainder_ >= TRACE_ID_SCALE_PARAM) {
880 traceIdRemainder_[info.uniqueId].remainder_ = 0;
881 }
882 traceIdRemainder_[info.uniqueId].setTimeSteady_ = setTimeSteady;
883 int64_t mappedUniqueId = info.uniqueId * TRACE_ID_SCALE_PARAM + (traceIdRemainder_[info.uniqueId].remainder_++);
884 int32_t traceId = static_cast<int32_t>(mappedUniqueId);
885 return traceId;
886 }
887
GetEffectiveFrameTime(bool isConsiderRsStartTime) const888 int64_t RSJankStats::GetEffectiveFrameTime(bool isConsiderRsStartTime) const
889 {
890 if (isConsiderRsStartTime) {
891 return std::min<int64_t>(rtEndTimeSteady_ - rtLastEndTimeSteady_, rtEndTimeSteady_ - rsStartTimeSteady_);
892 }
893 if (isCurrentFrameSwitchToNotDoDirectComposition_) {
894 return rtEndTimeSteady_ - rsStartTimeSteady_;
895 }
896 return rtEndTimeSteady_ - rtLastEndTimeSteady_;
897 }
898
GetEffectiveFrameTimeFloat(bool isConsiderRsStartTime) const899 float RSJankStats::GetEffectiveFrameTimeFloat(bool isConsiderRsStartTime) const
900 {
901 if (isConsiderRsStartTime) {
902 return std::min<float>(rtEndTimeSteadyFloat_ - rtLastEndTimeSteadyFloat_,
903 rtEndTimeSteadyFloat_ - rsStartTimeSteadyFloat_);
904 }
905 if (isCurrentFrameSwitchToNotDoDirectComposition_) {
906 return rtEndTimeSteadyFloat_ - rsStartTimeSteadyFloat_;
907 }
908 return rtEndTimeSteadyFloat_ - rtLastEndTimeSteadyFloat_;
909 }
910
ConvertTimeToSystime(int64_t time) const911 int64_t RSJankStats::ConvertTimeToSystime(int64_t time) const
912 {
913 if (time <= 0) {
914 ROSEN_LOGW("RSJankStats::ConvertTimeToSystime, time is error");
915 return 0;
916 }
917 struct timespec ts = { 0, 0 };
918 if (clock_gettime(CLOCK_MONOTONIC, &ts) != 0) {
919 return 0;
920 }
921 int64_t nowTime = static_cast<int64_t>(ts.tv_sec) * S_TO_NS + static_cast<int64_t>(ts.tv_nsec);
922 int64_t curSysTime = GetCurrentSystimeMs();
923 int64_t sysTime = curSysTime - (nowTime - time) / MS_TO_NS;
924 return sysTime;
925 }
926
GetCurrentSystimeMs() const927 int64_t RSJankStats::GetCurrentSystimeMs() const
928 {
929 auto curTime = std::chrono::system_clock::now().time_since_epoch();
930 int64_t curSysTime = std::chrono::duration_cast<std::chrono::milliseconds>(curTime).count();
931 return curSysTime;
932 }
933
GetCurrentSteadyTimeMs() const934 int64_t RSJankStats::GetCurrentSteadyTimeMs() const
935 {
936 auto curTime = std::chrono::steady_clock::now().time_since_epoch();
937 int64_t curSteadyTime = std::chrono::duration_cast<std::chrono::milliseconds>(curTime).count();
938 return curSteadyTime;
939 }
940
GetCurrentSteadyTimeMsFloat() const941 float RSJankStats::GetCurrentSteadyTimeMsFloat() const
942 {
943 auto curTime = std::chrono::steady_clock::now().time_since_epoch();
944 int64_t curSteadyTimeUs = std::chrono::duration_cast<std::chrono::microseconds>(curTime).count();
945 float curSteadyTime = curSteadyTimeUs / MS_TO_US;
946 return curSteadyTime;
947 }
948 } // namespace Rosen
949 } // namespace OHOS
950