Consider to emit stop with failure status if StreamFilterParent is detected as broken
Categories
(WebExtensions :: Request Handling, task, P3)
Tracking
(Not tracked)
People
(Reporter: rpl, Unassigned)
References
Details
(Whiteboard: [addons-jira])
Attachments
(1 file)
23.31 KB,
text/plain
|
Details |
While investigating how an extension may be able to trigger Bug 1752655 I noticed that if an extension:
- creates a StreamFilter for an intercepted webRequest
- doesn't handle any of the StreamFilter events (either by subscribing a listener for the StreamFilter events but not calling filter.write nor filter.stop, or by not subscribing any listeners at all)
- doesn't preserve any reference to the StreamFilter instance (so that the StreamFilter instance will be deallocated once there are no other references after StreamFilterChild does remove the last one kept internally until the intercepted channel gets closed)
Then:
- the StreamFilterParent::Broken method is being called, because it gets destroyed while it is still in an unexpected state
- but StreamFilterParent::EmitStopRequest is still called with status NS_OK from StreamFilterParent::FinishDisconnect
- and then the intercepted request looks like closed successfully (e.g. a call to fetch will resolve), but the response body is going to be empty
It seems likely that these conditions may be triggered if an extension is misbehaving (e.g. fails to handle an error condition that isn't expecting) and then lead to "corrupted" requests' responses like the one that are triggering Bug 1752655:
- At this point the intercepted connection got closed (interestingly there is quite some lag time between the last log in this group and the first one in the one follows, which I didn't look into yet):
0:05.26 GECKO(2079662) [Child 2079788: Main Thread]: D/StreamFilterChild StreamFilterChild::RecvStopRequest @7f0e74913e00 - aStatus: 0
0:05.27 GECKO(2079662) [Child 2079788: Main Thread]: D/StreamFilterChild StreamFilterChild::MaybeStopRequest @7f0e74913e00 - mReceivedOnStop: 1, mBufferData.isEmpty: 1
0:05.27 GECKO(2079662) [Child 2079788: Main Thread]: D/StreamFilter StreamFilter::CheckAlive @7f0e7270a660
0:05.27 GECKO(2079662) extension - filterResponseData onstop: 7
0:05.52 GECKO(2079662) extension - content script executed (to notify when service worker to be ready)
- The following logs are related to the last reference for StreamFilter being released and the StreamFilter destructor being called as a side effect of that:
0:18.07 GECKO(2079662) [Child 2079788: Main Thread]: D/StreamFilter StreamFilter::ForgetActor @7f0e7270a660 - mActor: @7f0e74913e00
0:18.07 GECKO(2079662) [Child 2079788: Main Thread]: D/StreamFilterChild StreamFilterChild::Cleanup @7f0e74913e00
0:18.07 GECKO(2079662) [Child 2079788: Main Thread]: D/StreamFilterChild StreamFilterChild::Disconnect @7f0e74913e00
0:18.07 GECKO(2079662) [Child 2079788: Main Thread]: D/StreamFilterChild StreamFilterChild::WriteBufferedData @7f0e74913e00
0:18.07 GECKO(2079662) [Child 2079932: Socket Thread]: D/StreamFilterParent StreamFilterParent::RecvDisconnect @7fa1eb7af800
0:18.08 GECKO(2079662) [Child 2079788: Main Thread]: D/StreamFilterChild StreamFilterChild::RecvFlushData @7f0e74913e00
0:18.08 GECKO(2079662) [Child 2079788: Main Thread]: D/StreamFilterChild StreamFilterChild::SetNextState @7f0e74913e00
0:18.08 GECKO(2079662) [Child 2079932: Socket Thread]: D/StreamFilterParent StreamFilterParent::RecvFlushedData @7fa1eb7af800
0:18.08 GECKO(2079662) [Child 2079932: Socket Thread]: D/StreamFilterParent StreamFilterParent::Destroy @7fa1eb7af800
0:18.08 GECKO(2079662) [Child 2079932: Socket Thread]: D/StreamFilterParent StreamFilterParent::FinishDisconnect @7fa1eb7af800 - mReceivedStop: 1, mSentStop: 0, mDisconnected: 0
0:18.08 GECKO(2079662) [Child 2079932: StreamTrans #1]: D/StreamFilterParent StreamFilterParent::FlushBufferedData @7fa1eb7af800
- At this point the
StreamFilterParent::Broken
gets called (on the socket thread), after we determined the broken state from insideStreamFilterParent::ActorDestroy
, and then EmitStopRequest gets called (on the main thread) triggered from FinishDisconnect (called previously on the socket thread).
0:18.08 GECKO(2079662) [Child 2079932: Socket Thread]: D/StreamFilterParent StreamFilterParent::ActorDestroy @7fa1eb7af800
0:18.08 GECKO(2079662) [Child 2079932: Socket Thread]: D/StreamFilterParent StreamFilterParent::Broken @7fa1eb7af800
0:18.08 GECKO(2079662) * mState == Disconnecting: 1
0:18.09 GECKO(2079662) [Child 2079932: Socket Thread]: D/StreamFilterParent StreamFilterParent::ActorDealloc @7fa1eb7af800
0:18.09 GECKO(2079662) [Child 2079932: Main Thread]: D/StreamFilterParent StreamFilterParent::EmitStopRequest @7fa1eb7af800
As a side note: the logs pasted above are collected using the additional StreamFilter MOZ_LOG (using the patch I've attached to Bug 1765991) while running the test case 'browser_ext_cache_api_corruption.js' attached to Bug 1752655. I'm attaching the entire set of logs from that run as an attachment on this issue.
This bug goal is to determine if it would be doable (and reasonable) to make EmitStopRequest to be called with a error status under this kind of broken state.
Reporter | ||
Updated•2 years ago
|
Reporter | ||
Updated•8 months ago
|
Description
•