Skip to content

Allow disable report timing in profile build since it takes not-negligible amount of time#113526

Closed
fzyzcjy wants to merge 4 commits intoflutter:masterfrom
fzyzcjy:feat/optional-timing
Closed

Allow disable report timing in profile build since it takes not-negligible amount of time#113526
fzyzcjy wants to merge 4 commits intoflutter:masterfrom
fzyzcjy:feat/optional-timing

Conversation

@fzyzcjy
Copy link
Copy Markdown
Contributor

@fzyzcjy fzyzcjy commented Oct 17, 2022

Flutter does say the time cost is "less than 0.1ms every 1 second to report the timings measured on iPhone6S". However, not every mobile phone is as high-end as iPhone6S. For example, on my testing device (TRT-AL00, indeed not the lowest-end device!), I measured that it takes about 20-30ms per second. Then we have a problem. When having https://github.com/fzyzcjy/flutter_smooth, we know a big janky frame (say, takes 200ms) will never let user really feel janky, but instead user will see the app being 60FPS smooth. However, this is based on the assumption that misc work such as report timings should not block the UI thread for a continuous period of time - which is not true if report timings happens. After the 200ms janky frame, we see about 6ms of report timing. Among with other things such as dispatch touch events, they easily take up more than ~16ms and we get one jank. Then flutter_smooth is no longer smooth due to the jank.

Except for the case of flutter_smooth, IMHO this PR is also useful for normal Flutter users. It takes 2-3% of CPU time, which is not negligible and may be measured. In addition, this is not a critical feature. Surely, when this is disabled, the DevTool will not show the frame ui/rasterizer time at all. However, not everyone needs to read that timing data, since they may either do not open DevTool, or use the tracing timeline instead (which contains more than enough information to know the frame timing data). Therefore, it looks reasonable to at least give users a chance (i.e. a flag) to disable it.

The code is deliberately written by reading a const bool environment variable. Therefore, it has completely zero overhead. I have confirmed that by using compiler explorer before - https://discordapp.com/channels/608014603317936148/608021234516754444/1024141682377236500.

Pre-launch Checklist

  • I read the Contributor Guide and followed the process outlined there for submitting PRs.
  • I read the Tree Hygiene wiki page, which explains my responsibilities.
  • I read and followed the Flutter Style Guide, including Features we expect every widget to implement.
  • I signed the CLA.
  • I listed at least one issue that this PR fixes in the description above.
  • I updated/added relevant documentation (doc comments with ///).
  • I added new tests to check the change I am making, or this PR is test-exempt.
  • All existing and new tests are passing.

If you need help, consider asking for advice on the #hackers-new channel on Discord.

@flutter-dashboard flutter-dashboard bot added the framework flutter/packages/flutter repository. See also f: labels. label Oct 17, 2022
@goderbauer goderbauer self-requested a review October 17, 2022 18:59
Copy link
Copy Markdown
Member

@goderbauer goderbauer left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I find adding this a bit dubios. The environment flag will be really hard to discover. Also, profile mode exists so you can get these kind of performance metrics out of your app. If you don't want that, there's always release mode...

/cc @dnfield @jonahwilliams

Comment on lines +238 to +246
/// Whether to send frame events to DevTool
static bool get _enableProfileFrame {
bool? override;
assert(() {
override = debugOverrideEnableProfileFrame;
return true;
}());
return override ?? const bool.fromEnvironment('FLUTTER_PROFILE_FRAME', defaultValue: true);
}
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This really has no impact in release mode? How did you verify that?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Because they have same assembly :)

https://godbolt.org/z/rs9hhfeMc

image

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I can remove the environment variable, see below.

mixin SchedulerBinding on BindingBase {
/// Override [_enableProfileFrame] in debug mode.
@visibleForTesting
static bool? debugOverrideEnableProfileFrame;
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think we should be exposing this and its also not super-helpful for testing. The test now only checks that this flag works which only exists for the test. It doesn't really test whether the actual env variable is doing the right thing...

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So may I know how Flutter tests existing env variable? Then I can make something similar

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I can remove the environment variable, see below.

@dnfield
Copy link
Copy Markdown
Contributor

dnfield commented Oct 26, 2022

Without this, how do you measure frame timings in profile mode?

@fzyzcjy
Copy link
Copy Markdown
Contributor Author

fzyzcjy commented Oct 26, 2022

@dnfield Without this, how do you measure frame timings in profile mode?

I personally by the timeline data. You know, look at the GPURasterizer::Draw rectangle inside timeline, etc.

p.s. partially related flutter/devtools#4522

@fzyzcjy
Copy link
Copy Markdown
Contributor Author

fzyzcjy commented Oct 26, 2022

@goderbauer I find adding this a bit dubios. The environment flag will be really hard to discover.

Hmm why are other env flags in flutter easy to discover, by adding doc or something else? I can do the same, then this is no problem.

Also, profile mode exists so you can get these kind of performance metrics out of your app.

As mentioned above, these perf metrics are already exposed via the timeline data, such as by looking at GPURasterizer::Draw.

If you don't want that, there's always release mode...

But we need to do profiling to get profile data, don't we :)

@fzyzcjy
Copy link
Copy Markdown
Contributor Author

fzyzcjy commented Oct 26, 2022

Rephrase the problem: We are providing redundant data (i.e. report timing, even if timeline tracing already has the data), and that redundancy is causing measurable speed drop compared with release mode. Then we are biasing the profiling result.

So, if this is not to be merged, maybe we should create another PR to the doc site, with something like: "Please do not believe the speed in profile mode. It will be measureably slower than release mode." But IMHO users will not like that sentence.

@fzyzcjy
Copy link
Copy Markdown
Contributor Author

fzyzcjy commented Oct 27, 2022

Look like I can remove the environment variable.

In Dart, if we have a normal variable that only has one constant value, then the field will be removed. dart-lang/sdk#50287 (comment) "Also AOT compiler is capable of removing unused fields of various kinds (the field is also effectively unused if it always contains the same constant value or is only written into, but never read)."

The experiment confirms this:

https://godbolt.org/z/Thd91YcPj

image

I will update the code shortly.

@fzyzcjy fzyzcjy force-pushed the feat/optional-timing branch from 84357fc to d610158 Compare October 27, 2022 00:19
@dnfield
Copy link
Copy Markdown
Contributor

dnfield commented Oct 27, 2022

@dnfield Without this, how do you measure frame timings in profile mode?

I personally by the timeline data. You know, look at the GPURasterizer::Draw rectangle inside timeline, etc.

p.s. partially related flutter/devtools#4522

This method is significantly cheaper than the timeline.

@fzyzcjy
Copy link
Copy Markdown
Contributor Author

fzyzcjy commented Oct 27, 2022

@dnfield This method is significantly cheaper than the timeline.

I originally thought so. But interestingly, seems no in a few reasons:

  • timeline is usually there (or even cannot be disabled? not find a flag to disable), while report timings is an extra thing
  • timeline makes app slower evenly, while report timings is a big burst. thus, flutter_smooth can handle timline slowness very easily (and still gets 60fps and smooth user feeling), while report timings will cause a jank (because it itself takes some long time and during that time flutter_smooth cannot perform any job to submit extra frames).

For disable tracing: Not see any flag to disable IMHO

flutter run --help | grep trace
    --trace-startup                               Trace application startup, then exit, saving the trace to a file. By default, this will be saved in the "build" directory. If the FLUTTER_TEST_OUTPUTS_DIR environment variable is set, the file will be written there instead.
    --endless-trace-buffer                        Enable tracing to an infinite buffer, instead of a ring buffer. This is useful when recording large traces. To use an endless buffer to record startup traces, combine this with "--trace-startup".
    --trace-systrace                              Enable tracing to the system tracer. This is only useful on platforms where such a tracer is available (Android, iOS, macOS and Fuchsia).
    --trace-skia                                  Enable tracing of Skia code. This is useful when debugging the raster thread (formerly known as the GPU thread). By default, Flutter will not log Skia code, as it introduces significant overhead that may affect recorded performance metrics in a misleading way.
    --[no-]await-first-frame-when-tracing         Whether to wait for the first frame when tracing startup ("--trace-startup"), or just dump the trace as soon as the application is running. The first frame is detected by looking for a Timeline event with the name "Rasterized first useful frame". By default, the widgets library's binding takes care of sending this event.
    --[no-]hot                                    Run with support for hot reloading. Only available for debug mode. Not available with "--trace-startup".

@dnfield
Copy link
Copy Markdown
Contributor

dnfield commented Oct 27, 2022

It'd be really helpful if you could share some measurements (including device/platform/runtime mode).

@fzyzcjy
Copy link
Copy Markdown
Contributor Author

fzyzcjy commented Oct 27, 2022

@dnfield Let me find an old screenshot from my past experiment (https://github.com/fzyzcjy/yplusplus/issues/6124#issuecomment-1272830057)

image
image
image
image

after fix

image
image

@dnfield
Copy link
Copy Markdown
Contributor

dnfield commented Nov 16, 2022

You can use systracing instead of timeline by doing --trace-systrace. That is less expensive than timeline based tracing.

Unfortunately, I'm having trouble from the images telling where the extra time is being spent. I'm also confused why the traces are looking at pointer data packet events when this bug is about frame timings.

I think we should try to look at ways to make the frame timings measurements cheaper on representative hardware rather than disabling them. Timeline adds more overhead on every frame. Maybe you could file an issue with some of your findings?

@dnfield dnfield closed this Nov 16, 2022
@fzyzcjy
Copy link
Copy Markdown
Contributor Author

fzyzcjy commented Nov 16, 2022

Unfortunately, I'm having trouble from the images telling where the extra time is being spent. I'm also confused why the traces are looking at pointer data packet events when this bug is about frame timings.

Ah sorry! I must paste the wrong image here - at the time I wrote the reply I may be thinking about my another PR about pointer events.

I think we should try to look at ways to make the frame timings measurements cheaper on representative hardware rather than disabling them. Timeline adds more overhead on every frame. Maybe you could file an issue with some of your findings?

Sure. I will do that soon (have no time now so possibly within a few days)

@fzyzcjy
Copy link
Copy Markdown
Contributor Author

fzyzcjy commented Nov 23, 2022

As discussed earlier in Discord, maybe I will focus on the main part of flutter_smooth now (quite busy recently), and restart this PR after the critical PRs of flutter_smooth has been merged.

(For future readers of this thread: Recent progress of the critical PRs are not only in flutter repositories and discord, but also somewhere such as fzyzcjy/flutter_smooth#173)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

framework flutter/packages/flutter repository. See also f: labels.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants