Skip to content

Commit 751cdaa

Browse files
fix: delayed frames summation
1 parent d84e96f commit 751cdaa

File tree

6 files changed

+74
-858
lines changed

6 files changed

+74
-858
lines changed

lib/src/modules/apm.dart

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -392,10 +392,10 @@ class APM {
392392
///
393393
/// Returns:
394394
/// A Future<void> is being returned.
395-
static Future<void> setScreenRenderEnabled(bool isEnabled) {
396-
return _host.setScreenRenderEnabled(isEnabled).then((_) {
395+
static Future<void> setScreenRenderEnabled(bool isEnabled) async {
396+
return _host.setScreenRenderEnabled(isEnabled).then((_) async {
397397
if (isEnabled) {
398-
InstabugScreenRenderManager.I.init(WidgetsBinding.instance);
398+
await InstabugScreenRenderManager.I.init(WidgetsBinding.instance);
399399
} else {
400400
InstabugScreenRenderManager.I.dispose();
401401
}

lib/src/modules/instabug.dart

Lines changed: 0 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -23,9 +23,7 @@ import 'package:instabug_flutter/src/utils/feature_flags_manager.dart';
2323
import 'package:instabug_flutter/src/utils/ibg_build_info.dart';
2424
import 'package:instabug_flutter/src/utils/instabug_logger.dart';
2525
import 'package:instabug_flutter/src/utils/screen_name_masker.dart';
26-
import 'package:instabug_flutter/src/utils/screen_rendering/instabug_screen_render_manager.dart';
2726
import 'package:instabug_flutter/src/utils/screen_rendering/instabug_widget_binding_observer.dart';
28-
import 'package:instabug_flutter/src/utils/ui_trace/flags_config.dart';
2927
import 'package:meta/meta.dart';
3028

3129
enum InvocationEvent {
@@ -198,10 +196,6 @@ class Instabug {
198196
debugLogsLevel.toString(),
199197
);
200198

201-
if (await FlagsConfig.screenRendering.isEnabled()) {
202-
InstabugScreenRenderManager.I.init(WidgetsBinding.instance);
203-
}
204-
205199
return FeatureFlagsManager().registerW3CFlagsListener();
206200
}
207201

lib/src/utils/instabug_navigator_observer.dart

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -66,18 +66,18 @@ class InstabugNavigatorObserver extends NavigatorObserver {
6666
}
6767

6868
FutureOr<void> _startScreenRenderCollector(int? uiTraceId) async {
69-
final isScreenRender = await FlagsConfig.screenRendering.isEnabled();
70-
_checkForScreenRenderInitialization(isScreenRender);
71-
if (uiTraceId != null && isScreenRender) {
69+
final isScreenRenderEnabled = await FlagsConfig.screenRendering.isEnabled();
70+
await _checkForScreenRenderInitialization(isScreenRenderEnabled);
71+
if (uiTraceId != null && isScreenRenderEnabled) {
7272
InstabugScreenRenderManager.I
7373
.startScreenRenderCollectorForTraceId(uiTraceId);
7474
}
7575
}
7676

77-
void _checkForScreenRenderInitialization(bool isScreenRender) {
77+
Future<void> _checkForScreenRenderInitialization(bool isScreenRender) async {
7878
if (isScreenRender) {
7979
if (!InstabugScreenRenderManager.I.screenRenderEnabled) {
80-
InstabugScreenRenderManager.I.init(WidgetsBinding.instance);
80+
await InstabugScreenRenderManager.I.init(WidgetsBinding.instance);
8181
}
8282
} else {
8383
if (InstabugScreenRenderManager.I.screenRenderEnabled) {

lib/src/utils/screen_rendering/instabug_screen_render_manager.dart

Lines changed: 60 additions & 58 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,5 @@
11
import 'dart:async';
2+
import 'dart:developer' show log;
23
import 'dart:ui';
34

45
import 'package:flutter/widgets.dart';
@@ -18,14 +19,14 @@ enum UiTraceType {
1819
@internal
1920
class InstabugScreenRenderManager {
2021
WidgetsBinding? _widgetsBinding;
21-
late int _buildTime;
22-
late int _rasterTime;
23-
late int _totalTime;
22+
late int _buildTimeMs;
23+
late int _rasterTimeMs;
24+
late int _totalTimeMs;
2425
late TimingsCallback _timingsCallback;
2526
late InstabugScreenRenderData _screenRenderForAutoUiTrace;
2627
late InstabugScreenRenderData _screenRenderForCustomUiTrace;
27-
int _slowFramesTotalDurationMs = 0;
28-
int _frozenFramesTotalDurationMs = 0;
28+
int _slowFramesTotalDurationMicro = 0;
29+
int _frozenFramesTotalDurationMicro = 0;
2930
int? _epochOffset;
3031
bool _isTimingsListenerAttached = false;
3132
bool screenRenderEnabled = false;
@@ -42,7 +43,7 @@ class InstabugScreenRenderManager {
4243
/// Default frozen frame threshold in milliseconds (700ms)
4344
final _frozenFrameThresholdMs = 700;
4445

45-
final _microsecondsPerMillisecond = 1000;
46+
// final _microsecondsPerMillisecond = 1000;
4647

4748
InstabugScreenRenderManager._();
4849

@@ -75,46 +76,45 @@ class InstabugScreenRenderManager {
7576
}
7677
}
7778

78-
/// analyze frame data in order to detect slow/frozen frame.
79+
/// Analyze frame data to detect slow or frozen frames efficiently.
7980
@visibleForTesting
8081
void analyzeFrameTiming(FrameTiming frameTiming) {
81-
_buildTime = frameTiming.buildDuration.inMilliseconds;
82-
_rasterTime = frameTiming.rasterDuration.inMilliseconds;
83-
_totalTime = frameTiming.totalSpan.inMilliseconds;
84-
85-
if (_isUiFrozen) {
86-
_frozenFramesTotalDurationMs += _buildTime;
87-
} else if (_isRasterFrozen) {
88-
_frozenFramesTotalDurationMs += _rasterTime;
89-
} else if (_isTotalTimeLarge) {
90-
_frozenFramesTotalDurationMs += _totalTime;
91-
}
92-
if (_isUiSlow) {
93-
_slowFramesTotalDurationMs += _buildTime;
94-
} else if (_isRasterSlow) {
95-
_slowFramesTotalDurationMs += _rasterTime;
96-
}
82+
_buildTimeMs = frameTiming.buildDuration.inMilliseconds;
83+
_rasterTimeMs = frameTiming.rasterDuration.inMilliseconds;
84+
_totalTimeMs = frameTiming.totalSpan.inMilliseconds;
9785

98-
if (_isUiDelayed) {
86+
if (_isTotalTimeLarge) {
87+
final micros = frameTiming.totalSpan.inMicroseconds;
88+
_frozenFramesTotalDurationMicro += micros;
9989
_onDelayedFrameDetected(
10090
_getMicrosecondsSinceEpoch(
101-
frameTiming.timestampInMicroseconds(FramePhase.buildStart),
91+
frameTiming.timestampInMicroseconds(FramePhase.vsyncStart),
10292
),
103-
_buildTime,
93+
micros,
10494
);
105-
} else if (_isRasterDelayed) {
95+
return;
96+
}
97+
98+
if (_isUiSlow) {
99+
final micros = frameTiming.buildDuration.inMicroseconds;
100+
_slowFramesTotalDurationMicro += micros;
106101
_onDelayedFrameDetected(
107102
_getMicrosecondsSinceEpoch(
108-
frameTiming.timestampInMicroseconds(FramePhase.rasterStart),
103+
frameTiming.timestampInMicroseconds(FramePhase.buildStart),
109104
),
110-
_rasterTime,
105+
micros,
111106
);
112-
} else if (_isTotalTimeLarge) {
107+
return;
108+
}
109+
110+
if (_isRasterSlow) {
111+
final micros = frameTiming.rasterDuration.inMicroseconds;
112+
_slowFramesTotalDurationMicro += micros;
113113
_onDelayedFrameDetected(
114114
_getMicrosecondsSinceEpoch(
115-
frameTiming.timestampInMicroseconds(FramePhase.vsyncStart),
115+
frameTiming.timestampInMicroseconds(FramePhase.rasterStart),
116116
),
117-
_totalTime,
117+
micros,
118118
);
119119
}
120120
}
@@ -215,23 +215,15 @@ class InstabugScreenRenderManager {
215215

216216
/// --------------------------- private methods ---------------------
217217
218-
bool get _isUiDelayed => _isUiSlow || _isUiFrozen;
219-
220-
bool get _isRasterDelayed => _isRasterSlow || _isRasterFrozen;
221-
222218
bool get _isUiSlow =>
223-
_buildTime > _slowFrameThresholdMs &&
224-
_buildTime < _frozenFrameThresholdMs;
219+
_buildTimeMs > _slowFrameThresholdMs &&
220+
_buildTimeMs < _frozenFrameThresholdMs;
225221

226222
bool get _isRasterSlow =>
227-
_rasterTime > _slowFrameThresholdMs &&
228-
_rasterTime < _frozenFrameThresholdMs;
223+
_rasterTimeMs > _slowFrameThresholdMs &&
224+
_rasterTimeMs < _frozenFrameThresholdMs;
229225

230-
bool get _isTotalTimeLarge => _totalTime >= _frozenFrameThresholdMs;
231-
232-
bool get _isUiFrozen => _buildTime >= _frozenFrameThresholdMs;
233-
234-
bool get _isRasterFrozen => _rasterTime >= _frozenFrameThresholdMs;
226+
bool get _isTotalTimeLarge => _totalTimeMs >= _frozenFrameThresholdMs;
235227

236228
/// Calculate the target time for the frame to be drawn in milliseconds based on the device refresh rate.
237229
double _targetMsPerFrame(double displayRefreshRate) =>
@@ -302,18 +294,21 @@ class InstabugScreenRenderManager {
302294

303295
/// Reset the memory cashed data
304296
void _resetCachedFrameData() {
305-
_slowFramesTotalDurationMs = 0;
306-
_frozenFramesTotalDurationMs = 0;
297+
_slowFramesTotalDurationMicro = 0;
298+
_frozenFramesTotalDurationMicro = 0;
307299
_delayedFrames.clear();
308300
}
309301

310302
/// Save Slow/Frozen Frames data
311-
void _onDelayedFrameDetected(int startTime, int durationInMilliseconds) {
303+
void _onDelayedFrameDetected(int startTime, int durationInMicroseconds) {
304+
log(
305+
"${durationInMicroseconds >= 700000 ? "🚨Frozen" : "⚠️Slow"} Frame Detected (startTime: $startTime, duration: $durationInMicroseconds µs)",
306+
name: tag,
307+
);
312308
_delayedFrames.add(
313309
InstabugFrameData(
314310
startTime,
315-
durationInMilliseconds *
316-
_microsecondsPerMillisecond, // Convert duration from milliseconds to microSeconds
311+
durationInMicroseconds,
317312
),
318313
);
319314
}
@@ -325,6 +320,10 @@ class InstabugScreenRenderManager {
325320
InstabugScreenRenderData screenRenderData,
326321
) async {
327322
try {
323+
log(
324+
"reportScreenRenderForCustomUiTrace $screenRenderData",
325+
name: tag,
326+
);
328327
await APM.endScreenRenderForCustomUiTrace(screenRenderData);
329328
return true;
330329
} catch (error, stackTrace) {
@@ -343,7 +342,12 @@ class InstabugScreenRenderManager {
343342
// Save the end time for the running ui trace, it's only needed in Android SDK.
344343
screenRenderData.saveEndTime();
345344

345+
log(
346+
"reportScreenRenderForAutoUiTrace $screenRenderData",
347+
name: tag,
348+
);
346349
await APM.endScreenRenderForAutoUiTrace(screenRenderData);
350+
347351
return true;
348352
} catch (error, stackTrace) {
349353
_logExceptionErrorAndStackTrace(error, stackTrace);
@@ -370,9 +374,9 @@ class InstabugScreenRenderManager {
370374
/// or synced with the native side.
371375
void _updateCustomUiData() {
372376
_screenRenderForCustomUiTrace.slowFramesTotalDurationMicro +=
373-
_slowFramesTotalDurationMs * _microsecondsPerMillisecond;
377+
_slowFramesTotalDurationMicro;
374378
_screenRenderForCustomUiTrace.frozenFramesTotalDurationMicro +=
375-
_frozenFramesTotalDurationMs * _microsecondsPerMillisecond;
379+
_frozenFramesTotalDurationMicro;
376380
_screenRenderForCustomUiTrace.frameData.addAll(_delayedFrames);
377381
}
378382

@@ -385,9 +389,9 @@ class InstabugScreenRenderManager {
385389
/// or synced with the native side.
386390
void _updateAutoUiData() {
387391
_screenRenderForAutoUiTrace.slowFramesTotalDurationMicro +=
388-
_slowFramesTotalDurationMs * _microsecondsPerMillisecond;
392+
_slowFramesTotalDurationMicro;
389393
_screenRenderForAutoUiTrace.frozenFramesTotalDurationMicro +=
390-
_frozenFramesTotalDurationMs * _microsecondsPerMillisecond;
394+
_frozenFramesTotalDurationMicro;
391395
_screenRenderForAutoUiTrace.frameData.addAll(_delayedFrames);
392396
}
393397

@@ -426,9 +430,7 @@ class InstabugScreenRenderManager {
426430
@visibleForTesting
427431
void setFrameData(InstabugScreenRenderData data) {
428432
_delayedFrames.addAll(data.frameData);
429-
_frozenFramesTotalDurationMs =
430-
data.frozenFramesTotalDurationMicro ~/ _microsecondsPerMillisecond;
431-
_slowFramesTotalDurationMs =
432-
data.slowFramesTotalDurationMicro ~/ _microsecondsPerMillisecond;
433+
_frozenFramesTotalDurationMicro = data.frozenFramesTotalDurationMicro;
434+
_slowFramesTotalDurationMicro = data.slowFramesTotalDurationMicro;
433435
}
434436
}

test/utils/screen_render/instabug_screen_render_manager_test.dart

Lines changed: 6 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,7 @@ import 'package:instabug_flutter/src/models/instabug_screen_render_data.dart';
55
import 'package:instabug_flutter/src/utils/screen_rendering/instabug_screen_render_manager.dart';
66
import 'package:mockito/mockito.dart';
77

8-
import 'instabug_screen_render_manager_test_manual_mocks.dart';
8+
import 'instabug_screen_render_manager_test.mocks.dart';
99

1010
void main() {
1111
TestWidgetsFlutterBinding.ensureInitialized();
@@ -380,40 +380,19 @@ void main() {
380380
});
381381

382382
test(
383-
'should detect frozen frame on build thread when durations are greater than or equal 700 ms',
383+
'should detect frozen frame when durations are greater than or equal 700 ms',
384384
() {
385-
const buildDuration = 700;
386-
when(mockFrameTiming.buildDuration)
387-
.thenReturn(const Duration(milliseconds: buildDuration));
388-
manager.startScreenRenderCollectorForTraceId(1); // start new collector
389-
manager.analyzeFrameTiming(mockFrameTiming); // mock frame timing
390-
manager.stopScreenRenderCollector(); // should save data
391-
392-
expect(manager.screenRenderForAutoUiTrace.frameData.length, 1);
393-
expect(
394-
manager.screenRenderForAutoUiTrace.frozenFramesTotalDurationMicro,
395-
buildDuration * 1000,
396-
); // * 1000 to convert from milliseconds to microseconds
397-
expect(
398-
manager.screenRenderForAutoUiTrace.slowFramesTotalDurationMicro,
399-
0,
400-
);
401-
});
402-
403-
test(
404-
'should detect frozen frame on raster thread when durations are greater than or equal 700 ms',
405-
() {
406-
const rasterBuild = 700;
407-
when(mockFrameTiming.buildDuration)
408-
.thenReturn(const Duration(milliseconds: rasterBuild));
385+
const totalTime = 700;
386+
when(mockFrameTiming.totalSpan)
387+
.thenReturn(const Duration(milliseconds: totalTime));
409388
manager.startScreenRenderCollectorForTraceId(1); // start new collector
410389
manager.analyzeFrameTiming(mockFrameTiming); // mock frame timing
411390
manager.stopScreenRenderCollector(); // should save data
412391

413392
expect(manager.screenRenderForAutoUiTrace.frameData.length, 1);
414393
expect(
415394
manager.screenRenderForAutoUiTrace.frozenFramesTotalDurationMicro,
416-
rasterBuild * 1000,
395+
totalTime * 1000,
417396
); // * 1000 to convert from milliseconds to microseconds
418397
expect(
419398
manager.screenRenderForAutoUiTrace.slowFramesTotalDurationMicro,

0 commit comments

Comments
 (0)