Avoid generating VSYNC trace events when tracing to systrace. #16248
Conversation
nichtverstehen
force-pushed
the
master
branch
2 times, most recently
from
bc92c7f to
01a83c6
Compare
|
I was in this code before for a different, but related reason. Currently, the tracing done in our code for VSYNC is implemented to trace our own processing of the frame. If you look at traces on Android and iOS it looks like we start processing immediately after a vsync interval, but that's a fake event because we told it that the vsync started when we got the message. Meanwhile we actually know the real time that the platform vsync interval started because the vsync_waiter reports it to us in the callback, but rather than transfer that information to the tracing code, we at most add a synthetic asynchronous event that shows the gap between when the real platform interval started and when we started doing work. I don't think that visualization helps debugging when viewing the traces. What I'd rather see is that we rely on the "platform" to do the VSYNC reporting and our internal process is always reported under our own event names. That would require the platform-specific vsync_waiter code to log the VSYNC events themselves - and then all of our platforms would match and the code in the callback would not have to worry about where the events came from. If we can do that then the alternating gray/white bars in the trace outputs would always show how our own internal processing matches up with what the hardware/platform is doing and we'd have much deeper insight into our timing - and less complexity in the code. |
flar
left a comment
flar
left a comment
There was a problem hiding this comment.
Would it be more "simplifying" to just expect all vsync callback sources to handle the VSYNC events when they are appropriate? Sources that aren't tied to actual platform/hardware vsync intervals would not generate those events and the code in the callback would only generate events under the private name "FlutterVsync".
(By "simplifying" I don't mean the fix would be necessarily simpler, but the resulting code would involve fewer flags being passed around and fewer work-arounds in the common code.)
|
@nichtverstehen is this still work-in-progress? |
|
I got carried away with some other changes. Will come back to this tomorrow. |
nichtverstehen
force-pushed
the
master
branch
from
01a83c6 to
99bfa2a
Compare
|
Apologies for the delay and then another delay :). Jim, what you are saying makes sense and simplifies the code a lot! Please take another look. Now the common vsync_waiter.cc only ever generates "VsyncProcessCallback" traces (in place of VSYNC) to signify that it is starting the callback on the UI thread. And I added the code to generate VSYNC traces on Android and iOS. Do I need to backfill VSYNC anywhere else? |
|
Oh wow, that is simpler! Do these events generate the gray/white alternating backgrounds that show where the frames are? |
|
(Perhaps include a snapshot of a couple of frames of an app for reference) |
|
So here are traces and screenshots of results. Raw JSONs are shared within @google.com. Android, timeline from devtools (Flutter-only): Android, systrace: CastOS, systrace: CastOS Flutter trace is missing VSYNC highlighting now (as expected). We'll add VSYNC event tracing to our embedder internally. I don't have access to iOS. |
|
Btw, I don't get it why checks show in comments are failing, but checks shown in the checks tab are passing (https://github.com/flutter/engine/pull/16248/checks). I looked at the failures and I can't imagine they could be caused by my commit ("VM snapshot invalid and could not be inferred from settings"). |
flar
left a comment
flar
left a comment
There was a problem hiding this comment.
LGTM, try rerunning the failed tests and see if they succeed.
|
Jim, how do I rerun the test? For me the Retry button https://ci.chromium.org/p/flutter/builders/try/Linux%20Host%20Engine/4392 is disabled. |
You have to click on the login link in the upper right corner to be able to request a rerun. I tried doing that yesterday, but all of the tests still show failing runs from the 24th, so something seems to be off about that. Another option might be to push an innocuous commit which should rerun the tests if you can't get the re-run button to work. |
nichtverstehen
force-pushed
the
master
branch
2 times, most recently
from
1a1e2cd to
9f6bdf8
Compare
Chrome Trace viewer treats events labeled "VSYNC" as special and highlights them (when the "Highlight Vsync" checkbox is enabled). Ideally VSYNC events are generated by the host system at their source. System VSYNC events are indeed present in full-system systraces. Flutter-level traces (as seen in Observatory/Flutter devtools) do not contain the system VSYNC events, so we rely on the engine to generate them (as close to where they would be generated by the system ideally). Currently the common (platform-independent code) generates VSYNC events at the time when the UI thread starts processing a frame. This has two drawbacks: 1. The traces are generated with a delay (we wait for the callback to be have been scheduled on the UI thread instead of tracing as soon as the system notified us. 2. When inspecting system-wide traces we'll have both the system and the Flutter app (or potentially multiple Flutter apps) generate VSYNC events at the same time. This confuses both the developers and the trace viewer. This change moves the VSYNC event generation to the platform-specific embedder implementations: 1. On Android/iOS we always generate the VSYNC event since Android/iOS developers use Flutter tools to debug the apps. 2. On Fuchsia we do not generate VSYNC events since the systraces always contain them. 3. In the Embedder wrapper we don not generate VSYNC events and rely on the actual embedder to do this in a way appropriate for the target system.
4 participants
Chrome Trace viewer treats events labeled "VSYNC" as special and highlights them (when the "Highlight Vsync" checkbox is enabled). This is the only VSYNC reference existing when debugging a single Flutter app through Observatory.
However when tracing to Systrace there is usually a more authoritative system-wide VSYNC event source. So we avoid sending Flutter VSYNC events which make/ debugging multiple applications running in the system at once.