Repository navigation
Avoid calling Dart_New in engine - it's slow. #50997
Description
Devicelab cull_opacity_perf__timeline_summary test failing with 30 second timeout exception.
2020-02-18T15:06:37.185691: stderr: [ +37 ms] VMServiceFlutterDriver: Waiting for service extension
2020-02-18T15:06:37.354258: stderr: [ +168 ms] VMServiceFlutterDriver: Connected to Flutter application.
2020-02-18T15:07:06.827425: stdout: [+29473 ms] 00:30 �[32m+0�[0m�[31m -1�[0m: cull_opacity_perf �[1m�[31m[E]�[0m�[0m
2020-02-18T15:07:06.829451: stdout: [ +2 ms] TimeoutException after 0:00:30.000000: Test timed out after 30 seconds. See https://pub.dev/packages/test#timeouts
cull_opacity_perf__timeline_summary_bcacd06_2.log
Failing on engine roll bcacd06
Activity
goderbauer commentedon Feb 19, 2020
/cc @jason-simmons I believe you're the engine roll sherif.
jmagman commentedon Feb 19, 2020
@jason-simmons says:
dnfield commentedon Feb 19, 2020
Right now working theory is that new dart API is logging more timeline events, making the timeline about 50% bigger, which is taking about 33% logger to download, and is just enough to make our timeout too short ot download the timeline.
The bigger problem is that this also results in a 20% drop in performance on the benchmark. @jason-simmons @rmacnak-google and @bkonyi are going to sync up on that further.
dnfield commentedon Feb 19, 2020
We may want to consider reverting the upstream dart change that removed the API (dart-lang/sdk@082aece) and then revert flutter-team-archive/engine@4941ff7 unless we can figure out a way to make it not regress performance so much more quickly.
[-]cull_opacity_perf__timeline_summary timeout failure[/-][+]cull_opacity_perf__timeline_summary regression and timeout failure[/+]jason-simmons commentedon Feb 19, 2020
The additional timeline events are coming from the
Dart_NewStringFromCStringcall added to provide the name of the default private constructor.Tried patching
DartWrappable::CreateDartWrapperto create the string once and use a persistent handle afterward. With that change the timeline size and thegetVMTimelinelatency now match what they were before flutter-team-archive/engine@4941ff7.However, the
average_frame_build_time_millismetric for thecull_opacitybenchmark is still around 20% higher forDart_Newcompared to the oldDart_AllocateWithNativeFieldsAPI.dnfield commentedon Feb 19, 2020
The cull opacity benchmark creates tons of objects every single frame.
It seems like there's just now a lot more overhead from calling constructors on those objects where we used to not.
It'd be interesting to see if we can figure out which constructors we're calling and if some of them are doing some unnecessary work - it'd also be nice if there was just some Dart API to avoid doing the double hop from native -> dart -> native -> dart to construct an object and initialize fields. It seems more likely to me that the double hop is what is hurting performance here rather than that some randomc onstructor is doing tons of work.
13 remaining items
chinmaygarde commentedon Feb 20, 2020
Just for this benchmark or generally?
dnfield commentedon Feb 20, 2020
Generally. This benchmark was particularly affected, but we should avoid replacing the current fast path with a slow path - and there's no good way to refactor the current path AFAICT - unless there's some magic the VM can do to recognize this constructor is empty and the object has no fields to initialize and avoid doing any expensive lookups more than once.
dnfield commentedon Feb 20, 2020
Basically, we hit the path we're touching a lot on every frame, to pretty much do anything.
chinmaygarde commentedon Feb 20, 2020
I meant go one step further and also make
Dart_Newunusable as there is no fast way of making it work. I could still bypass tonic and write code that usesDart_Newdirectly if you removed only CreateDartWrapper.jason-simmons commentedon Feb 20, 2020
Tried running the cull_opacity benchmark with the
dnfield/picture_dartbranch on a Moto G4. Thebuild_time_millismetrics were roughly equal to the current master that usesDart_AllocateWithNativeFields.dnfield commentedon Feb 20, 2020
flutter-team-archive/engine#16713 should cover enough of the regression to be landable again. I'll break out other parts of my larger patch into smaller PRs, since some stuff is requiring a bigger refactor (images and paragraph in particular).
[-]Engine/Tonic/Dart wants a fast path for allocating dart objects with empty constructor bodies[/-][+]Avoid calling Dart_New in engine - it's slow.[/+]dnfield commentedon Feb 20, 2020
Repurposing this bug again - VM may be able to optimize Dart_New, but it seems like we have another work around available that would be preferable. Rather than opening a new bug, keep this one for the context.
jmagman commentedon Feb 20, 2020
cull_opacity_perf failing again on 0b5667a
bkonyi commentedon Feb 20, 2020
That's a roll that only contains changes ~2 day old and doesn't contain the reverts.
jmagman commentedon Feb 20, 2020
Looks like this issue was repurposed away from the cull_opacity_perf__timeline_summary test failure. I'll file a new issue.
#51148
github-actions commentedon Aug 22, 2021
This thread has been automatically locked since there has not been any recent activity after it was closed. If you are still experiencing a similar issue, please open a new bug, including the output of
flutter doctor -vand a minimal reproduction of the issue.