Engine startup event timed after VM initializes #35713

yaakovschectman · 2022-08-25T20:31:22Z

The Flutter Engine uses a function exposed by the Dart SDK to get a timestamp in microseconds. However, depending on the platform, this Dart_TimelineGetMicros function can return timestamps in different forms depending on whether or not Dart::Initialize has yet been called. On Windows, when the Dart VM is not yet initialized, such as when setting the engine_start_timestamp, the timestamp is given in microseconds since the Unix Epoch. After the Dart VM has been initialized, such as when the time is queried for all later timeline events, the timetsamp on Windows is in QPC, which, according to Microsoft's documentation, cannot be sycned to any standard format such as UTC or Epoch time. This means that the starting timestamp for the FlutterEngineMainEnter timeline event previously was in a different format than the timestamp of all later events. By changing the timestamp0 of this event to a timestamp obtained after initializing the Dart VM, all events now have consistent timestamp forms.

As far as I can tell, this FlutterEngineMainEnter event that is affected is only used by the tracing code in Flutter used in startup tests to calculate the time between the engine startup and the first frame being built. Previously, this value would be reported as roughly -16 quadrillion on Windows because of this inconsistency.

Addresses flutter/flutter#109859 in Flutter.

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 and the C++, Objective-C, Java style guides.
I listed at least one issue that this PR fixes in the description above.
I added new tests to check the change I am making or feature I am adding, or Hixie said the PR is test-exempt. See testing the engine for instructions on
writing and running engine tests.
I updated/added relevant documentation (doc comments with ///).
I signed the CLA.
All existing and new tests are passing.

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

runtime/dart_vm.cc

zanderso · 2022-08-25T22:21:49Z

runtime/dart_vm.cc

-          nullptr                                    // argument_values
+      int64_t micros = Dart_TimelineGetMicros();
+      Dart_TimelineEvent("FlutterEngineMainEnter",     // label
+                         micros,                       // timestamp0


How does this affect the benchmark value reported for non-Windows?

Does the comment above need to be adjusted?

It will shift the earliest timestamp forward by the time taken to initialize the VM. This seems a preferable outcome to having inconsistent and sometimes meaningless timestamps. The comment should be changed as it is not using a duration any more.

@dnfield Will this affect the startup metrics used by customer: money?

I don't think so but @jiahaog would know for sure

This will affect 1P startup metrics that read from the observatory (in profile mode), such as from Flutter driver. We read only the ts value of this metric, which is the timestamp0 parameter.

I don't think this is a blocker though, as customers can rebaseline their tests. We have also been directing customers to move away from such metrics to more general Android ones, and customer: money specifically does not use this metric.

Do you then see a need for further changes to this PR?

No, this should be fine. Thanks :)

chinmaygarde · 2022-08-26T19:18:11Z

runtime/dart_vm.cc

+    // Use an instant event because the call to Dart_TimelineGetMicros
+    // may behave differently before and after the Dart VM is initialized.
+    // As this call is immediately after initialization of the Dart VM,
+    // we are interested in only one timestamp.
    if (settings_.engine_start_timestamp.count()) {


Are there any users of engine_start_timestamp? If not, can we get rid of them. Why can't the caller specify the startup time instead?

As far as I can find, this was the only user. I am unsure what you mean by that. Caller to where?

Internal codesearch suggests this is the only usage.

To make sure we are clear, is your suggestion to remove the engine_start_timestamp now and continue with the effort of this PR?

If no one is using the field in the settings struct, I suggest removing it altogether. If someone is using it, I suggest setting the field in the embedder you are working on. As it stands, this field will go unused and existing users (if any) will break.

It is not being used otherwise but our Flutter Engine, but should we make any consideration for 3rd party forks or embedders that we do not know about but might use it? settings_ is a private field so I would not expect there to be.

We promise stability to third-party embedders via the embedder API. Since Settings is non-public API, we'd simply need to make sure none of our own embedders that bypass the embedder API (e.g. iOS/Android/Fuchsia and internal embedders) are broken. If no one's using it (which seems to be the case) then you can safely delete it.

The Android shell assigns to this value but never uses it. Its only use is in generating this event

cbracken

lgtm.

cbracken · 2022-08-30T17:45:08Z

My guess is we'll need to rebaseline some benchmarks after this so it would be a good idea to reach out to the framework gardener and engine sheriff proactively to let them know.

…gine#35713)

…110697) * d782c3303 [web] roll CanvasKit to 0.36.1 (flutter/engine#35747) * 300592bc8 allows mallocmapping copies of size zero (flutter/engine#35803) * 61e4c0715 Generate mac os framework with a global generator. (flutter/engine#35673) * 7a03a54a8 Roll Skia from 545e45ab4d5d to 27a2eeacd330 (11 revisions) (flutter/engine#35805) * 89909d966 Fix DartPerformanceMode enum mismatch (flutter/engine#35806) * ead134880 Queue all semantic nodes & actions before completing batch (flutter/engine#35792) * adec6edb0 Run clang-tidy and Mac Unopt on Xcode beta (flutter/engine#35793) * eb6e2e08c Roll Skia from 27a2eeacd330 to 18b36bd2e2a3 (1 revision) (flutter/engine#35807) * e74352c7f Remove extract_far.dart (flutter/engine#35801) * 5ee7b3816 Test cover 'toImage'. (flutter/engine#35791) * 8ed1e6ca7 Roll Skia from 18b36bd2e2a3 to 7c67a21eec59 (3 revisions) (flutter/engine#35810) * cc2a32332 Roll Dart SDK from 9faec45da06c to 7e5a69f6b25f (1 revision) (flutter/engine#35811) * c2a2a5679 Roll Fuchsia Linux SDK from NwG1XTWHxB9R3XcU5... to usGLIrlCJW1C1yaF1... (flutter/engine#35812) * 8ab3b8f5a Migrate testing/symbols to null safety (flutter/engine#35809) * 7e27b923b Roll Skia from 7c67a21eec59 to 3abad1ab16cc (1 revision) (flutter/engine#35816) * 4cb5be089 [web] remove references to IE11 and old Edge; treat Samsung browser as Blink (flutter/engine#35205) * 5154b8ac0 Roll Fuchsia Mac SDK from 4GZkuoQmvVanO84uA... to V_dBCcwGfOqJkrG9b... (flutter/engine#35817) * b5a5a0dc7 Roll Dart SDK from 7e5a69f6b25f to 5a2737b71877 (1 revision) (flutter/engine#35818) * e11457362 [dart:ui] Adds a reusable FragmentShader (flutter/engine#35253) * 26d6bcfd6 Roll Skia from 3abad1ab16cc to a7829f6da292 (1 revision) (flutter/engine#35819) * 6c9f6f5b8 Roll Skia from a7829f6da292 to 83b5d7ae4bca (2 revisions) (flutter/engine#35821) * 169181f8d Make shader mask layer code builder aware (flutter/engine#35622) * 06925ed06 Roll Fuchsia Linux SDK from usGLIrlCJW1C1yaF1... to 5YEIlndU4ncjOl9I_... (flutter/engine#35824) * 7a40a0a26 Roll Skia from 83b5d7ae4bca to e4a2061eb1fc (1 revision) (flutter/engine#35826) * 43ee40e31 Engine startup event timed after VM initializes (flutter/engine#35713) * 9eb524bad Roll Fuchsia Mac SDK from V_dBCcwGfOqJkrG9b... to sgXD5SyRPOxGjWV4q... (flutter/engine#35829) * cfdc83ad6 Roll Skia from e4a2061eb1fc to 34df0f94c849 (1 revision) (flutter/engine#35828) * 90d65fa5f fix null access for CkParagraph.dispose (flutter/engine#35815) * ef039c197 Update the API check script for the latest Dart analyzer APIs (flutter/engine#35831) * c3c872776 Revert "[web] roll CanvasKit to 0.36.1 (#35747)" (flutter/engine#35837) * db97b55d0 Roll Skia from 34df0f94c849 to e0b87738eca7 (5 revisions) (flutter/engine#35832) * f69e0ccc3 add enterkeyhint property to web textfields (flutter/engine#35411) * 54a1b59c9 Add a comment in the scenario app to meet the latest analyzer requirements (flutter/engine#35838) * d993e0d55 Revert "[dart:ui] Adds a reusable FragmentShader (#35253)" (flutter/engine#35843)

Engine startup event timed after VM initializes

ac334e5

yaakovschectman requested review from cbracken, loic-sharma, zanderso and a-wallen August 25, 2022 20:31

yaakovschectman self-assigned this Aug 25, 2022

cbracken requested a review from chinmaygarde August 25, 2022 20:57

a-wallen reviewed Aug 25, 2022

View reviewed changes

runtime/dart_vm.cc Outdated Show resolved Hide resolved

Formatting

e2d0691

yaakovschectman marked this pull request as ready for review August 25, 2022 21:02

zanderso reviewed Aug 25, 2022

View reviewed changes

Update FlutterEngineMainEnter event comment

a4f0dc8

chinmaygarde reviewed Aug 26, 2022

View reviewed changes

yaakovschectman added 2 commits August 30, 2022 09:21

Remove engine_start_time

a11e0a4

Remove unused variable

f53100c

cbracken approved these changes Aug 30, 2022

View reviewed changes

loic-sharma approved these changes Aug 30, 2022

View reviewed changes

yaakovschectman merged commit 43ee40e into flutter:main Aug 31, 2022

engine-flutter-autoroll mentioned this pull request Aug 31, 2022

Roll Flutter Engine from 0ef08a85252a to db97b55d0457 (31 revisions) flutter/flutter#110690

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/flutter that referenced this pull request Aug 31, 2022

43ee40e31 Engine startup event timed after VM initializes (flutter/en…

cf5dd1f

…gine#35713)

engine-flutter-autoroll mentioned this pull request Aug 31, 2022

Roll Flutter Engine from 0ef08a85252a to f69e0ccc3ef8 (32 revisions) flutter/flutter#110691

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/flutter that referenced this pull request Aug 31, 2022

43ee40e31 Engine startup event timed after VM initializes (flutter/en…

145cc2f

…gine#35713)

engine-flutter-autoroll mentioned this pull request Aug 31, 2022

Roll Flutter Engine from 0ef08a85252a to 54a1b59c9a55 (33 revisions) flutter/flutter#110695

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/flutter that referenced this pull request Aug 31, 2022

43ee40e31 Engine startup event timed after VM initializes (flutter/en…

6539753

…gine#35713)

engine-flutter-autoroll mentioned this pull request Aug 31, 2022

Roll Flutter Engine from 0ef08a85252a to d993e0d55fc6 (34 revisions) flutter/flutter#110697

Merged

engine-flutter-autoroll added a commit to engine-flutter-autoroll/flutter that referenced this pull request Aug 31, 2022

43ee40e31 Engine startup event timed after VM initializes (flutter/en…

77818dc

…gine#35713)

yaakovschectman mentioned this pull request Sep 1, 2022

Bogus data reported to SkiaPerf for complex_layout_win_desktop__start_up flutter/flutter#109859

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Engine startup event timed after VM initializes #35713

Engine startup event timed after VM initializes #35713

yaakovschectman commented Aug 25, 2022 •

edited by cbracken

Loading

zanderso Aug 25, 2022

yaakovschectman Aug 26, 2022

zanderso Aug 26, 2022

dnfield Aug 26, 2022

jiahaog Aug 29, 2022

yaakovschectman Aug 30, 2022

jiahaog Aug 31, 2022

chinmaygarde Aug 26, 2022

yaakovschectman Aug 26, 2022

dnfield Aug 26, 2022

yaakovschectman Aug 26, 2022

chinmaygarde Aug 26, 2022

yaakovschectman Aug 26, 2022

cbracken Aug 27, 2022 •

edited

Loading

yaakovschectman Aug 30, 2022

cbracken left a comment

cbracken commented Aug 30, 2022

Engine startup event timed after VM initializes #35713

Engine startup event timed after VM initializes #35713

Conversation

yaakovschectman commented Aug 25, 2022 • edited by cbracken Loading

Pre-launch Checklist

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

cbracken Aug 27, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

cbracken left a comment

Choose a reason for hiding this comment

cbracken commented Aug 30, 2022

yaakovschectman commented Aug 25, 2022 •

edited by cbracken

Loading

cbracken Aug 27, 2022 •

edited

Loading