diff --git a/CHANGELOG.md b/CHANGELOG.md index b348e23f..3a97178d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -27,6 +27,9 @@ ### Fixed - An out-of-process iframe, e.g. Chrome's PDF viewer for an embedded PDF, appearing while a web worker was connected raised `'Page.enable' wasn't found` in the event thread. Only pages and iframes are now searched for its parent [#640] +- A browser that stopped reading its websocket froze the whole client: a large command blocked in a socket write + forever while holding the send lock. The write now gives up after the command's timeout and raises + `Ferrum::DeadBrowserError` [#644] - A browser context whose `Target.disposeBrowserContext` timed out stayed registered, so every later `#reset` asked again and raised `Disposal of browser context ... is already pending` for the rest of the process. It's now forgotten either way, and `#reset` disposes the remaining contexts before raising the first error [#641] diff --git a/lib/ferrum/client.rb b/lib/ferrum/client.rb index 24069745..9c02992e 100644 --- a/lib/ferrum/client.rb +++ b/lib/ferrum/client.rb @@ -208,24 +208,30 @@ def command(method, async: false, timeout: nil, **params) # Whether to return immediately instead of waiting for a response. # # @param [Numeric, nil] timeout - # How long to wait for the response. Defaults to `protocol_timeout`. + # How long to wait for the browser to take the message, and then for its + # response. Defaults to `protocol_timeout`. # # @return [Boolean, Hash] # `true` when sent asynchronously, otherwise the parsed `"result"` # from the response. # def send_message(message, async:, timeout: nil) + timeout ||= protocol_timeout + if async - @ws.send_message(message) + @ws.send_message(message, timeout) true else raise DeadBrowserError if @ws.messages.closed? pending = Concurrent::IVar.new @pendings[message[:id]] = pending - @ws.send_message(message) - data = pending.value!(timeout || protocol_timeout) - @pendings.delete(message[:id]) + begin + @ws.send_message(message, timeout) + data = pending.value!(timeout) + ensure + @pendings.delete(message[:id]) + end raise DeadBrowserError if data.nil? && @ws.messages.closed? raise TimeoutError.new(message[:method], session_id: message[:sessionId]) unless data diff --git a/lib/ferrum/client/web_socket.rb b/lib/ferrum/client/web_socket.rb index 95697e68..1069e22f 100644 --- a/lib/ferrum/client/web_socket.rb +++ b/lib/ferrum/client/web_socket.rb @@ -106,13 +106,26 @@ def on_close(_event) # @param [Hash] data # The message to send, must include an `:id` key. # + # @param [Numeric, nil] timeout + # How long the browser may go without accepting any of the frame's + # bytes. `nil` waits for as long as it takes. + # # @return [void] # - def send_message(data) + # @raise [Ferrum::DeadBrowserError] + # If the browser accepted no data for `timeout` seconds. The connection + # is closed, since the frame was cut off midway. + # + def send_message(data, timeout = nil) @screenshot_commands[data[:id]] = true if SKIP_LOGGING_SCREENSHOTS json = data.to_json - @driver_mutex.synchronize { @driver.text(json) } + @driver_mutex.synchronize do + @write_timeout = timeout + @driver.text(json) + ensure + @write_timeout = nil + end @logger&.puts("\n\n▶ #{Utils::ElapsedTime.elapsed_time} #{json}") end @@ -121,13 +134,28 @@ def send_message(data) # `websocket-driver` to emit frames. Closes {#messages} instead of # raising if the connection has already been torn down. # + # A browser that stops reading its socket (hung, or stopped) would block + # a plain write forever, holding the lock every other command needs to be + # sent. So the write gives up once the browser accepts no data for the + # timeout of the command being sent. + # # @param [String] data # The raw bytes to write. # # @return [void] # + # @raise [Ferrum::DeadBrowserError] + # If the browser accepted no data for the command's timeout. + # def write(data) - @sock.write(data) + until data.empty? + written = @sock.write_nonblock(data, exception: false) + if written.is_a?(Integer) + data = data.byteslice(written..) + elsif !wait_for_socket(written) + abandon_stalled_write + end + end rescue EOFError, Errno::ECONNRESET, Errno::EPIPE, IOError # rubocop:disable Lint/ShadowedException @messages.close end @@ -161,6 +189,18 @@ def force_close private + def wait_for_socket(state) + readers, writers = state == :wait_readable ? [[@sock], nil] : [nil, [@sock]] + IO.select(readers, writers, nil, @write_timeout) + end + + def abandon_stalled_write + timeout = @write_timeout + @messages.close + @sock.close + raise DeadBrowserError, "Browser accepted no data for #{timeout}s and is likely stuck, connection closed" + end + def start @thread = Utils::Thread.spawn do loop do diff --git a/sig/ferrum/client/web_socket.rbs b/sig/ferrum/client/web_socket.rbs index 8c31e9a0..69144d46 100644 --- a/sig/ferrum/client/web_socket.rbs +++ b/sig/ferrum/client/web_socket.rbs @@ -15,6 +15,7 @@ module Ferrum @messages: ::Queue @screenshot_commands: ::Concurrent::Hash[Integer, bool]? @thread: ::Thread + @write_timeout: ::Numeric? def initialize: ((String | ::Addressable::URI) url, Integer? max_receive_size, untyped logger) -> void @@ -24,7 +25,7 @@ module Ferrum def on_close: (untyped event) -> void - def send_message: (Hash[Symbol, untyped] data) -> void + def send_message: (Hash[Symbol, untyped] data, ?::Numeric? timeout) -> void def write: (String data) -> void @@ -34,6 +35,10 @@ module Ferrum private + def wait_for_socket: (:wait_readable | :wait_writable state) -> untyped + + def abandon_stalled_write: () -> bot + def start: () -> void def safely_parse_json: (String data) -> Hash[String, untyped]? diff --git a/spec/client_spec.rb b/spec/client_spec.rb index f3cbbe33..c70b426e 100644 --- a/spec/client_spec.rb +++ b/spec/client_spec.rb @@ -59,6 +59,47 @@ def messages end end + describe "a browser that stops reading", skip: Ferrum::Utils::Platform.windows? do + let(:remote) { Ferrum::Browser.new(base_url: base_url, timeout: 1, protocol_timeout: 1) } + let(:larger_than_socket_buffers) { "'#{'x' * (16 * 1024 * 1024)}'.length" } + + after do + Process.kill("CONT", remote.process.pid) + remote.quit + end + + def evaluate_in_background(page, expression) + Thread.new do + page.command("Runtime.evaluate", expression: expression) + rescue Ferrum::Error => e + e + end + end + + it "gives up on a command the browser doesn't take" do + page = remote.create_page + Process.kill("STOP", remote.process.pid) + + sender = evaluate_in_background(page, larger_than_socket_buffers) + + expect(sender.join(5)).to eq(sender), "the command was still blocked after 5s" + expect(sender.value).to be_a(Ferrum::DeadBrowserError) + expect(sender.value.message).to match(/accepted no data for 1s/) + end + + it "fails the commands waiting to be sent behind it" do + page = remote.create_page + Process.kill("STOP", remote.process.pid) + + evaluate_in_background(page, larger_than_socket_buffers) + sleep(0.2) + waiting = evaluate_in_background(page, "1 + 1") + + expect(waiting.join(5)).to eq(waiting), "the command was still blocked after 5s" + expect(waiting.value).to be_a(Ferrum::DeadBrowserError) + end + end + describe "event callbacks" do let(:remote) { Ferrum::Browser.new(base_url: base_url, timeout: 3, protocol_timeout: 3) } diff --git a/spec/unit/client_spec.rb b/spec/unit/client_spec.rb index 316b7f94..15875d90 100644 --- a/spec/unit/client_spec.rb +++ b/spec/unit/client_spec.rb @@ -98,5 +98,16 @@ def +(other) client.send_message(message, async: false, timeout: 0.05) end.to raise_error(Ferrum::TimeoutError) end + + it "forgets a command whose send raised" do + client.instance_variable_set(:@options, Ferrum::Browser::Options.new) + ws = instance_double(Ferrum::Client::WebSocket, messages: Queue.new) + allow(ws).to receive(:send_message).and_raise(Ferrum::DeadBrowserError) + client.instance_variable_set(:@ws, ws) + + message = client.build_message("Page.navigate", {}) + expect { client.send_message(message, async: false) }.to raise_error(Ferrum::DeadBrowserError) + expect(client.instance_variable_get(:@pendings)).to be_empty + end end end