-
Notifications
You must be signed in to change notification settings - Fork 29.7k
Added option for Platform Channel statistics and Timeline events #104531
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Conversation
|
@dnfield right now it prints out a second-by-second summary of the bandwidth and type of platform channels. Do you think we should add timeline events? The nice thing about this is that it should provide little overhead since it avoids system calls. I could optionally add timeline events for:
That would give us 2 of the 3 things we are interested in, round trip time and time spent on the ui thread. It doesn't give us latency between sending and receiving. By putting all the stats on the dart side, it works everywhere but it lacks information about the thread the requests are handled on in the platform side. |
dnfield
left a comment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think this is good.
It'd be really nice to have some timings in here. Timeline events (perhaps behind a debug flag like we do for debugProfileWidgetBuilds or whatever) would probably help.
This won't really give us insight into time spent across threads right? We'd need an engine patch for that?
|
Towards #102189 |
Yea, I'm still trying to think what best to do for that. Do you think 3 different timeline events would be too much?
Nope, just end to end time. |
|
I'd be curious how often the timeline events fire in something like |
Unfortunately we don't have a good way to add timeline events that doesn't severely effect the readability of the code or add runtime cost. I'll see what I can do. |
|
I tried adding timeline events around encoding and decoding and they are so tiny (<0.1ms) I think it's better just looking at that with a profiler. I'll look at round trip times. |
4bd43c1 to
8ecbf49
Compare
|
It looks like this pull request may not have tests. Please make sure to add tests before merging. If you need an exemption to this rule, contact Hixie on the #hackers channel in Chat (don't just cc him here, he won't see it! He's on Discord!). If you are not sure if you need tests, consider this rule of thumb: the purpose of a test is to make sure someone doesn't accidentally revert the fix. Ask yourself, is there anything in your PR that you feel it is important we not accidentally revert back to how it was before your fix? Reviewers: Read the Tree Hygiene page and make sure this patch meets those guidelines before LGTMing. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think this should be in a try/finally block
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
done
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Instead of up and down we should say maybe upBytes since it isn't quite clear what the up and down are?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
done
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think it will be also good to have an example of what will be printed here
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Added more details about what is printed.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This string might be too long for apps that run a lot of platform messages. On android long messages will be truncated. We should probably use debugPrint instead, and I think we won't need the lint ignore as well
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
+1 on debugPrint, but I'm a bit curious about whether printing will be the right thing to do here.
On Android, in a real world application on a real world device, this seems like it'll easily be lost in a lot of logging noise.
One option is to use postEvent so that devtools could pick up the message(s) and present them somewhere. We could also add it to the timeline as an instant event with arguments, which could then be harvested by integration tests (although not by the internal integration test platform...).
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We should probably use debugPrint instead
Done.
On Android, in a real world application on a real world device, this seems like it'll easily be lost in a lot of logging noise.
Android developers just filter their output: adb logcat | grep "flutter:"
One option is to use postEvent so that devtools could pick up the message(s)
Yea I was going to talk to devtools about this to get it on their radar. I think printing is the right thing to do for now since it's low cost while we perfect the output.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This should go in packages/flutter/lib/src/services/debug.dart instead?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yes - along with the appropriate assertions about it being reset if someone sets it in a test.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
done
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In the example in the PR description the codec looks something like:
Instance of 'StandardMethodCodec'
The "Instance of" is probably noise we don't need, can we implement toString on the codec to avoid that?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done
|
This is great and is going to make startup profiling easier without having to patch the framework. One of the use cases for this would be to figure out why the UI thread is sleeping during startup, which is sometimes due to waiting on long running platform messages, that the new |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@kenzieschmoll is there a better way to do this to be able to surface in devtools?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Timeline events are probably the best way to surface this in DevTools, which this PR already accomplishes.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@kenzieschmoll I think at some point it might be worth considering surfacing this in DevTools. So the timeline events are showing the time between sending and receiving a response which is helpful. The stats getting printed out here are the bandwidth of each channel, roughly bytes/sec up and down. I'm not sure how we decide what is a good feature to do for devtools but this is potentially helpful for inspecting plugins. I think we should probably wait to get feedback from customer: money before implementing it into devtools.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We can add a service extension that will modify debugProfilePlatformChannels and expose this as a user-controlled toggle in the DevTools performance page. Maybe we should consider turning this flag on by default in debug mode.
Are all the stats you mentioned included in the timeline event args?
There was a problem hiding this comment.
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 want to turn it on by default because we have no idea how much overhead it will create because the overhead is a function of what plugins are being used.
I didn't attach bandwidth information to the timeline events. I'm not sure if that is helpful compared to seeing the summary for a time range. We don't want people to get out their calculators and start clicking event my event hehe.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Ah I see. If the information printed to console ends up being useful, we could send it to devtools via postEvent, and then we can listen and surface it somewhere. We may want to verify its usefulness first though before we plumb this through. The prints will already show up in the DevTools logging view with the current impl.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Nit: extra space at . "Up"
It's also upbytes / downBytes now?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Nit: extra space at . "Up"
done
It's also upbytes / downBytes now?
yea
When
debugProfilePlatformChannelsis true there will be Timeline events representing the time between sending a message and getting the result from the host platform. Also, every second there will be bandwidth information printed to the console for the platform channels.issue: #102189
example log:
Pre-launch Checklist
///).If you need help, consider asking for advice on the #hackers-new channel on Discord.