Multiple exchanges are created for the same request when network intercept is enabled

[rzane]

Describe the bug

Normally, build_exchange is called upon Network.requestWillBeSent: https://github.com/rubycdp/ferrum/blob/5ca5e9ed5e9ac8be580589e234aadc1de6929bc0/lib/ferrum/network.rb#L387-L388

When a whitelist is registered, a Fetch.requestPaused event is also registered and causes build_exchange to be called again for the same request: https://github.com/rubycdp/ferrum/blob/ac52ce960c681b1fa0bb9d448fc3d6a7e761f3a9/lib/ferrum/page.rb#L367-L368

As a result, Network#traffic will have two exchanges referencing the same request. One of these exchanges will not be #finished?. As a result, calling wait_for_idle will raise Ferrum::TimeoutError.

To Reproduce I'm not sure if I'll be able to produce a minimal reproduction. This happens pretty infrequently.

I added some logging to network.rb and here's what I found in my application:

D, [2020-08-11T00:00:10.967036 #93432] DEBUG -- : Network.requestWillBeSent: GET http://127.0.0.1:52464/redacted (94044.261)
D, [2020-08-11T00:00:10.967094 #93432] DEBUG -- : Fetch.requestPaused: GET http://127.0.0.1:52464/redacted (94044.261)
D, [2020-08-11T00:00:10.967123 #93432] DEBUG -- : build_exchange: exchange 19883500 (94044.261)
D, [2020-08-11T00:00:10.967165 #93432] DEBUG -- : build_exchange: exchange 19883520 (94044.261)
D, [2020-08-11T00:00:10.967144 #93432] DEBUG -- : Fetch.requestPaused: exchange 19883500 (94044.261)
D, [2020-08-11T00:00:10.967187 #93432] DEBUG -- : Network.requestWillBeSent: exchange 19883520 (94044.261)

In the logs above, 94044.261 is the request ID. 19883500 and 19883520 are Exchange#object_id. As you can see, two exchanges were created for this request.

Expected behavior

Changing this line appears to fix the issue:

-exchange = build_exchange(request.id) unless exchange&.blank?
+exchange ||= build_exchange(request.id)

That being said, I'm sure there's a good reason why this .blank? check exists.

Screenshots None

Desktop (please complete the following information):

• OS: macOS
• Browser: Chrome 127.0.6533.74 (Official Build) (arm64)
• Version: v0.15

Additional context None.

[rzane]

I managed to make a script that occasionally reproduces the issue.

https://gist.github.com/rzane/a4efe24db7ce44491f0ec6056ac16401

[rzane]

Note: The reason these pending requests aren't marked as #finished? is because the subscriptions that handle responses only assign properties to select(request_id).last

https://github.com/rubycdp/ferrum/blob/5ca5e9ed5e9ac8be580589e234aadc1de6929bc0/lib/ferrum/network.rb#L395-L445