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