1 /*
2 * Copyright (c) 2023-2025 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 #include "cJSON.h"
24
25 #include "hisysevent.h"
26 #include "rs_trace.h"
27
28 #include "common/rs_background_thread.h"
29 #include "common/rs_common_def.h"
30 #include "platform/common/rs_log.h"
31 #include "platform/common/rs_hisysevent.h"
32
33 namespace OHOS {
34 namespace Rosen {
35 namespace {
36 constexpr float HITCH_TIME_EPSILON = 0.0001f; // 0.0001ms
37 constexpr float VSYNC_PERIOD = 16.6f; // 16.6ms
38 constexpr float S_TO_MS = 1000.f; // s to ms
39 constexpr int64_t ANIMATION_TIMEOUT = 10000; // 10s
40 constexpr int64_t S_TO_NS = 1000000000; // s to ns
41 constexpr int64_t VSYNC_JANK_LOG_THRESHOLED = 6; // 6 times vsync
42 constexpr int64_t INPUTTIME_TIMEOUT = 100000000; // ns, 100ms
43 constexpr uint64_t DELAY_TIME_MS = 1000;
44 constexpr uint32_t ACVIDEO_QUIT_FRAME_COUNT = 10;
45 }
46
GetInstance()47 RSJankStats& RSJankStats::GetInstance()
48 {
49 static RSJankStats instance;
50 return instance;
51 }
52
SetOnVsyncStartTime(int64_t onVsyncStartTime,int64_t onVsyncStartTimeSteady,float onVsyncStartTimeSteadyFloat)53 void RSJankStats::SetOnVsyncStartTime(int64_t onVsyncStartTime, int64_t onVsyncStartTimeSteady,
54 float onVsyncStartTimeSteadyFloat)
55 {
56 std::lock_guard<std::mutex> lock(mutex_);
57 rsStartTime_ = onVsyncStartTime;
58 rsStartTimeSteady_ = onVsyncStartTimeSteady;
59 if (IS_CALCULATE_PRECISE_HITCH_TIME) {
60 rsStartTimeSteadyFloat_ = onVsyncStartTimeSteadyFloat;
61 }
62 }
63
SetAccumulatedBufferCount(int accumulatedBufferCount)64 void RSJankStats::SetAccumulatedBufferCount(int accumulatedBufferCount)
65 {
66 std::lock_guard<std::mutex> lock(mutex_);
67 accumulatedBufferCount_ = accumulatedBufferCount;
68 }
69
SetStartTime(bool doDirectComposition)70 void RSJankStats::SetStartTime(bool doDirectComposition)
71 {
72 std::lock_guard<std::mutex> lock(mutex_);
73 SetStartTimeInner(doDirectComposition);
74 }
75
SetStartTimeInner(bool doDirectComposition)76 void RSJankStats::SetStartTimeInner(bool doDirectComposition)
77 {
78 if (!doDirectComposition) {
79 rtStartTime_ = GetCurrentSystimeMs();
80 rtStartTimeSteady_ = GetCurrentSteadyTimeMs();
81 }
82 if (isFirstSetStart_) {
83 lastReportTime_ = rtStartTime_;
84 lastReportTimeSteady_ = rtStartTimeSteady_;
85 lastSceneReportTime_ = rtStartTime_;
86 lastSceneReportTimeSteady_ = rtStartTimeSteady_;
87 }
88 for (auto &[animationId, jankFrames] : animateJankFrames_) {
89 jankFrames.isReportEventResponse_ = jankFrames.isSetReportEventResponseTemp_;
90 jankFrames.isSetReportEventResponseTemp_ = jankFrames.isSetReportEventResponse_;
91 jankFrames.isSetReportEventResponse_ = false;
92 jankFrames.isReportEventComplete_ = jankFrames.isSetReportEventComplete_;
93 jankFrames.isSetReportEventComplete_ = false;
94 jankFrames.isReportEventJankFrame_ = jankFrames.isSetReportEventJankFrame_;
95 jankFrames.isSetReportEventJankFrame_ = false;
96 }
97 isFirstSetStart_ = false;
98 }
99
IsAnimationEmpty()100 bool RSJankStats::IsAnimationEmpty()
101 {
102 std::lock_guard<std::mutex> lock(mutex_);
103 return implicitAnimationTotal_ + explicitAnimationTotal_ == 0;
104 }
105
SetEndTime(bool skipJankAnimatorFrame,bool discardJankFrames,uint32_t dynamicRefreshRate,bool doDirectComposition,bool isReportTaskDelayed)106 void RSJankStats::SetEndTime(bool skipJankAnimatorFrame, bool discardJankFrames, uint32_t dynamicRefreshRate,
107 bool doDirectComposition, bool isReportTaskDelayed)
108 {
109 std::lock_guard<std::mutex> lock(mutex_);
110 SetEndTimeInner(skipJankAnimatorFrame, discardJankFrames, dynamicRefreshRate, doDirectComposition,
111 isReportTaskDelayed);
112 }
113
SetEndTimeInner(bool skipJankAnimatorFrame,bool discardJankFrames,uint32_t dynamicRefreshRate,bool doDirectComposition,bool isReportTaskDelayed)114 void RSJankStats::SetEndTimeInner(bool skipJankAnimatorFrame, bool discardJankFrames, uint32_t dynamicRefreshRate,
115 bool doDirectComposition, bool isReportTaskDelayed)
116 {
117 if (rtStartTime_ == TIMESTAMP_INITIAL || rtStartTimeSteady_ == TIMESTAMP_INITIAL ||
118 rsStartTime_ == TIMESTAMP_INITIAL || rsStartTimeSteady_ == TIMESTAMP_INITIAL) {
119 ROSEN_LOGE("RSJankStats::SetEndTime startTime is not initialized");
120 return;
121 }
122 isCurrentFrameSwitchToNotDoDirectComposition_ = isLastFrameDoDirectComposition_ && !doDirectComposition;
123 if (!doDirectComposition) { UpdateEndTime(); }
124 if (discardJankFrames) { ClearAllAnimation(); }
125 SetRSJankStats(skipJankAnimatorFrame || discardJankFrames, dynamicRefreshRate);
126 ReportSceneJankFrame(dynamicRefreshRate);
127 RecordJankFrame(dynamicRefreshRate);
128 #ifdef RS_ENABLE_PREFETCH
129 __builtin_prefetch(&firstFrameAppPids_, 0, 1);
130 #endif
131 for (auto &[animationId, jankFrames] : animateJankFrames_) {
132 if (jankFrames.isReportEventResponse_) {
133 SetAnimationTraceBegin(animationId, jankFrames);
134 ReportEventResponse(jankFrames);
135 }
136 // skip jank frame statistics at the first frame of animation && at the end frame of implicit animation
137 if (jankFrames.isUpdateJankFrame_ && !jankFrames.isFirstFrame_ && !(!jankFrames.isDisplayAnimator_ &&
138 (jankFrames.isReportEventComplete_ || jankFrames.isReportEventJankFrame_))) {
139 UpdateJankFrame(jankFrames, skipJankAnimatorFrame, dynamicRefreshRate);
140 }
141 if (jankFrames.isReportEventJankFrame_) {
142 RecordAnimationDynamicFrameRate(jankFrames, isReportTaskDelayed);
143 }
144 if (jankFrames.isReportEventComplete_ || jankFrames.isReportEventJankFrame_) {
145 SetAnimationTraceEnd(jankFrames);
146 }
147 if (jankFrames.isReportEventComplete_) {
148 ReportEventComplete(jankFrames);
149 }
150 if (jankFrames.isReportEventJankFrame_) {
151 ReportEventJankFrame(jankFrames, isReportTaskDelayed);
152 ReportEventHitchTimeRatio(jankFrames, isReportTaskDelayed);
153 }
154 jankFrames.isFirstFrame_ = jankFrames.isFirstFrameTemp_;
155 jankFrames.isFirstFrameTemp_ = false;
156 }
157 ReportEventFirstFrame();
158 CheckAnimationTraceTimeout();
159 isLastFrameDoDirectComposition_ = doDirectComposition;
160 isFirstSetEnd_ = false;
161 }
162
UpdateEndTime()163 void RSJankStats::UpdateEndTime()
164 {
165 if (isFirstSetEnd_) {
166 rtLastEndTime_ = GetCurrentSystimeMs();
167 rtEndTime_ = rtLastEndTime_;
168 rtLastEndTimeSteady_ = GetCurrentSteadyTimeMs();
169 rtEndTimeSteady_ = rtLastEndTimeSteady_;
170 if (IS_CALCULATE_PRECISE_HITCH_TIME) {
171 rtLastEndTimeSteadyFloat_ = GetCurrentSteadyTimeMsFloat();
172 rtEndTimeSteadyFloat_ = rtLastEndTimeSteadyFloat_;
173 }
174 return;
175 }
176 rtLastEndTime_ = rtEndTime_;
177 rtEndTime_ = GetCurrentSystimeMs();
178 rtLastEndTimeSteady_ = rtEndTimeSteady_;
179 rtEndTimeSteady_ = GetCurrentSteadyTimeMs();
180 if (IS_CALCULATE_PRECISE_HITCH_TIME) {
181 rtLastEndTimeSteadyFloat_ = rtEndTimeSteadyFloat_;
182 rtEndTimeSteadyFloat_ = GetCurrentSteadyTimeMsFloat();
183 }
184 }
185
NeedPostTaskToUniRenderThread() const186 bool RSJankStats::NeedPostTaskToUniRenderThread() const
187 {
188 for (const auto &[_, jankFrames] : animateJankFrames_) {
189 if (jankFrames.isReportEventResponse_ || jankFrames.isReportEventComplete_ ||
190 jankFrames.isReportEventJankFrame_) {
191 // report event will occur in this frame
192 return true;
193 }
194 }
195 return false;
196 }
197
HandleDirectComposition(const JankDurationParams & rsParams,bool isReportTaskDelayed,std::function<void (const std::function<void ()> &)> postTaskHandler)198 void RSJankStats::HandleDirectComposition(const JankDurationParams& rsParams, bool isReportTaskDelayed,
199 std::function<void(const std::function<void()>&)> postTaskHandler)
200 {
201 std::lock_guard<std::mutex> lock(mutex_);
202 rsStartTime_ = rsParams.timeStart_;
203 rsStartTimeSteady_ = rsParams.timeStartSteady_;
204 rtStartTime_ = rsParams.timeEnd_;
205 rtStartTimeSteady_ = rsParams.timeEndSteady_;
206 rtLastEndTime_ = rtEndTime_;
207 rtEndTime_ = rsParams.timeEnd_;
208 rtLastEndTimeSteady_ = rtEndTimeSteady_;
209 rtEndTimeSteady_ = rsParams.timeEndSteady_;
210 if (IS_CALCULATE_PRECISE_HITCH_TIME) {
211 rsStartTimeSteadyFloat_ = rsParams.timeStartSteadyFloat_;
212 rtLastEndTimeSteadyFloat_ = rtEndTimeSteadyFloat_;
213 rtEndTimeSteadyFloat_ = rsParams.timeEndSteadyFloat_;
214 }
215 SetStartTimeInner(true);
216 SetImplicitAnimationEndInner(rsParams.implicitAnimationEnd_);
217 if (postTaskHandler == nullptr || !NeedPostTaskToUniRenderThread()) {
218 SetEndTimeInner(rsParams.skipJankAnimatorFrame_, rsParams.discardJankFrames_, rsParams.refreshRate_, true,
219 isReportTaskDelayed);
220 } else { // post task to unirender thread when report event occurs in direct composition scene
221 auto task = [this, rsParams, isReportTaskDelayed]() {
222 SetEndTime(rsParams.skipJankAnimatorFrame_, rsParams.discardJankFrames_, rsParams.refreshRate_, true,
223 isReportTaskDelayed);
224 };
225 postTaskHandler(task);
226 }
227 }
228
229 // dynamicRefreshRate is retained for future algorithm adjustment, keep it unused currently
SetRSJankStats(bool skipJankStats,uint32_t)230 void RSJankStats::SetRSJankStats(bool skipJankStats, uint32_t /* dynamicRefreshRate */)
231 {
232 if (skipJankStats) {
233 RS_TRACE_NAME("RSJankStats::SetRSJankStats skip jank frame statistics");
234 return;
235 }
236 const int64_t frameTime = GetEffectiveFrameTime(true);
237 const int64_t missedVsync = static_cast<int64_t>(frameTime / VSYNC_PERIOD);
238 if (missedVsync <= 0) {
239 return;
240 }
241 RS_TRACE_NAME_FMT("RSJankStats::SetRSJankStats missedVsync %" PRId64 " frameTime %" PRId64, missedVsync, frameTime);
242 if (missedVsync >= VSYNC_JANK_LOG_THRESHOLED) {
243 ROSEN_LOGW("RSJankStats::SetJankStats jank frames %{public}" PRId64, missedVsync);
244 }
245 const size_t type = GetJankRangeType(missedVsync);
246 if (type == JANK_FRAME_INVALID) {
247 return;
248 }
249 if (rsJankStats_[type] == USHRT_MAX) {
250 ROSEN_LOGD("RSJankStats::SetJankStats rsJankStats_ value oversteps USHRT_MAX");
251 return;
252 }
253 if (type == JANK_FRAME_6_FREQ) {
254 RS_TRACE_INT(JANK_FRAME_1_TO_5F_COUNT_TRACE_NAME, missedVsync);
255 } else {
256 RS_TRACE_INT(JANK_FRAME_6F_COUNT_TRACE_NAME, missedVsync);
257 lastJankFrame6FreqTimeSteady_ = rtEndTimeSteady_;
258 lastSceneJankFrame6FreqTimeSteady_ = rtEndTimeSteady_;
259 }
260 rsJankStats_[type]++;
261 rsSceneJankStats_[type]++;
262 isNeedReportJankStats_ = true;
263 isNeedReportSceneJankStats_ = true;
264 if (type == JANK_FRAME_6_FREQ) {
265 RS_TRACE_INT(JANK_FRAME_1_TO_5F_COUNT_TRACE_NAME, 0);
266 } else {
267 RS_TRACE_INT(JANK_FRAME_6F_COUNT_TRACE_NAME, 0);
268 }
269 }
270
GetJankRangeType(int64_t missedVsync) const271 size_t RSJankStats::GetJankRangeType(int64_t missedVsync) const
272 {
273 size_t type = JANK_FRAME_INVALID;
274 if (missedVsync < 6) { // JANK_FRAME_6_FREQ : (0,6)
275 type = JANK_FRAME_6_FREQ;
276 } else if (missedVsync < 15) { // JANK_FRAME_15_FREQ : [6,15)
277 type = JANK_FRAME_15_FREQ;
278 } else if (missedVsync < 20) { // JANK_FRAME_20_FREQ : [15,20)
279 type = JANK_FRAME_20_FREQ;
280 } else if (missedVsync < 36) { // JANK_FRAME_36_FREQ : [20,36)
281 type = JANK_FRAME_36_FREQ;
282 } else if (missedVsync < 48) { // JANK_FRAME_48_FREQ : [36,48)
283 type = JANK_FRAME_48_FREQ;
284 } else if (missedVsync < 60) { // JANK_FRAME_60_FREQ : [48,60)
285 type = JANK_FRAME_60_FREQ;
286 } else if (missedVsync < 120) { // JANK_FRAME_120_FREQ : [60,120)
287 type = JANK_FRAME_120_FREQ;
288 } else if (missedVsync < 180) { // JANK_FRAME_180_FREQ : [120,180)
289 type = JANK_FRAME_180_FREQ;
290 } else {
291 ROSEN_LOGW("RSJankStats::SetJankStats jank frames over 180");
292 }
293 return type;
294 }
295
UpdateJankFrame(JankFrames & jankFrames,bool skipJankStats,uint32_t dynamicRefreshRate)296 void RSJankStats::UpdateJankFrame(JankFrames& jankFrames, bool skipJankStats, uint32_t dynamicRefreshRate)
297 {
298 if (jankFrames.startTime_ == TIMESTAMP_INITIAL) {
299 jankFrames.startTime_ = rsStartTime_;
300 }
301 if (skipJankStats) {
302 RS_TRACE_NAME("RSJankStats::UpdateJankFrame skip jank animator frame");
303 return;
304 }
305 jankFrames.lastTotalFrames_ = jankFrames.totalFrames_;
306 jankFrames.lastTotalFrameTimeSteady_ = jankFrames.totalFrameTimeSteady_;
307 jankFrames.lastTotalMissedFrames_ = jankFrames.totalMissedFrames_;
308 jankFrames.lastMaxFrameTimeSteady_ = jankFrames.maxFrameTimeSteady_;
309 jankFrames.lastMaxTechFrameTimeSteady_ = jankFrames.maxTechFrameTimeSteady_;
310 jankFrames.lastMaxRealFrameTimeSteady_ = jankFrames.maxRealFrameTimeSteady_;
311 jankFrames.lastMaxSeqMissedFrames_ = jankFrames.maxSeqMissedFrames_;
312 jankFrames.lastMaxFrameOccurenceTimeSteady_ = jankFrames.maxFrameOccurenceTimeSteady_;
313 jankFrames.lastMaxFrameRefreshRate_ = jankFrames.maxFrameRefreshRate_;
314 if (dynamicRefreshRate == 0) {
315 dynamicRefreshRate = STANDARD_REFRESH_RATE;
316 }
317 const float standardFrameTime = S_TO_MS / dynamicRefreshRate;
318 const bool isConsiderRsStartTime =
319 jankFrames.isDisplayAnimator_ || jankFrames.isFirstFrame_ || isFirstSetEnd_;
320 const float accumulatedTime = accumulatedBufferCount_ * standardFrameTime;
321 const int64_t frameDuration = std::max<int64_t>(0, GetEffectiveFrameTime(isConsiderRsStartTime) - accumulatedTime);
322 const int64_t frameTechDuration = GetEffectiveFrameTime(true);
323 const int32_t missedFramesToReport = static_cast<int32_t>(frameDuration / VSYNC_PERIOD);
324 jankFrames.totalFrames_++;
325 jankFrames.totalFrameTimeSteady_ += frameDuration;
326 if (jankFrames.maxFrameRefreshRate_ == 0) {
327 jankFrames.maxFrameRefreshRate_ = dynamicRefreshRate;
328 }
329 if (frameDuration > jankFrames.maxFrameTimeSteady_) {
330 jankFrames.maxFrameOccurenceTimeSteady_ = rtEndTimeSteady_;
331 jankFrames.maxFrameTimeSteady_ = frameDuration;
332 jankFrames.maxFrameRefreshRate_ = dynamicRefreshRate;
333 }
334 if (frameTechDuration > jankFrames.maxTechFrameTimeSteady_) {
335 jankFrames.maxTechFrameTimeSteady_ = frameTechDuration;
336 }
337 if (frameDuration > jankFrames.maxRealFrameTimeSteady_ && !jankFrames.isAnimationInterrupted_) {
338 jankFrames.maxRealFrameTimeSteady_ = frameDuration;
339 }
340 if (missedFramesToReport > 0) {
341 jankFrames.totalMissedFrames_ += missedFramesToReport;
342 jankFrames.seqMissedFrames_ += missedFramesToReport;
343 jankFrames.maxSeqMissedFrames_ = std::max<int32_t>(jankFrames.maxSeqMissedFrames_, jankFrames.seqMissedFrames_);
344 } else {
345 jankFrames.seqMissedFrames_ = 0;
346 }
347 UpdateHitchTime(jankFrames, standardFrameTime);
348 }
349
UpdateHitchTime(JankFrames & jankFrames,float standardFrameTime)350 void RSJankStats::UpdateHitchTime(JankFrames& jankFrames, float standardFrameTime)
351 {
352 jankFrames.lastMaxHitchTime_ = jankFrames.maxHitchTime_;
353 jankFrames.lastTotalHitchTimeSteady_ = jankFrames.totalHitchTimeSteady_;
354 jankFrames.lastTotalFrameTimeSteadyForHTR_ = jankFrames.totalFrameTimeSteadyForHTR_;
355 jankFrames.lastMaxHitchOccurenceTimeSteady_ = jankFrames.maxHitchOccurenceTimeSteady_;
356 const float frameTimeForHTR = (IS_CALCULATE_PRECISE_HITCH_TIME ? GetEffectiveFrameTimeFloat(true) :
357 static_cast<float>(GetEffectiveFrameTime(true)));
358 const float frameHitchTime = std::max<float>(0.f, frameTimeForHTR - standardFrameTime);
359 const bool isConsiderRsStartTimeForHTR = jankFrames.isFirstFrame_ || isFirstSetEnd_;
360 const int64_t frameDurationForHTR = (isConsiderRsStartTimeForHTR ?
361 (rtEndTimeSteady_ - rsStartTimeSteady_) : (rtEndTimeSteady_ - rtLastEndTimeSteady_));
362 if (frameHitchTime - jankFrames.maxHitchTime_ > HITCH_TIME_EPSILON) {
363 jankFrames.maxHitchOccurenceTimeSteady_ = rtEndTimeSteady_;
364 jankFrames.maxHitchTime_ = frameHitchTime;
365 }
366 jankFrames.totalHitchTimeSteady_ += frameHitchTime;
367 jankFrames.totalFrameTimeSteadyForHTR_ += frameDurationForHTR;
368 }
369
ReportJankStats()370 void RSJankStats::ReportJankStats()
371 {
372 std::lock_guard<std::mutex> lock(mutex_);
373 if (lastReportTime_ == TIMESTAMP_INITIAL || lastReportTimeSteady_ == TIMESTAMP_INITIAL) {
374 ROSEN_LOGE("RSJankStats::ReportJankStats lastReportTime is not initialized");
375 return;
376 }
377 int64_t reportTime = GetCurrentSystimeMs();
378 int64_t reportTimeSteady = GetCurrentSteadyTimeMs();
379 if (!isNeedReportJankStats_) {
380 ROSEN_LOGD("RSJankStats::ReportJankStats Nothing need to report");
381 lastReportTime_ = reportTime;
382 lastReportTimeSteady_ = reportTimeSteady;
383 lastJankFrame6FreqTimeSteady_ = TIMESTAMP_INITIAL;
384 std::fill(rsJankStats_.begin(), rsJankStats_.end(), 0);
385 return;
386 }
387 int64_t lastJankFrame6FreqTime = ((lastJankFrame6FreqTimeSteady_ == TIMESTAMP_INITIAL) ? 0 :
388 (reportTime - (reportTimeSteady - lastJankFrame6FreqTimeSteady_)));
389 int64_t reportDuration = reportTimeSteady - lastReportTimeSteady_;
390 int64_t lastReportTime = lastReportTime_;
391 std::vector<uint16_t> rsJankStats = rsJankStats_;
392 RS_TRACE_NAME("RSJankStats::ReportJankStats receive notification: reportTime " + std::to_string(reportTime) +
393 ", lastJankFrame6FreqTime " + std::to_string(lastJankFrame6FreqTime));
394 RSBackgroundThread::Instance().PostTask([reportDuration, lastReportTime, rsJankStats]() {
395 RS_TRACE_NAME("RSJankStats::ReportJankStats in RSBackgroundThread");
396 RSHiSysEvent::EventWrite(RSEventName::JANK_STATS_RS, RSEventType::RS_STATISTIC,
397 "STARTTIME", static_cast<uint64_t>(lastReportTime),
398 "DURATION", static_cast<uint64_t>(reportDuration), "JANK_STATS", rsJankStats, "PID", DEFAULT_INT_VALUE,
399 "BUNDLE_NAME", DEFAULT_STRING_VALUE, "PROCESS_NAME", DEFAULT_STRING_VALUE,
400 "VERSION_NAME", DEFAULT_STRING_VALUE, "VERSION_CODE", DEFAULT_INT_VALUE,
401 "JANK_STATS_VER", JANK_RANGE_VERSION);
402 });
403 lastReportTime_ = reportTime;
404 lastReportTimeSteady_ = reportTimeSteady;
405 lastJankFrame6FreqTimeSteady_ = TIMESTAMP_INITIAL;
406 std::fill(rsJankStats_.begin(), rsJankStats_.end(), 0);
407 isNeedReportJankStats_ = false;
408 }
409
ReportSceneJankStats(const AppInfo & appInfo)410 void RSJankStats::ReportSceneJankStats(const AppInfo& appInfo)
411 {
412 if (lastSceneReportTime_ == TIMESTAMP_INITIAL || lastSceneReportTimeSteady_ == TIMESTAMP_INITIAL) {
413 ROSEN_LOGE("RSJankStats::ReportSceneJankStats lastReportTime is not initialized");
414 return;
415 }
416 int64_t reportTime = GetCurrentSystimeMs();
417 int64_t reportTimeSteady = GetCurrentSteadyTimeMs();
418 if (!isNeedReportSceneJankStats_) {
419 ROSEN_LOGD("RSJankStats::ReportSceneJankStats Nothing need to report");
420 lastSceneReportTime_ = reportTime;
421 lastSceneReportTimeSteady_ = reportTimeSteady;
422 lastSceneJankFrame6FreqTimeSteady_ = TIMESTAMP_INITIAL;
423 std::fill(rsSceneJankStats_.begin(), rsSceneJankStats_.end(), 0);
424 return;
425 }
426 int64_t lastJankFrame6FreqTime = ((lastSceneJankFrame6FreqTimeSteady_ == TIMESTAMP_INITIAL) ? 0
427 : (reportTime - (reportTimeSteady - lastSceneJankFrame6FreqTimeSteady_)));
428 int64_t reportDuration = reportTimeSteady - lastSceneReportTimeSteady_;
429 int64_t lastReportTime = lastSceneReportTime_;
430 std::vector<uint16_t> rsSceneJankStats = rsSceneJankStats_;
431 RS_TRACE_NAME("RSJankStats::ReportSceneJankStats reportTime " + std::to_string(reportTime) +
432 ", lastJankFrame6FreqTime " + std::to_string(lastJankFrame6FreqTime));
433
434 RSBackgroundThread::Instance().PostTask([reportDuration, lastReportTime, rsSceneJankStats, appInfo]() {
435 RS_TRACE_NAME("RSJankStats::ReportSceneJankStats in RSBackgroundThread");
436 RSHiSysEvent::EventWrite(RSEventName::JANK_STATS_RS, RSEventType::RS_STATISTIC,
437 "STARTTIME", static_cast<uint64_t>(lastReportTime),
438 "DURATION", static_cast<uint64_t>(reportDuration), "JANK_STATS", rsSceneJankStats, "PID", appInfo.pid,
439 "BUNDLE_NAME", appInfo.bundleName, "PROCESS_NAME", appInfo.processName,
440 "VERSION_NAME", appInfo.versionName, "VERSION_CODE", appInfo.versionCode,
441 "JANK_STATS_VER", JANK_SCENE_RANGE_VERSION);
442 });
443 appInfo_.startTime = 0;
444 appInfo_.endTime = 0;
445 appInfo_.pid = 0;
446 lastSceneReportTime_ = reportTime;
447 lastSceneReportTimeSteady_ = reportTimeSteady;
448 lastSceneJankFrame6FreqTimeSteady_ = TIMESTAMP_INITIAL;
449 std::fill(rsSceneJankStats_.begin(), rsSceneJankStats_.end(), 0);
450 isNeedReportSceneJankStats_ = false;
451 isLastReportSceneDone_ = true;
452 }
453
ReportSceneJankFrame(uint32_t dynamicRefreshRate)454 void RSJankStats::ReportSceneJankFrame(uint32_t dynamicRefreshRate)
455 {
456 if (lastSceneReportTime_ == TIMESTAMP_INITIAL || lastSceneReportTimeSteady_ == TIMESTAMP_INITIAL) {
457 ROSEN_LOGE("RSJankStats::ReportSceneJankFrame lastSceneReportTime_ is not initialized");
458 return;
459 }
460
461 int64_t skipFrameTime = GetEffectiveFrameTime(true);
462 if (skipFrameTime < SCENE_JANK_FRAME_THRESHOLD) {
463 return;
464 }
465 if (dynamicRefreshRate == 0) {
466 dynamicRefreshRate = STANDARD_REFRESH_RATE;
467 }
468 const float accumulatedTime = accumulatedBufferCount_ * S_TO_MS / dynamicRefreshRate;
469
470 RS_TRACE_NAME("RSJankStats::ReportSceneJankFrame reportTime " + std::to_string(GetCurrentSystimeMs())
471 + ", skipped_frame_time: " + std::to_string(skipFrameTime)
472 + ", frame_refresh_rate: " + std::to_string(dynamicRefreshRate));
473 const int64_t realSkipFrameTime = static_cast<int64_t>(std::max<float>(0.f, skipFrameTime - accumulatedTime));
474 RSBackgroundThread::Instance().PostTask(
475 [appInfo = appInfo_, skipFrameTime, realSkipFrameTime, dynamicRefreshRate]() {
476 RS_TRACE_NAME("RSJankStats::ReportSceneJankFrame in RSBackgroundThread");
477 RSHiSysEvent::EventWrite(RSEventName::JANK_FRAME_RS, RSEventType::RS_FAULT,
478 "PID", appInfo.pid, "BUNDLE_NAME", appInfo.bundleName,
479 "PROCESS_NAME", appInfo.processName, "VERSION_NAME", appInfo.versionName,
480 "VERSION_CODE", appInfo.versionCode, "FILTER_TYPE", FILTER_TYPE,
481 "SKIPPED_FRAME_TIME", skipFrameTime, "REAL_SKIPPED_FRAME_TIME", realSkipFrameTime,
482 "FRAME_REFRESH_RATE", static_cast<int32_t>(dynamicRefreshRate));
483 });
484 }
485
SetReportEventResponse(const DataBaseRs & info)486 void RSJankStats::SetReportEventResponse(const DataBaseRs& info)
487 {
488 std::lock_guard<std::mutex> lock(mutex_);
489 RS_TRACE_NAME("RSJankStats::SetReportEventResponse receive notification: " + GetSceneDescription(info));
490 int64_t setTimeSteady = GetCurrentSteadyTimeMs();
491 EraseIf(animateJankFrames_, [setTimeSteady](const auto& pair) -> bool {
492 return setTimeSteady - pair.second.setTimeSteady_ > ANIMATION_TIMEOUT;
493 });
494 EraseIf(traceIdRemainder_, [setTimeSteady](const auto& pair) -> bool {
495 return setTimeSteady - pair.second.setTimeSteady_ > ANIMATION_TIMEOUT;
496 });
497 const auto animationId = GetAnimationId(info);
498 auto it = animateJankFrames_.find(animationId);
499 if (it != animateJankFrames_.end()) {
500 it->second.info_ = info;
501 it->second.isSetReportEventResponse_ = true;
502 if (it->second.isDisplayAnimator_ != info.isDisplayAnimator) {
503 ROSEN_LOGW("RSJankStats::SetReportEventResponse isDisplayAnimator not consistent");
504 }
505 return;
506 }
507 for (auto &[animationId, jankFrames] : animateJankFrames_) {
508 if (info.inputTime - jankFrames.info_.beginVsyncTime > INPUTTIME_TIMEOUT &&
509 !jankFrames.isAnimationInterrupted_ && !jankFrames.isAnimationEnded_ &&
510 jankFrames.isUpdateJankFrame_) {
511 jankFrames.isAnimationInterrupted_ = true;
512 RS_TRACE_NAME("RSJankStats::SetReportEventResponse " + jankFrames.info_.sceneId +
513 " animation is interrupted by " + info.sceneId);
514 }
515 }
516 JankFrames jankFrames;
517 jankFrames.info_ = info;
518 jankFrames.isSetReportEventResponse_ = true;
519 jankFrames.setTimeSteady_ = setTimeSteady;
520 jankFrames.isFirstFrame_ = true;
521 jankFrames.isFirstFrameTemp_ = true;
522 jankFrames.traceId_ = GetTraceIdInit(info, setTimeSteady);
523 jankFrames.isDisplayAnimator_ = info.isDisplayAnimator;
524 animateJankFrames_.emplace(animationId, jankFrames);
525 }
526
SetReportEventComplete(const DataBaseRs & info)527 void RSJankStats::SetReportEventComplete(const DataBaseRs& info)
528 {
529 std::lock_guard<std::mutex> lock(mutex_);
530 RS_TRACE_NAME("RSJankStats::SetReportEventComplete receive notification: " + GetSceneDescription(info));
531 const auto animationId = GetAnimationId(info);
532 if (animateJankFrames_.find(animationId) == animateJankFrames_.end()) {
533 ROSEN_LOGD("RSJankStats::SetReportEventComplete Not find exited animationId");
534 } else {
535 animateJankFrames_[animationId].info_ = info;
536 animateJankFrames_[animationId].isSetReportEventComplete_ = true;
537 if (animateJankFrames_.at(animationId).isDisplayAnimator_ != info.isDisplayAnimator) {
538 ROSEN_LOGW("RSJankStats::SetReportEventComplete isDisplayAnimator not consistent");
539 }
540 HandleImplicitAnimationEndInAdvance(animateJankFrames_[animationId], false);
541 }
542 }
543
SetReportEventJankFrame(const DataBaseRs & info,bool isReportTaskDelayed)544 void RSJankStats::SetReportEventJankFrame(const DataBaseRs& info, bool isReportTaskDelayed)
545 {
546 std::lock_guard<std::mutex> lock(mutex_);
547 RS_TRACE_NAME("RSJankStats::SetReportEventJankFrame receive notification: " + GetSceneDescription(info));
548 const auto animationId = GetAnimationId(info);
549 if (animateJankFrames_.find(animationId) == animateJankFrames_.end()) {
550 ROSEN_LOGD("RSJankStats::SetReportEventJankFrame Not find exited animationId");
551 } else {
552 animateJankFrames_[animationId].info_ = info;
553 animateJankFrames_[animationId].isSetReportEventJankFrame_ = true;
554 if (animateJankFrames_.at(animationId).isDisplayAnimator_ != info.isDisplayAnimator) {
555 ROSEN_LOGW("RSJankStats::SetReportEventJankFrame isDisplayAnimator not consistent");
556 }
557 HandleImplicitAnimationEndInAdvance(animateJankFrames_[animationId], isReportTaskDelayed);
558 }
559 }
560
SetReportRsSceneJankStart(const AppInfo & info)561 void RSJankStats::SetReportRsSceneJankStart(const AppInfo& info)
562 {
563 std::lock_guard<std::mutex> lock(mutex_);
564 RS_TRACE_NAME("RSJankStats::SetReportRsSceneJankStart receive notification: " + info.processName);
565 auto currentTime = GetCurrentSteadyTimeMs();
566 if (!isLastReportSceneDone_ && currentTime - appInfo_.startTime > MIN_FRAME_SHOW_TIME) {
567 appInfo_.endTime = currentTime;
568 ReportSceneJankStats(appInfo_);
569 }
570 appInfo_ = info;
571 appInfo_.startTime = currentTime;
572 isLastReportSceneDone_ = false;
573 }
574
SetReportRsSceneJankEnd(const AppInfo & info)575 void RSJankStats::SetReportRsSceneJankEnd(const AppInfo& info)
576 {
577 std::lock_guard<std::mutex> lock(mutex_);
578 RS_TRACE_NAME("RSJankStats::SetReportRsSceneJankEnd receive notification: " + info.processName);
579 if (isLastReportSceneDone_ || appInfo_.pid != info.pid) {
580 ROSEN_LOGE("RSJankStats::SetReportRsSceneJankEnd error scene");
581 return;
582 }
583
584 appInfo_.endTime = GetCurrentSteadyTimeMs();
585 ReportSceneJankStats(appInfo_);
586 }
587
HandleImplicitAnimationEndInAdvance(JankFrames & jankFrames,bool isReportTaskDelayed)588 void RSJankStats::HandleImplicitAnimationEndInAdvance(JankFrames& jankFrames, bool isReportTaskDelayed)
589 {
590 if (jankFrames.isDisplayAnimator_) {
591 return;
592 }
593 if (jankFrames.isSetReportEventJankFrame_) {
594 RecordAnimationDynamicFrameRate(jankFrames, isReportTaskDelayed);
595 }
596 if (jankFrames.isSetReportEventComplete_ || jankFrames.isSetReportEventJankFrame_) {
597 SetAnimationTraceEnd(jankFrames);
598 }
599 if (jankFrames.isSetReportEventComplete_) {
600 ReportEventComplete(jankFrames);
601 }
602 if (jankFrames.isSetReportEventJankFrame_) {
603 ReportEventJankFrame(jankFrames, isReportTaskDelayed);
604 ReportEventHitchTimeRatio(jankFrames, isReportTaskDelayed);
605 }
606 jankFrames.isSetReportEventComplete_ = false;
607 jankFrames.isSetReportEventJankFrame_ = false;
608 }
609
SetAppFirstFrame(pid_t appPid)610 void RSJankStats::SetAppFirstFrame(pid_t appPid)
611 {
612 std::lock_guard<std::mutex> lock(mutex_);
613 firstFrameAppPids_.push(appPid);
614 }
615
SetImplicitAnimationEnd(bool isImplicitAnimationEnd)616 void RSJankStats::SetImplicitAnimationEnd(bool isImplicitAnimationEnd)
617 {
618 std::lock_guard<std::mutex> lock(mutex_);
619 SetImplicitAnimationEndInner(isImplicitAnimationEnd);
620 }
621
SetImplicitAnimationEndInner(bool isImplicitAnimationEnd)622 void RSJankStats::SetImplicitAnimationEndInner(bool isImplicitAnimationEnd)
623 {
624 if (!isImplicitAnimationEnd) {
625 return;
626 }
627 RS_TRACE_NAME("RSJankStats::SetImplicitAnimationEnd");
628 for (auto &[animationId, jankFrames] : animateJankFrames_) {
629 if (jankFrames.isDisplayAnimator_) {
630 continue;
631 }
632 SetAnimationTraceEnd(jankFrames);
633 }
634 }
635
ReportEventResponse(const JankFrames & jankFrames) const636 void RSJankStats::ReportEventResponse(const JankFrames& jankFrames) const
637 {
638 const auto &info = jankFrames.info_;
639 int64_t inputTime = ConvertTimeToSystime(info.inputTime);
640 int64_t beginVsyncTime = ConvertTimeToSystime(info.beginVsyncTime);
641 int64_t renderTime = jankFrames.traceCreateTime_;
642 if (renderTime == TIMESTAMP_INITIAL) {
643 renderTime = rtEndTime_;
644 }
645 int64_t responseLatency = renderTime - inputTime;
646 RS_TRACE_NAME_FMT("RSJankStats::ReportEventResponse responseLatency is %" PRId64 "ms: %s",
647 responseLatency, GetSceneDescription(info).c_str());
648 RSBackgroundThread::Instance().PostTask([info, inputTime, beginVsyncTime, responseLatency, renderTime]() {
649 RS_TRACE_NAME("RSJankStats::ReportEventResponse in RSBackgroundThread");
650 RSHiSysEvent::EventWrite(RSEventName::INTERACTION_RESPONSE_LATENCY, RSEventType::RS_BEHAVIOR,
651 "SCENE_ID", info.sceneId, "APP_PID", info.appPid,
652 "VERSION_CODE", info.versionCode, "VERSION_NAME", info.versionName, "BUNDLE_NAME", info.bundleName,
653 "ABILITY_NAME", info.abilityName, "PROCESS_NAME", info.processName, "PAGE_URL", info.pageUrl,
654 "SOURCE_TYPE", info.sourceType, "NOTE", info.note, "INPUT_TIME", static_cast<uint64_t>(inputTime),
655 "ANIMATION_START_TIME", static_cast<uint64_t>(beginVsyncTime), "RENDER_TIME",
656 static_cast<uint64_t>(renderTime), "RESPONSE_LATENCY", static_cast<uint64_t>(responseLatency));
657 });
658 }
659
ReportEventComplete(const JankFrames & jankFrames) const660 void RSJankStats::ReportEventComplete(const JankFrames& jankFrames) const
661 {
662 const auto &info = jankFrames.info_;
663 int64_t inputTime = ConvertTimeToSystime(info.inputTime);
664 int64_t beginVsyncTime = ConvertTimeToSystime(info.beginVsyncTime);
665 int64_t endVsyncTime = ConvertTimeToSystime(info.endVsyncTime);
666 int64_t animationStartLatency = beginVsyncTime - inputTime;
667 int64_t animationEndLatency = endVsyncTime - beginVsyncTime;
668 int64_t renderTime = jankFrames.traceTerminateTime_;
669 if (renderTime == TIMESTAMP_INITIAL) {
670 renderTime = rtEndTime_;
671 }
672 int64_t completedLatency = renderTime - inputTime;
673 RS_TRACE_NAME_FMT("RSJankStats::ReportEventComplete e2eLatency is %" PRId64 "ms: %s",
674 completedLatency, GetSceneDescription(info).c_str());
675 RSBackgroundThread::Instance().PostTask([
676 info, inputTime, animationStartLatency, animationEndLatency, completedLatency]() {
677 RS_TRACE_NAME("RSJankStats::ReportEventComplete in RSBackgroundThread");
678 RSHiSysEvent::EventWrite(RSEventName::INTERACTION_COMPLETED_LATENCY, RSEventType::RS_BEHAVIOR,
679 "APP_PID", info.appPid, "VERSION_CODE", info.versionCode,
680 "VERSION_NAME", info.versionName, "BUNDLE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
681 "PROCESS_NAME", info.processName, "PAGE_URL", info.pageUrl, "SCENE_ID", info.sceneId,
682 "SOURCE_TYPE", info.sourceType, "NOTE", info.note, "INPUT_TIME", static_cast<uint64_t>(inputTime),
683 "ANIMATION_START_LATENCY", static_cast<uint64_t>(animationStartLatency), "ANIMATION_END_LATENCY",
684 static_cast<uint64_t>(animationEndLatency), "E2E_LATENCY", static_cast<uint64_t>(completedLatency));
685 });
686 }
687
ReportEventJankFrame(const JankFrames & jankFrames,bool isReportTaskDelayed) const688 void RSJankStats::ReportEventJankFrame(const JankFrames& jankFrames, bool isReportTaskDelayed) const
689 {
690 if (!isReportTaskDelayed) {
691 ReportEventJankFrameWithoutDelay(jankFrames);
692 } else {
693 ReportEventJankFrameWithDelay(jankFrames);
694 }
695 }
696
ReportEventJankFrameWithoutDelay(const JankFrames & jankFrames) const697 void RSJankStats::ReportEventJankFrameWithoutDelay(const JankFrames& jankFrames) const
698 {
699 if (jankFrames.totalFrames_ <= 0) {
700 ROSEN_LOGD("RSJankStats::ReportEventJankFrame totalFrames is zero, nothing need to report");
701 return;
702 }
703 const auto &info = jankFrames.info_;
704 float aveFrameTimeSteady = jankFrames.totalFrameTimeSteady_ / static_cast<float>(jankFrames.totalFrames_);
705 bool isReportTaskDelayed = false;
706 int64_t maxFrameTimeFromStart = 0;
707 int64_t maxHitchTimeFromStart = 0;
708 int64_t duration = 0;
709 GetMaxJankInfo(jankFrames, isReportTaskDelayed, maxFrameTimeFromStart, maxHitchTimeFromStart, duration);
710 RS_TRACE_NAME_FMT(
711 "RSJankStats::ReportEventJankFrame maxFrameTime is %" PRId64 "ms, maxHitchTime is %" PRId64
712 "ms, maxTechFrameTime is %" PRId64 "ms, maxRealFrameTime is %" PRId64 "ms,"
713 "maxFrameRefreshRate is %" PRId32 "fps: %s",
714 jankFrames.maxFrameTimeSteady_, static_cast<int64_t>(jankFrames.maxHitchTime_),
715 jankFrames.maxTechFrameTimeSteady_, jankFrames.maxRealFrameTimeSteady_,
716 jankFrames.maxFrameRefreshRate_, GetSceneDescription(info).c_str());
717 RSBackgroundThread::Instance().PostTask([
718 jankFrames, info, aveFrameTimeSteady, maxFrameTimeFromStart, maxHitchTimeFromStart, duration]() {
719 RS_TRACE_NAME("RSJankStats::ReportEventJankFrame in RSBackgroundThread");
720 RSHiSysEvent::EventWrite(RSEventName::INTERACTION_RENDER_JANK, RSEventType::RS_STATISTIC,
721 "UNIQUE_ID", info.uniqueId, "SCENE_ID", info.sceneId,
722 "PROCESS_NAME", info.processName, "MODULE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
723 "PAGE_URL", info.pageUrl, "TOTAL_FRAMES", jankFrames.totalFrames_, "TOTAL_MISSED_FRAMES",
724 jankFrames.totalMissedFrames_, "MAX_FRAMETIME", static_cast<uint64_t>(jankFrames.maxFrameTimeSteady_),
725 "MAX_TECH_FRAMETIME", static_cast<uint64_t>(jankFrames.maxTechFrameTimeSteady_),
726 "MAX_REAL_FRAMETIME", static_cast<uint64_t>(jankFrames.maxRealFrameTimeSteady_),
727 "MAX_FRAMETIME_SINCE_START", static_cast<uint64_t>(maxFrameTimeFromStart), "AVERAGE_FRAMETIME",
728 aveFrameTimeSteady, "MAX_SEQ_MISSED_FRAMES", jankFrames.maxSeqMissedFrames_, "IS_FOLD_DISP", IS_FOLD_DISP,
729 "BUNDLE_NAME_EX", info.note, "MAX_HITCH_TIME", static_cast<uint64_t>(jankFrames.maxHitchTime_),
730 "MAX_HITCH_TIME_SINCE_START", static_cast<uint64_t>(maxHitchTimeFromStart),
731 "DURATION", static_cast<uint64_t>(duration),
732 "MAX_FRAME_REFRESH_RATE", static_cast<int32_t>(jankFrames.maxFrameRefreshRate_));
733 });
734 }
735
ReportEventJankFrameWithDelay(const JankFrames & jankFrames) const736 void RSJankStats::ReportEventJankFrameWithDelay(const JankFrames& jankFrames) const
737 {
738 if (jankFrames.lastTotalFrames_ <= 0) {
739 ROSEN_LOGD("RSJankStats::ReportEventJankFrame totalFrames is zero, nothing need to report");
740 return;
741 }
742 const auto &info = jankFrames.info_;
743 float aveFrameTimeSteady =
744 jankFrames.lastTotalFrameTimeSteady_ / static_cast<float>(jankFrames.lastTotalFrames_);
745 bool isReportTaskDelayed = true;
746 int64_t maxFrameTimeFromStart = 0;
747 int64_t maxHitchTimeFromStart = 0;
748 int64_t duration = 0;
749 GetMaxJankInfo(jankFrames, isReportTaskDelayed, maxFrameTimeFromStart, maxHitchTimeFromStart, duration);
750 RS_TRACE_NAME_FMT(
751 "RSJankStats::ReportEventJankFrame maxFrameTime is %" PRId64 "ms, maxHitchTime is %" PRId64
752 "ms, maxTechFrameTime is %" PRId64 "ms, maxRealFrameTime is %" PRId64 "ms,"
753 "maxFrameRefreshRate is %" PRId32 "fps: %s",
754 jankFrames.lastMaxFrameTimeSteady_, static_cast<int64_t>(jankFrames.lastMaxHitchTime_),
755 jankFrames.lastMaxTechFrameTimeSteady_, jankFrames.lastMaxRealFrameTimeSteady_,
756 jankFrames.lastMaxFrameRefreshRate_, GetSceneDescription(info).c_str());
757 RSBackgroundThread::Instance().PostTask([
758 jankFrames, info, aveFrameTimeSteady, maxFrameTimeFromStart, maxHitchTimeFromStart, duration]() {
759 RS_TRACE_NAME("RSJankStats::ReportEventJankFrame in RSBackgroundThread");
760 RSHiSysEvent::EventWrite(RSEventName::INTERACTION_RENDER_JANK, RSEventType::RS_STATISTIC,
761 "UNIQUE_ID", info.uniqueId, "SCENE_ID", info.sceneId,
762 "PROCESS_NAME", info.processName, "MODULE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
763 "PAGE_URL", info.pageUrl, "TOTAL_FRAMES", jankFrames.lastTotalFrames_,
764 "TOTAL_MISSED_FRAMES", jankFrames.lastTotalMissedFrames_,
765 "MAX_FRAMETIME", static_cast<uint64_t>(jankFrames.lastMaxFrameTimeSteady_),
766 "MAX_TECH_FRAMETIME", static_cast<uint64_t>(jankFrames.lastMaxTechFrameTimeSteady_),
767 "MAX_REAL_FRAMETIME", static_cast<uint64_t>(jankFrames.lastMaxRealFrameTimeSteady_),
768 "MAX_FRAMETIME_SINCE_START", static_cast<uint64_t>(maxFrameTimeFromStart),
769 "AVERAGE_FRAMETIME", aveFrameTimeSteady, "MAX_SEQ_MISSED_FRAMES", jankFrames.lastMaxSeqMissedFrames_,
770 "IS_FOLD_DISP", IS_FOLD_DISP, "BUNDLE_NAME_EX", info.note,
771 "MAX_HITCH_TIME", static_cast<uint64_t>(jankFrames.lastMaxHitchTime_),
772 "MAX_HITCH_TIME_SINCE_START", static_cast<uint64_t>(maxHitchTimeFromStart),
773 "DURATION", static_cast<uint64_t>(duration),
774 "MAX_FRAME_REFRESH_RATE", static_cast<int32_t>(jankFrames.lastMaxFrameRefreshRate_));
775 });
776 }
777
GetMaxJankInfo(const JankFrames & jankFrames,bool isReportTaskDelayed,int64_t & maxFrameTimeFromStart,int64_t & maxHitchTimeFromStart,int64_t & duration) const778 void RSJankStats::GetMaxJankInfo(const JankFrames& jankFrames, bool isReportTaskDelayed,
779 int64_t& maxFrameTimeFromStart, int64_t& maxHitchTimeFromStart, int64_t& duration) const
780 {
781 maxFrameTimeFromStart = 0;
782 maxHitchTimeFromStart = 0;
783 duration = 0;
784 const int64_t startTimeSteady = jankFrames.traceCreateTimeSteady_;
785 const int64_t endTimeSteady = jankFrames.traceTerminateTimeSteady_;
786 if (startTimeSteady == TIMESTAMP_INITIAL || endTimeSteady == TIMESTAMP_INITIAL) {
787 return;
788 }
789 duration = std::max<int64_t>(0, endTimeSteady - startTimeSteady);
790 if (!isReportTaskDelayed) {
791 if (jankFrames.maxFrameOccurenceTimeSteady_ != TIMESTAMP_INITIAL) {
792 maxFrameTimeFromStart = std::max<int64_t>(0, jankFrames.maxFrameOccurenceTimeSteady_ - startTimeSteady);
793 }
794 if (jankFrames.maxHitchOccurenceTimeSteady_ != TIMESTAMP_INITIAL) {
795 maxHitchTimeFromStart = std::max<int64_t>(0, jankFrames.maxHitchOccurenceTimeSteady_ - startTimeSteady);
796 }
797 } else {
798 if (jankFrames.lastMaxFrameOccurenceTimeSteady_ != TIMESTAMP_INITIAL) {
799 maxFrameTimeFromStart = std::max<int64_t>(0, jankFrames.lastMaxFrameOccurenceTimeSteady_ - startTimeSteady);
800 }
801 if (jankFrames.lastMaxHitchOccurenceTimeSteady_ != TIMESTAMP_INITIAL) {
802 maxHitchTimeFromStart = std::max<int64_t>(0, jankFrames.lastMaxHitchOccurenceTimeSteady_ - startTimeSteady);
803 }
804 }
805 maxFrameTimeFromStart = std::min<int64_t>(maxFrameTimeFromStart, duration);
806 maxHitchTimeFromStart = std::min<int64_t>(maxHitchTimeFromStart, duration);
807 }
808
ReportEventHitchTimeRatio(const JankFrames & jankFrames,bool isReportTaskDelayed) const809 void RSJankStats::ReportEventHitchTimeRatio(const JankFrames& jankFrames, bool isReportTaskDelayed) const
810 {
811 if (!isReportTaskDelayed) {
812 ReportEventHitchTimeRatioWithoutDelay(jankFrames);
813 } else {
814 ReportEventHitchTimeRatioWithDelay(jankFrames);
815 }
816 }
817
ReportEventHitchTimeRatioWithoutDelay(const JankFrames & jankFrames) const818 void RSJankStats::ReportEventHitchTimeRatioWithoutDelay(const JankFrames& jankFrames) const
819 {
820 if (jankFrames.totalFrameTimeSteadyForHTR_ <= 0) {
821 ROSEN_LOGD("RSJankStats::ReportEventHitchTimeRatio duration is zero, nothing need to report");
822 return;
823 }
824 const auto &info = jankFrames.info_;
825 int64_t beginVsyncTime = ConvertTimeToSystime(info.beginVsyncTime);
826 float hitchTimeRatio = jankFrames.totalHitchTimeSteady_ / (jankFrames.totalFrameTimeSteadyForHTR_ / S_TO_MS);
827 RS_TRACE_NAME_FMT("RSJankStats::ReportEventHitchTimeRatio hitch time ratio is %g ms/s: %s",
828 hitchTimeRatio, GetSceneDescription(info).c_str());
829 RSBackgroundThread::Instance().PostTask([jankFrames, info, beginVsyncTime, hitchTimeRatio]() {
830 RS_TRACE_NAME("RSJankStats::ReportEventHitchTimeRatio in RSBackgroundThread");
831 RSHiSysEvent::EventWrite(RSEventName::INTERACTION_HITCH_TIME_RATIO, RSEventType::RS_STATISTIC,
832 "UNIQUE_ID", info.uniqueId, "SCENE_ID", info.sceneId,
833 "PROCESS_NAME", info.processName, "MODULE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
834 "PAGE_URL", info.pageUrl, "UI_START_TIME", static_cast<uint64_t>(beginVsyncTime),
835 "RS_START_TIME", static_cast<uint64_t>(jankFrames.startTime_), "DURATION",
836 static_cast<uint64_t>(jankFrames.totalFrameTimeSteadyForHTR_), "HITCH_TIME",
837 static_cast<uint64_t>(jankFrames.totalHitchTimeSteady_), "HITCH_TIME_RATIO", hitchTimeRatio,
838 "IS_FOLD_DISP", IS_FOLD_DISP, "BUNDLE_NAME_EX", info.note);
839 });
840 }
841
ReportEventHitchTimeRatioWithDelay(const JankFrames & jankFrames) const842 void RSJankStats::ReportEventHitchTimeRatioWithDelay(const JankFrames& jankFrames) const
843 {
844 if (jankFrames.lastTotalFrameTimeSteadyForHTR_ <= 0) {
845 ROSEN_LOGD("RSJankStats::ReportEventHitchTimeRatio duration is zero, nothing need to report");
846 return;
847 }
848 const auto &info = jankFrames.info_;
849 int64_t beginVsyncTime = ConvertTimeToSystime(info.beginVsyncTime);
850 float hitchTimeRatio =
851 jankFrames.lastTotalHitchTimeSteady_ / (jankFrames.lastTotalFrameTimeSteadyForHTR_ / S_TO_MS);
852 RS_TRACE_NAME_FMT("RSJankStats::ReportEventHitchTimeRatio hitch time ratio is %g ms/s: %s",
853 hitchTimeRatio, GetSceneDescription(info).c_str());
854 RSBackgroundThread::Instance().PostTask([jankFrames, info, beginVsyncTime, hitchTimeRatio]() {
855 RS_TRACE_NAME("RSJankStats::ReportEventHitchTimeRatio in RSBackgroundThread");
856 RSHiSysEvent::EventWrite(RSEventName::INTERACTION_HITCH_TIME_RATIO, RSEventType::RS_STATISTIC,
857 "UNIQUE_ID", info.uniqueId, "SCENE_ID", info.sceneId,
858 "PROCESS_NAME", info.processName, "MODULE_NAME", info.bundleName, "ABILITY_NAME", info.abilityName,
859 "PAGE_URL", info.pageUrl, "UI_START_TIME", static_cast<uint64_t>(beginVsyncTime),
860 "RS_START_TIME", static_cast<uint64_t>(jankFrames.startTime_), "DURATION",
861 static_cast<uint64_t>(jankFrames.lastTotalFrameTimeSteadyForHTR_), "HITCH_TIME",
862 static_cast<uint64_t>(jankFrames.lastTotalHitchTimeSteady_), "HITCH_TIME_RATIO", hitchTimeRatio,
863 "IS_FOLD_DISP", IS_FOLD_DISP, "BUNDLE_NAME_EX", info.note);
864 });
865 }
866
ReportEventFirstFrame()867 void RSJankStats::ReportEventFirstFrame()
868 {
869 while (!firstFrameAppPids_.empty()) {
870 pid_t appPid = firstFrameAppPids_.front();
871 ReportEventFirstFrameByPid(appPid);
872 firstFrameAppPids_.pop();
873 }
874 }
875
ReportEventFirstFrameByPid(pid_t appPid) const876 void RSJankStats::ReportEventFirstFrameByPid(pid_t appPid) const
877 {
878 RS_TRACE_NAME_FMT("RSJankStats::ReportEventFirstFrame app pid %d", appPid);
879 RSBackgroundThread::Instance().PostTask([appPid]() {
880 RS_TRACE_NAME("RSJankStats::ReportEventFirstFrame in RSBackgroundThread");
881 RSHiSysEvent::EventWrite(RSEventName::FIRST_FRAME_DRAWN, RSEventType::RS_BEHAVIOR,
882 "APP_PID", static_cast<int32_t>(appPid));
883 });
884 }
885
RecordJankFrame(uint32_t dynamicRefreshRate)886 void RSJankStats::RecordJankFrame(uint32_t dynamicRefreshRate)
887 {
888 RS_TRACE_INT(ACCUMULATED_BUFFER_COUNT_TRACE_NAME, accumulatedBufferCount_);
889 if (dynamicRefreshRate == 0) {
890 dynamicRefreshRate = STANDARD_REFRESH_RATE;
891 }
892 const float accumulatedTime = accumulatedBufferCount_ * S_TO_MS / dynamicRefreshRate;
893 for (auto& recordStats : jankExplicitAnimatorFrameRecorder_) {
894 recordStats.isRecorded_ = false;
895 }
896 const int64_t missedFramesByDuration = static_cast<int64_t>(
897 std::max<float>(0.f, GetEffectiveFrameTime(true) - accumulatedTime) / VSYNC_PERIOD);
898 if (missedFramesByDuration > 0 && explicitAnimationTotal_ > 0) {
899 for (auto& recordStats : jankExplicitAnimatorFrameRecorder_) {
900 RecordJankFrameSingle(missedFramesByDuration, recordStats);
901 }
902 }
903 for (auto& recordStats : jankImplicitAnimatorFrameRecorder_) {
904 recordStats.isRecorded_ = false;
905 }
906 const int64_t missedFramesByInterval = static_cast<int64_t>(
907 std::max<float>(0.f, GetEffectiveFrameTime(isFirstSetEnd_) - accumulatedTime) / VSYNC_PERIOD);
908 if (missedFramesByInterval > 0 && implicitAnimationTotal_ > 0) {
909 for (auto& recordStats : jankImplicitAnimatorFrameRecorder_) {
910 RecordJankFrameSingle(missedFramesByInterval, recordStats);
911 }
912 }
913 RS_TRACE_INT(ACCUMULATED_BUFFER_COUNT_TRACE_NAME, 0);
914 }
915
RecordJankFrameSingle(int64_t missedFrames,JankFrameRecordStats & recordStats)916 void RSJankStats::RecordJankFrameSingle(int64_t missedFrames, JankFrameRecordStats& recordStats)
917 {
918 if (recordStats.isRecorded_) {
919 return;
920 }
921 if (missedFrames >= recordStats.recordThreshold_) {
922 RS_TRACE_INT(recordStats.countTraceName_, missedFrames);
923 recordStats.isRecorded_ = true;
924 RS_TRACE_INT(recordStats.countTraceName_, 0);
925 }
926 }
927
RecordAnimationDynamicFrameRate(JankFrames & jankFrames,bool isReportTaskDelayed)928 void RSJankStats::RecordAnimationDynamicFrameRate(JankFrames& jankFrames, bool isReportTaskDelayed)
929 {
930 if (jankFrames.isFrameRateRecorded_) {
931 return;
932 }
933 const int32_t traceId = jankFrames.traceId_;
934 if (traceId == TRACE_ID_INITIAL) {
935 ROSEN_LOGE("RSJankStats::RecordAnimationDynamicFrameRate traceId not initialized");
936 return;
937 }
938 if (!isReportTaskDelayed) {
939 if (animationAsyncTraces_.find(traceId) == animationAsyncTraces_.end() || jankFrames.totalFrames_ <= 0 ||
940 jankFrames.totalFrameTimeSteadyForHTR_ <= 0) {
941 return;
942 }
943 float animationDuration = static_cast<float>(jankFrames.totalFrameTimeSteadyForHTR_) / S_TO_MS;
944 float animationTotalFrames = static_cast<float>(jankFrames.totalFrames_);
945 float animationDynamicFrameRate = animationTotalFrames / animationDuration;
946 RS_TRACE_NAME_FMT("RSJankStats::RecordAnimationDynamicFrameRate frame rate is %.2f: %s",
947 animationDynamicFrameRate, animationAsyncTraces_.at(traceId).traceName_.c_str());
948 } else {
949 if (animationAsyncTraces_.find(traceId) == animationAsyncTraces_.end() || jankFrames.lastTotalFrames_ <= 0 ||
950 jankFrames.lastTotalFrameTimeSteadyForHTR_ <= 0) {
951 return;
952 }
953 float animationDuration = static_cast<float>(jankFrames.lastTotalFrameTimeSteadyForHTR_) / S_TO_MS;
954 float animationTotalFrames = static_cast<float>(jankFrames.lastTotalFrames_);
955 float animationDynamicFrameRate = animationTotalFrames / animationDuration;
956 RS_TRACE_NAME_FMT("RSJankStats::RecordAnimationDynamicFrameRate frame rate is %.2f: %s",
957 animationDynamicFrameRate, animationAsyncTraces_.at(traceId).traceName_.c_str());
958 }
959 jankFrames.isFrameRateRecorded_ = true;
960 }
961
GetEarlyZEnableFlag()962 bool RSJankStats::GetEarlyZEnableFlag()
963 {
964 std::lock_guard<std::mutex> lock(mutex_);
965 isFlushEarlyZ_ = false;
966 return ddgrEarlyZEnable_;
967 }
968
GetFlushEarlyZ()969 bool RSJankStats::GetFlushEarlyZ()
970 {
971 std::lock_guard<std::mutex> lock(mutex_);
972 return isFlushEarlyZ_;
973 }
974
SetAnimationTraceBegin(std::pair<int64_t,std::string> animationId,JankFrames & jankFrames)975 void RSJankStats::SetAnimationTraceBegin(std::pair<int64_t, std::string> animationId, JankFrames& jankFrames)
976 {
977 jankFrames.isUpdateJankFrame_ = true;
978 if (jankFrames.isAnimationEnded_) {
979 return;
980 }
981 const int32_t traceId = jankFrames.traceId_;
982 if (traceId == TRACE_ID_INITIAL) {
983 ROSEN_LOGE("RSJankStats::SetAnimationTraceBegin traceId not initialized");
984 return;
985 }
986 if (animationAsyncTraces_.find(traceId) != animationAsyncTraces_.end()) {
987 return;
988 }
989 jankFrames.traceCreateTime_ = rtEndTime_;
990 jankFrames.traceCreateTimeSteady_ = rtEndTimeSteady_;
991 const auto &info = jankFrames.info_;
992 const std::string traceName = GetSceneDescription(info);
993 AnimationTraceStats traceStat = {.animationId_ = animationId,
994 .traceName_ = traceName,
995 .traceCreateTimeSteady_ = rtEndTimeSteady_,
996 .isDisplayAnimator_ = info.isDisplayAnimator};
997 animationAsyncTraces_.emplace(traceId, traceStat);
998 if (info.isDisplayAnimator) {
999 explicitAnimationTotal_++;
1000 } else {
1001 implicitAnimationTotal_++;
1002 }
1003 RS_ASYNC_TRACE_BEGIN(traceName, traceId);
1004 if (RSSystemProperties::GetEarlyZEnable() && info.sceneId == SWITCH_SCENE_NAME) {
1005 ddgrEarlyZEnable_ = true;
1006 isFlushEarlyZ_ = true;
1007 lastReportEarlyZTraceId_ = traceId;
1008 }
1009 }
1010
SetAnimationTraceEnd(JankFrames & jankFrames)1011 void RSJankStats::SetAnimationTraceEnd(JankFrames& jankFrames)
1012 {
1013 jankFrames.isUpdateJankFrame_ = false;
1014 jankFrames.isAnimationEnded_ = true;
1015 const int32_t traceId = jankFrames.traceId_;
1016 if (traceId == TRACE_ID_INITIAL) {
1017 ROSEN_LOGE("RSJankStats::SetAnimationTraceEnd traceId not initialized");
1018 return;
1019 }
1020 if (animationAsyncTraces_.find(traceId) == animationAsyncTraces_.end()) {
1021 return;
1022 }
1023 jankFrames.traceTerminateTime_ = rtEndTime_;
1024 jankFrames.traceTerminateTimeSteady_ = rtEndTimeSteady_;
1025 const bool isDisplayAnimator = animationAsyncTraces_.at(traceId).isDisplayAnimator_;
1026 RS_ASYNC_TRACE_END(animationAsyncTraces_.at(traceId).traceName_, traceId);
1027 if (ddgrEarlyZEnable_ && lastReportEarlyZTraceId_ == traceId) {
1028 ddgrEarlyZEnable_ = false;
1029 isFlushEarlyZ_ = true;
1030 lastReportEarlyZTraceId_ = traceId;
1031 }
1032 animationAsyncTraces_.erase(traceId);
1033 if (isDisplayAnimator) {
1034 explicitAnimationTotal_--;
1035 } else {
1036 implicitAnimationTotal_--;
1037 }
1038 }
1039
CheckAnimationTraceTimeout()1040 void RSJankStats::CheckAnimationTraceTimeout()
1041 {
1042 if (++animationTraceCheckCnt_ < ANIMATION_TRACE_CHECK_FREQ) {
1043 return;
1044 }
1045 EraseIf(animationAsyncTraces_, [this](const auto& pair) -> bool {
1046 bool needErase = rtEndTimeSteady_ - pair.second.traceCreateTimeSteady_ > ANIMATION_TIMEOUT;
1047 if (needErase) {
1048 RS_ASYNC_TRACE_END(pair.second.traceName_, pair.first);
1049 if (pair.second.isDisplayAnimator_) {
1050 explicitAnimationTotal_--;
1051 } else {
1052 implicitAnimationTotal_--;
1053 }
1054 animateJankFrames_.erase(pair.second.animationId_);
1055 }
1056 return needErase;
1057 });
1058 animationTraceCheckCnt_ = 0;
1059 }
1060
ClearAllAnimation()1061 void RSJankStats::ClearAllAnimation()
1062 {
1063 RS_TRACE_NAME("RSJankStats::ClearAllAnimation");
1064 EraseIf(animationAsyncTraces_, [](const auto& pair) -> bool {
1065 RS_ASYNC_TRACE_END(pair.second.traceName_, pair.first);
1066 return true;
1067 });
1068 explicitAnimationTotal_ = 0;
1069 implicitAnimationTotal_ = 0;
1070 animateJankFrames_.clear();
1071 }
1072
GetSceneDescription(const DataBaseRs & info) const1073 std::string RSJankStats::GetSceneDescription(const DataBaseRs& info) const
1074 {
1075 std::stringstream sceneDescription;
1076 int64_t inputTime = ConvertTimeToSystime(info.inputTime);
1077 std::string animatorType = (info.isDisplayAnimator ? "EXPLICIT_ANIMATOR" : "IMPLICIT_ANIMATOR");
1078 sceneDescription << info.sceneId << ", " << info.bundleName << ", " << info.pageUrl
1079 << ", " << inputTime << ", " << animatorType << ", uid" << info.uniqueId;
1080 return sceneDescription.str();
1081 }
1082
GetAnimationId(const DataBaseRs & info) const1083 std::pair<int64_t, std::string> RSJankStats::GetAnimationId(const DataBaseRs& info) const
1084 {
1085 std::pair<int64_t, std::string> animationId(info.uniqueId, info.sceneId);
1086 return animationId;
1087 }
1088
GetTraceIdInit(const DataBaseRs & info,int64_t setTimeSteady)1089 int32_t RSJankStats::GetTraceIdInit(const DataBaseRs& info, int64_t setTimeSteady)
1090 {
1091 if (traceIdRemainder_.find(info.uniqueId) == traceIdRemainder_.end()) {
1092 TraceIdRemainderStats traceIdStat;
1093 traceIdRemainder_.emplace(info.uniqueId, traceIdStat);
1094 }
1095 if (traceIdRemainder_.at(info.uniqueId).remainder_ >= TRACE_ID_SCALE_PARAM) {
1096 traceIdRemainder_[info.uniqueId].remainder_ = 0;
1097 }
1098 traceIdRemainder_[info.uniqueId].setTimeSteady_ = setTimeSteady;
1099 int64_t mappedUniqueId = info.uniqueId * TRACE_ID_SCALE_PARAM + (traceIdRemainder_[info.uniqueId].remainder_++);
1100 int32_t traceId = static_cast<int32_t>(mappedUniqueId);
1101 return traceId;
1102 }
1103
AvcodecVideoDump(std::string & dumpString,std::string & type,const std::string & avcodecVideo)1104 void RSJankStats::AvcodecVideoDump(
1105 std::string& dumpString, std::string& type, const std::string& avcodecVideo)
1106 {
1107 std::string func;
1108 uint64_t uniqueId;
1109 std::string surfaceName = "";
1110 uint32_t fps = 0;
1111 uint64_t reportTime = UINT64_MAX;
1112
1113 RS_LOGD("AvcodecVideoDump start. type %{public}s", type.substr(avcodecVideo.length()).c_str());
1114 cJSON* jsonObject = cJSON_Parse(type.substr(avcodecVideo.length()).c_str());
1115 if (jsonObject == nullptr) {
1116 dumpString.append("AvcodecVideoDump can not parse type to json.\n");
1117 cJSON_Delete(jsonObject);
1118 return;
1119 }
1120
1121 cJSON* jsonItemFunc = cJSON_GetObjectItem(jsonObject, "func");
1122 if (jsonItemFunc != nullptr && cJSON_IsString(jsonItemFunc)) {
1123 func = jsonItemFunc->valuestring;
1124 }
1125
1126 cJSON* jsonItemUniqueId = cJSON_GetObjectItem(jsonObject, "uniqueId");
1127 if (jsonItemUniqueId != nullptr && cJSON_IsString(jsonItemUniqueId)) {
1128 std::string strM = jsonItemUniqueId->valuestring;
1129 char* end = nullptr;
1130 errno = 0;
1131 long long sizeM = std::strtoll(strM.c_str(), &end, 10);
1132 if (end != nullptr && end != strM.c_str() && errno == 0 && *end == '\0' && sizeM > 0) {
1133 uniqueId = static_cast<uint64_t>(sizeM);
1134 } else {
1135 dumpString.append("AvcodecVideoDump param error : uniqueId.\n");
1136 cJSON_Delete(jsonObject);
1137 return;
1138 }
1139 } else {
1140 dumpString.append("AvcodecVideoDump param error : uniqueId.\n");
1141 cJSON_Delete(jsonObject);
1142 return;
1143 }
1144
1145 cJSON* jsonItemSurface = cJSON_GetObjectItem(jsonObject, "surfaceName");
1146 if (jsonItemSurface != nullptr && cJSON_IsString(jsonItemSurface)) {
1147 surfaceName = jsonItemSurface->valuestring;
1148 }
1149
1150 cJSON* jsonItemFps = cJSON_GetObjectItem(jsonObject, "fps");
1151 if (jsonItemFps != nullptr && cJSON_IsNumber(jsonItemFps)) {
1152 fps = static_cast<uint32_t>(jsonItemFps->valueint);
1153 }
1154
1155 if (func == "start") {
1156 cJSON* jsonItemReportTime = cJSON_GetObjectItem(jsonObject, "reportTime");
1157 if (jsonItemReportTime != nullptr && cJSON_IsNumber(jsonItemReportTime)) {
1158 reportTime = static_cast<uint64_t>(jsonItemReportTime->valueint);
1159 } else {
1160 dumpString.append("AvcodecVideoDump param error : reportTime.\n");
1161 cJSON_Delete(jsonObject);
1162 return;
1163 }
1164
1165 AvcodecVideoStart(uniqueId, surfaceName, fps, reportTime);
1166 dumpString.append("AvcodecVideoStart ");
1167 } else {
1168 AvcodecVideoStop(uniqueId, surfaceName, fps);
1169 dumpString.append("AvcodecVideoStop ");
1170 }
1171 cJSON_Delete(jsonObject);
1172 dumpString.append("[uniqueId:" + std::to_string(uniqueId) + ", surfaceName:" + surfaceName +
1173 ", fps:" + std::to_string(fps) + ", reportTime:" + std::to_string(reportTime) + "]\n");
1174 }
1175
AvcodecVideoStart(const uint64_t queueId,const std::string & surfaceName,const uint32_t fps,const uint64_t reportTime)1176 void RSJankStats::AvcodecVideoStart(
1177 const uint64_t queueId, const std::string& surfaceName, const uint32_t fps, const uint64_t reportTime)
1178 {
1179 std::lock_guard<std::mutex> lock(mutex_);
1180 if (avcodecVideoMap_.find(queueId) != avcodecVideoMap_.end()) {
1181 RS_LOGE("AvcodecVideoStart mission exists. %{public}" PRIu64 ".", queueId);
1182 return;
1183 }
1184
1185 AvcodecVideoParam& info = avcodecVideoMap_[queueId];
1186 info.surfaceName = surfaceName;
1187 info.fps = fps;
1188 info.reportTime = reportTime;
1189 info.startTime = static_cast<uint64_t>(GetCurrentSystimeMs());
1190 info.decodeCount = 0;
1191
1192 avcodecVideoCollectOpen_ = true;
1193 RS_TRACE_NAME_FMT("AvcodecVideoStart [queueId %lu, surfaceName %s, fps %u, reportTime %lu, startTime %lu]",
1194 queueId, info.surfaceName.c_str(), info.fps, info.reportTime, info.startTime);
1195 }
1196
AvcodecVideoStop(const uint64_t queueId,const std::string & surfaceName,const uint32_t fps)1197 void RSJankStats::AvcodecVideoStop(const uint64_t queueId, const std::string& surfaceName, const uint32_t fps)
1198 {
1199 std::lock_guard<std::mutex> lock(mutex_);
1200 auto it = avcodecVideoMap_.find(queueId);
1201 if (it == avcodecVideoMap_.end()) {
1202 RS_LOGE("AvcodecVideoStop mission does not exist. %{public}" PRIu64 ".", queueId);
1203 return;
1204 }
1205
1206 uint64_t duration = static_cast<uint64_t>(GetCurrentSystimeMs()) - it->second.startTime;
1207 RS_TRACE_NAME_FMT("AvcodecVideoStop mission complete. NotifyVideoEventToXperf" \
1208 "[uniqueId %lu, duration %lu, avgFps %lu]",
1209 queueId, duration, it->second.decodeCount * DELAY_TIME_MS / duration);
1210 RS_LOGD("AvcodecVideoStop mission complete. NotifyVideoEventToXperf" \
1211 "[uniqueId %{public}" PRIu64 ", duration %{public}" PRIu64 ", avgFps %{public}" PRIu64 "]",
1212 queueId, duration, it->second.decodeCount * DELAY_TIME_MS / duration);
1213
1214 avcodecVideoMap_.erase(it);
1215
1216 if (avcodecVideoMap_.empty()) {
1217 avcodecVideoCollectOpen_ = false;
1218 }
1219 }
1220
AvcodecVideoCollectBegin()1221 void RSJankStats::AvcodecVideoCollectBegin()
1222 {
1223 if (!avcodecVideoCollectOpen_) {
1224 return;
1225 }
1226
1227 for (auto& [queueId, info] : avcodecVideoMap_) {
1228 info.continuousFrameLoss++;
1229 }
1230 }
1231
AvcodecVideoCollectFinish()1232 void RSJankStats::AvcodecVideoCollectFinish()
1233 {
1234 if (!avcodecVideoCollectOpen_) {
1235 return;
1236 }
1237
1238 std::vector<uint64_t> finishedVideos;
1239 for (auto it = avcodecVideoMap_.begin(); it != avcodecVideoMap_.end(); it++) {
1240 if (it->second.continuousFrameLoss >= ACVIDEO_QUIT_FRAME_COUNT) {
1241 RS_LOGD("AvcodecVideoCollectFinish. [uniqueId %{public}" PRIu64 "]", it->first);
1242 finishedVideos.push_back(it->first);
1243 }
1244 }
1245 for (auto queueId : finishedVideos) {
1246 AvcodecVideoStop(queueId);
1247 }
1248 }
1249
AvcodecVideoCollect(const uint64_t queueId,const uint32_t sequence)1250 void RSJankStats::AvcodecVideoCollect(const uint64_t queueId, const uint32_t sequence)
1251 {
1252 if (!avcodecVideoCollectOpen_) {
1253 return;
1254 }
1255
1256 auto it = avcodecVideoMap_.find(queueId);
1257 if (it == avcodecVideoMap_.end()) {
1258 return;
1259 }
1260
1261 uint64_t now = static_cast<uint64_t>(GetCurrentSystimeMs());
1262 if (it->second.previousSequence == 0) {
1263 // first sequence
1264 it->second.decodeCount++;
1265 it->second.previousSequence = sequence;
1266 it->second.previousFrameTime = now;
1267 it->second.continuousFrameLoss = 0;
1268 } else if (it->second.previousSequence != sequence) {
1269 uint64_t frameTime = now - it->second.previousFrameTime;
1270 if (frameTime > it->second.reportTime) {
1271 RSBackgroundThread::Instance().PostTask([queueId, frameTime]() {
1272 RS_TRACE_NAME_FMT("AvcodecVideoCollect NotifyVideoFaultToXperf [uniqueId %lu, frameTime %lu]",
1273 queueId, frameTime);
1274 RS_LOGD("AvcodecVideoCollect NotifyVideoFaultToXperf" \
1275 "[uniqueId %{public}" PRIu64 ", frameTime %{public}" PRIu64 "]",
1276 queueId, frameTime);
1277 });
1278 }
1279 it->second.decodeCount++;
1280 it->second.previousSequence = sequence;
1281 it->second.previousFrameTime = now;
1282 it->second.continuousFrameLoss = 0;
1283 }
1284 }
1285
GetEffectiveFrameTime(bool isConsiderRsStartTime) const1286 int64_t RSJankStats::GetEffectiveFrameTime(bool isConsiderRsStartTime) const
1287 {
1288 if (isConsiderRsStartTime) {
1289 return std::min<int64_t>(rtEndTimeSteady_ - rtLastEndTimeSteady_, rtEndTimeSteady_ - rsStartTimeSteady_);
1290 }
1291 if (isCurrentFrameSwitchToNotDoDirectComposition_) {
1292 return rtEndTimeSteady_ - rsStartTimeSteady_;
1293 }
1294 return rtEndTimeSteady_ - rtLastEndTimeSteady_;
1295 }
1296
GetEffectiveFrameTimeFloat(bool isConsiderRsStartTime) const1297 float RSJankStats::GetEffectiveFrameTimeFloat(bool isConsiderRsStartTime) const
1298 {
1299 if (isConsiderRsStartTime) {
1300 return std::min<float>(rtEndTimeSteadyFloat_ - rtLastEndTimeSteadyFloat_,
1301 rtEndTimeSteadyFloat_ - rsStartTimeSteadyFloat_);
1302 }
1303 if (isCurrentFrameSwitchToNotDoDirectComposition_) {
1304 return rtEndTimeSteadyFloat_ - rsStartTimeSteadyFloat_;
1305 }
1306 return rtEndTimeSteadyFloat_ - rtLastEndTimeSteadyFloat_;
1307 }
1308
ConvertTimeToSystime(int64_t time) const1309 int64_t RSJankStats::ConvertTimeToSystime(int64_t time) const
1310 {
1311 if (time <= 0) {
1312 ROSEN_LOGW("RSJankStats::ConvertTimeToSystime, time is error");
1313 return 0;
1314 }
1315 struct timespec ts = { 0, 0 };
1316 if (clock_gettime(CLOCK_MONOTONIC, &ts) != 0) {
1317 return 0;
1318 }
1319 int64_t nowTime = static_cast<int64_t>(ts.tv_sec) * S_TO_NS + static_cast<int64_t>(ts.tv_nsec);
1320 int64_t curSysTime = GetCurrentSystimeMs();
1321 int64_t sysTime = curSysTime - (nowTime - time) / MS_TO_NS;
1322 return sysTime;
1323 }
1324
GetCurrentSystimeMs() const1325 int64_t RSJankStats::GetCurrentSystimeMs() const
1326 {
1327 auto curTime = std::chrono::system_clock::now().time_since_epoch();
1328 int64_t curSysTime = std::chrono::duration_cast<std::chrono::milliseconds>(curTime).count();
1329 return curSysTime;
1330 }
1331
GetCurrentSteadyTimeMs() const1332 int64_t RSJankStats::GetCurrentSteadyTimeMs() const
1333 {
1334 auto curTime = std::chrono::steady_clock::now().time_since_epoch();
1335 int64_t curSteadyTime = std::chrono::duration_cast<std::chrono::milliseconds>(curTime).count();
1336 return curSteadyTime;
1337 }
1338
GetCurrentSteadyTimeMsFloat() const1339 float RSJankStats::GetCurrentSteadyTimeMsFloat() const
1340 {
1341 auto curTime = std::chrono::steady_clock::now().time_since_epoch();
1342 int64_t curSteadyTimeUs = std::chrono::duration_cast<std::chrono::microseconds>(curTime).count();
1343 float curSteadyTime = curSteadyTimeUs / MS_TO_US;
1344 return curSteadyTime;
1345 }
1346 } // namespace Rosen
1347 } // namespace OHOS
1348