Open Bug 1766053 Opened 2 years ago Updated 5 months ago

Consider to emit stop with failure status if StreamFilterParent is detected as broken

Categories

(WebExtensions :: Request Handling, task, P3)

task

Tracking

(Not tracked)

People

(Reporter: rpl, Unassigned)

References

Details

(Whiteboard: [addons-jira])

Attachments

(1 file)

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 inside StreamFilterParent::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.

Priority: P2 → P3
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: