Fix Network tab not capturing requests after hot restart and clear#9856
Fix Network tab not capturing requests after hot restart and clear#9856muhammadkamel wants to merge 8 commits into
Conversation
Re-enable HTTP logging and socket profiling when new isolates are spawned, reset clear timestamps using the VM timeline, and keep the search field enabled while recording.
|
Thanks for your pull request! It looks like this may be your first contribution to a Google open source project. Before we can look at your pull request, you'll need to sign a Contributor License Agreement (CLA). View this failed invocation of the CLA check for more information. For the most up to date status, view the checks section at the bottom of the pull request. |
There was a problem hiding this comment.
Code Review
This pull request addresses issues in the Network profiler where capturing stopped after a hot restart or after clearing recorded data, and introduces an onIsolateCreated stream to detect new isolates. The review feedback highlights a regression where the search field is disabled when recording is paused (even if requests exist), and suggests wrapping asynchronous VM service calls in error-handling blocks to prevent unhandled RPCErrors.
| _, | ||
| ) async { | ||
| if (_recordingNotifier.value) { | ||
| await _enableNetworkTrafficRecordingOnAllIsolates(); |
There was a problem hiding this comment.
[CONCERN] Wrap the call to _enableNetworkTrafficRecordingOnAllIsolates() in allowedError to safely handle any potential RPCErrors that might occur if the newly created isolate is quickly destroyed or if the connection is lost during the asynchronous operation.
| await _enableNetworkTrafficRecordingOnAllIsolates(); | |
| await allowedError(_enableNetworkTrafficRecordingOnAllIsolates()); |
References
- Categorize Severity: Prefix every comment with a severity:
[CONCERN]for robustness/maintainability issues. (link)
19e96b7 to
043132a
Compare
4a1a518 to
a082ddb
Compare
Keep search enabled when paused with visible requests, handle RPC errors during clear, and wrap isolate profiling re-enable in allowedError.
74fc05b to
7d34604
Compare
srawlins
left a comment
There was a problem hiding this comment.
Love this; mostly nit comments.
…k tests for clarity. Adjusted start times in various test cases and improved code readability in the HotRestartNetworkVmService class.
|
Hi @srawlins Could you please take another look now. |
srawlins
left a comment
There was a problem hiding this comment.
Lovely! Thanks this is a huge help!
You're welcome 🤗 |
|
So sorry for the delay; just went through a release cycle and you'll need to resolve conflicts. @kenzieschmoll would you mind giving this PR a once over? Thanks! |
|
/gemini review |
There was a problem hiding this comment.
Code Review
This pull request addresses issues in the Network profiler where HTTP request capturing would stop after a hot restart or after clearing recorded data. It introduces an onIsolateCreated stream to detect new isolates and re-enable recording, updates the clear data logic, and adds comprehensive tests. The review feedback highlights a critical syntax error in network_profiler_test.dart due to a missing closing block, and a clock mismatch bug in NetworkService.clearData() where VM timeline microseconds are incorrectly used instead of wall-clock microseconds for HTTP refresh timestamps. Corresponding updates to the tests and fake VM service are recommended to address this clock mismatch.
| await clearTimeouts(tester); | ||
| 'search field stays enabled after clearing', | ||
| windowSize, | ||
| (WidgetTester tester) async { |
There was a problem hiding this comment.
[MUST-FIX] There is a syntax error in this test file. The closing block }, and ); for the test 'search field stays enabled when recording is paused with requests' is missing, causing the next test's description to be parsed as part of the statement, which results in a compilation failure.
await clearTimeouts(tester);
},
);
testWidgetsWithWindowSize(
'search field stays enabled after clearing',
windowSize,
(WidgetTester tester) async {| try { | ||
| final timestamp = (await service.getVMTimelineMicros()).timestamp!; | ||
| networkController.lastSocketDataRefreshMicros = timestamp; | ||
| await service.forEachIsolate((isolate) async { | ||
| lastHttpDataRefreshTimePerIsolate[isolate.id!] = timestamp; | ||
| }); |
There was a problem hiding this comment.
[MUST-FIX] There is a clock mismatch bug here. lastHttpDataRefreshTimePerIsolate tracks timestamps in wall-clock microseconds since epoch (as seen in updateLastHttpDataRefreshTime and _refreshHttpProfile). However, getVMTimelineMicros() returns monotonic VM timeline microseconds, which is completely different from wall-clock time on real devices.
Setting lastHttpDataRefreshTimePerIsolate to the VM timeline timestamp on clear will cause subsequent HTTP profile requests to use a 1970-era timestamp for updatedSince, resulting in all historical HTTP requests being fetched again on every poll after a clear.
You should use DateTime.now().microsecondsSinceEpoch for the HTTP refresh timestamps, while keeping the VM timeline timestamp for lastSocketDataRefreshMicros.
| try { | |
| final timestamp = (await service.getVMTimelineMicros()).timestamp!; | |
| networkController.lastSocketDataRefreshMicros = timestamp; | |
| await service.forEachIsolate((isolate) async { | |
| lastHttpDataRefreshTimePerIsolate[isolate.id!] = timestamp; | |
| }); | |
| try { | |
| final timestamp = (await service.getVMTimelineMicros()).timestamp!; | |
| networkController.lastSocketDataRefreshMicros = timestamp; | |
| final wallClockTimestamp = DateTime.now().microsecondsSinceEpoch; | |
| await service.forEachIsolate((isolate) async { | |
| lastHttpDataRefreshTimePerIsolate[isolate.id!] = wallClockTimestamp; | |
| }); |
| test( | ||
| 'resets HTTP refresh timestamps to the VM timeline on clear', | ||
| () async { | ||
| final isolateId = vmService.currentIsolateId; | ||
| final controller = await initNetworkLifecycleController( | ||
| vmService: vmService, | ||
| fakeServiceConnection: fakeServiceConnection, | ||
| ); | ||
| await controller.networkService.refreshNetworkData(); | ||
|
|
||
| controller | ||
| .networkService | ||
| .lastHttpDataRefreshTimePerIsolate[isolateId] = | ||
| 500_000; | ||
|
|
||
| await controller.clear(); | ||
|
|
||
| final timelineMicros = | ||
| (await vmService.getVMTimelineMicros()).timestamp!; | ||
| expect( | ||
| controller | ||
| .networkService | ||
| .lastHttpDataRefreshTimePerIsolate[isolateId], | ||
| timelineMicros, | ||
| ); | ||
| }, |
There was a problem hiding this comment.
[CONCERN] This test asserts the incorrect behavior of resetting the HTTP refresh timestamps to the VM timeline instead of the wall-clock time. Once NetworkService.clearData() is corrected to use DateTime.now().microsecondsSinceEpoch, this test should be updated to verify that the timestamp is reset to the wall-clock time.
test(
'resets HTTP refresh timestamps to the wall-clock time on clear',
() async {
final isolateId = vmService.currentIsolateId;
final controller = await initNetworkLifecycleController(
vmService: vmService,
fakeServiceConnection: fakeServiceConnection,
);
await controller.networkService.refreshNetworkData();
controller
.networkService
.lastHttpDataRefreshTimePerIsolate[isolateId] =
500_000;
final beforeClear = DateTime.now().microsecondsSinceEpoch;
await controller.clear();
final afterClear = DateTime.now().microsecondsSinceEpoch;
final refreshTime = controller
.networkService
.lastHttpDataRefreshTimePerIsolate[isolateId]!;
expect(refreshTime, greaterThanOrEqualTo(beforeClear));
expect(refreshTime, lessThanOrEqualTo(afterClear));
},| if (!(_httpLoggingEnabled[isolateId] ?? false)) { | ||
| return HttpProfile( | ||
| requests: [], | ||
| timestamp: DateTime.fromMicrosecondsSinceEpoch(_timelineMicros), | ||
| ); | ||
| } |
There was a problem hiding this comment.
[CONCERN] In the fake VM service, getHttpProfileWrapper returns HttpProfile with a timestamp based on _timelineMicros (which simulates the monotonic VM timeline clock). In a real VM service, HttpProfile.timestamp is a wall-clock DateTime (microseconds since epoch), whereas getVMTimelineMicros() is the monotonic timeline clock.
Using the same clock for both in the mock masked the clock mismatch bug in NetworkService.clearData(). To prevent such issues in the future and more accurately simulate the real VM service, consider using a separate simulated wall-clock timestamp for HttpProfile responses.
| if (!(_httpLoggingEnabled[isolateId] ?? false)) { | |
| return HttpProfile( | |
| requests: [], | |
| timestamp: DateTime.fromMicrosecondsSinceEpoch(_timelineMicros), | |
| ); | |
| } | |
| if (!(_httpLoggingEnabled[isolateId] ?? false)) { | |
| return HttpProfile( | |
| requests: [], | |
| timestamp: DateTime.now(), | |
| ); | |
| } |
| ]), | ||
| ); | ||
|
|
||
| // TODO(kenz): only call these if http logging and socket profiling are not |
There was a problem hiding this comment.
Did this TODO get addressed by this PR? If not, please add it back so that we don't lose track of this work.
| Expanded( | ||
| child: SearchField<NetworkController>( | ||
| searchController: controller, | ||
| searchFieldEnabled: _recording || hasRequests, |
There was a problem hiding this comment.
This parameter was removed in #9855 so that the SearchField remained editable even when there were not requests. Please remove this parameter so that it always uses the default value of true.
| final timestamp = (await service.getVMTimelineMicros()).timestamp!; | ||
| networkController.lastSocketDataRefreshMicros = timestamp; | ||
| await service.forEachIsolate((isolate) async { | ||
| lastHttpDataRefreshTimePerIsolate[isolate.id!] = timestamp; | ||
| }); |
There was a problem hiding this comment.
why can't we use the updateLastSocketDataRefreshTime and updateLastHttpDataRefreshTime helpers here? Is there a bug in those methods that needs to be fixed rather than updating these variables in a different way here?
| ); | ||
| expect(searchField.enabled, isTrue); | ||
|
|
||
| await clearTimeouts(tester); |
There was a problem hiding this comment.
Looks like you are missing some brackets and the next test method:
| await clearTimeouts(tester); | |
| await clearTimeouts(tester); | |
| }, | |
| ); | |
| testWidgetsWithWindowSize( |
There was a problem hiding this comment.
[Reviewed by Gemini]
I've done a deep, "fine-tooth comb" review of the tests introduced in this PR (network_clear_test.dart, network_hot_restart_test.dart, utils/hot_restart_network_vm_service.dart, and utils/network_lifecycle_test_utils.dart).
Overall, the test quality is excellent. The HotRestartNetworkVmService correctly and meticulously simulates VM behavior for isolate lifecycles (like the timeline clock and HTTP/socket logging defaulting to false on a new isolate). The combinations tested (e.g., clear followed by hot restart vs hot restart followed by clear) provide rigorous coverage. The use of await pumpEventQueue() effectively guarantees that the asynchronous streams from IsolateManager.onIsolateCreated propagate natively before running assertions.
However, during this deep dive into the simulated VM timeline vs the application logic, I uncovered a couple of small gaps in the test assertions, as well as an important pre-existing wall clock bug in network_service.dart that wasn't caught by the tests but is directly related to this PR.
1. The DateTime.now() Bug in updateLastHttpDataRefreshTime
While reviewing how the mock VM tests timestamp filtering (lastHttpDataRefreshTimePerIsolate), I noticed that the PR successfully refactored NetworkService.clearData() to correctly use the VM timeline (getVMTimelineMicros()). However, network_service.dart still has this method:
void updateLastHttpDataRefreshTime({bool alreadyRecordingHttp = false}) {
if (!alreadyRecordingHttp) {
for (final isolateId in lastHttpDataRefreshTimePerIsolate.keys.toList()) {
// It's safe to use `DateTime.now()` here since we don't need to worry...
lastHttpDataRefreshTimePerIsolate[isolateId] =
DateTime.now().microsecondsSinceEpoch;
}
}
}This is called by networkController.togglePolling(true) when recording is resumed.
The problem: The VM service protocol explicitly states that the updatedSince argument passed to getHttpProfile must be a timestamp from the VM's timeline clock (which is monotonic and starts from a relatively low number when the VM boots). DateTime.now().microsecondsSinceEpoch provides a massive wall clock timestamp.
If a user pauses and unpauses recording, this wall clock timestamp gets sent to the VM as updatedSince, which will mistakenly filter out all subsequent requests (because their VM timestamps will be vastly smaller than the wall clock timestamp).
Recommendation: updateLastHttpDataRefreshTime should be refactored to asynchronously fetch and use (await service.getVMTimelineMicros()).timestamp! just like you wisely did in clearData(). A test covering the "pause/resume recording" flow inside network_hot_restart_test.dart might be a good addition to prevent regressions here.
2. Missing Socket Timestamp Assertion in Clear Tests
In network_clear_test.dart within the clear refresh timestamp tracking group, there is a test: 'resets HTTP refresh timestamps to the VM timeline on clear'.
This test brilliantly asserts that networkService.lastHttpDataRefreshTimePerIsolate[isolateId] matches the VM's timeline clock. However, in NetworkService.clearData(), you also reset the socket profiling timestamp:
networkController.lastSocketDataRefreshMicros = timestamp;
Recommendation: You should add an assertion for the socket timestamp in that same test to fully cover the logic inside clearData():
expect(
controller.lastSocketDataRefreshMicros,
timelineMicros,
);3. Testing Stale Requests relies on clearHttpProfileWrapper
In network_clear_test.dart, the 'does not show stale requests after clear' test validates that older requests don't show up. However, the test implicitly passes because HotRestartNetworkVmService.clearHttpProfileWrapper actually clears the _httpProfiles mock list entirely. This means the frontend's timestamp filtering logic isn't heavily exercised in this specific test because the data is just dropped by the mock VM anyway.
Recommendation: This isn't a blocker (because clear does tell the VM to clear), but if you wanted to test that the timestamp tracking (updatedSince) strictly filters out stale requests that somehow survive the VM clear, you would need a test that sets the controller's lastHttpDataRefreshTimePerIsolate to a timeline timestamp in the future and verifies that an older request (appended without triggering a VM clear) is successfully ignored. (Your hot restart tests actually do something similar to this in 'stale isolate IDs do not prevent fetching from the new isolate', so you have partial coverage for this concept already).
Summary
IsolateManager.onIsolateCreated, fixing the Network tab freeze after hot restart (#9783, #9839).IsolateManager.onIsolateCreatedindevtools_app_sharedfor isolate lifecycle detection.Test plan
flutter test test/screens/network/network_hot_restart_test.dartflutter test test/screens/network/network_clear_test.dartflutter test test/screens/network/network_profiler_test.dart./tool/bin/dt presubmit --fix