Timeout loading Facebook front page #6813

lukeis · 2016-03-04T07:31:30Z

Originally reported on Google Code with ID 6813

Hello,

I am using Watir a plugin for Ruby that uses Selenium in background. While getting
the html code for Facebook page. It gives this specific error:

/Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/protocol.rb:158:in `rescue
in rbuf_fill': Net::ReadTimeout (Net::ReadTimeout)
    from /Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/protocol.rb:152:in
`rbuf_fill'
    from /Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/protocol.rb:134:in
`readuntil'
    from /Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/protocol.rb:144:in
`readline'
    from /Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/http/response.rb:39:in
`read_status_line'
    from /Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/http/response.rb:28:in
`read_new'
    from /Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/http.rb:1406:in
`block in transport_request'
    from /Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/http.rb:1403:in
`catch'
    from /Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/http.rb:1403:in
`transport_request'
    from /Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/http.rb:1376:in
`request'
    from /Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/http.rb:1369:in
`block in request'
    from /Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/http.rb:852:in
`start'
    from /Users/COMPUSER/.rvm/rubies/ruby-2.0.0-p247/lib/ruby/2.0.0/net/http.rb:1367:in
`request'
    from /Users/COMPUSER/.rvm/gems/ruby-2.0.0-p247/gems/selenium-webdriver-2.37.0/lib/selenium/webdriver/remote/http/default.rb:83:in
`response_for'
    from /Users/COMPUSER/.rvm/gems/ruby-2.0.0-p247/gems/selenium-webdriver-2.37.0/lib/selenium/webdriver/remote/http/default.rb:39:in
`request'
    from /Users/COMPUSER/.rvm/gems/ruby-2.0.0-p247/gems/selenium-webdriver-2.37.0/lib/selenium/webdriver/remote/http/common.rb:40:in
`call'
    from /Users/COMPUSER/.rvm/gems/ruby-2.0.0-p247/gems/selenium-webdriver-2.37.0/lib/selenium/webdriver/remote/bridge.rb:634:in
`raw_execute'
    from /Users/COMPUSER/.rvm/gems/ruby-2.0.0-p247/gems/selenium-webdriver-2.37.0/lib/selenium/webdriver/remote/bridge.rb:612:in
`execute'
    from /Users/COMPUSER/.rvm/gems/ruby-2.0.0-p247/gems/selenium-webdriver-2.37.0/lib/selenium/webdriver/remote/bridge.rb:174:in
`getPageSource'
    from /Users/COMPUSER/.rvm/gems/ruby-2.0.0-p247/gems/selenium-webdriver-2.37.0/lib/selenium/webdriver/common/driver.rb:140:in
`page_source'
    from /Users/COMPUSER/.rvm/gems/ruby-2.0.0-p247/gems/watir-webdriver-0.6.4/lib/watir-webdriver/browser.rb:183:in
`html'
    from crawler.rb:36:in `<main>'

My Code is:

require "watir-webdriver/wait"
require 'net/http'

client = Selenium::WebDriver::Remote::Http::Default.new
client.timeout = 180

browser = Watir::Browser.new :firefox, :http_client => client
browser.driver.manage.timeouts.implicit_wait = 3
browser.goto 'https://www.facebook.com'
browser.text_field(:name => 'email').set "USER"
browser.text_field(:name => 'pass').set "PASSWORD"
browser.button(:'id' => 'u_0_f').click

p Time.now.to_s + ': HTML Parsing started.'

doc = Nokogiri::HTML.parse(browser.html)

p Time.now.to_s + ': HTML Parsing ended.'

Reported by yagiznizipli on 2014-01-08 19:14:29

The text was updated successfully, but these errors were encountered:

lukeis · 2016-03-04T07:31:30Z

Reported by barancev on 2014-01-09 06:20:51

Labels added: Lang-Ruby

lukeis · 2016-03-04T07:31:31Z

Does this happen consistently for you?

 I tried running your code, substituting my FB username/password, but I'm unable to
reproduce the problem:

$ ruby test.rb
"2014-01-10 17:29:08 +0100: HTML Parsing started."
"2014-01-10 17:29:09 +0100: HTML Parsing ended."
$

Do you have any errors in the Firefox Error console (which you can bring up on with
Command-Shift-J)?

Reported by jari.bakken on 2014-01-10 16:40:31

Status changed: NeedsClarification
Labels added: Browser-Firefox
Labels removed: Status-Untriaged

lukeis · 2016-03-04T07:31:32Z

Hello,

This is what I get when I run it. It doesn't always give this error message. But %80
of the time Selenium gives Timeouterror.

Also, it doesn't get the browser.html again.

19:45:01.937 OpenGL compositor Initialized Succesfully.
Version: 2.1 INTEL-8.18.29
Vendor: Intel Inc.
Renderer: Intel HD Graphics 4000 OpenGL Engine
FBO Texture Target: TEXTURE_2D
19:44:59.501 Could not read chrome manifest 'file:///Applications/Firefox.app/Contents/MacOS/chrome.manifest'.
19:44:59.557 LOG addons.xpi: startup
19:44:59.558 LOG addons.xpi: Skipping unavailable install location app-system-share
19:44:59.558 LOG addons.xpi: checkForChanges
19:44:59.562 LOG addons.xpi: No changes found
19:44:59.566 Trying to re-register CID '{e26dbdcd-d3ba-4ded-88c3-6cb07ee3e9e0}' already
registered by file:///var/folders/w6/6zxqtl6n3hz5rwpldh8kn5n80000gn/T/webdriver-profile20140110-21443-kvuocg/extensions/fxdriver@googlecode.com/components/prompt_service.js.
chrome.manifest:35
19:44:59.566 Could not read chrome manifest 'file:///Applications/Firefox.app/Contents/MacOS/browser/extensions/%7B972ce4c6-7e08-4474-a285-3208198ce6fd%7D/chrome.manifest'.
19:44:59.568 While creating services from category 'profile-after-change', could not
create service for entry 'Disk Space Watcher Service', contract ID '@mozilla.org/toolkit/disk-space-watcher;1'
19:45:00.031 OpenGL compositor Initialized Succesfully.
Version: 2.1 INTEL-8.18.29
Vendor: Intel Inc.
Renderer: Intel HD Graphics 4000 OpenGL Engine
FBO Texture Target: TEXTURE_2D
19:45:00.110 [WEBDRIVER] [INFO] bad_cert_listener.js:3237 Found preference for webdriver_assume_untrusted_issuer:
true

19:45:00.111 [WEBDRIVER] [INFO] bad_cert_listener.js:3237 Found preference for webdriver_accept_untrusted_certs:
true

19:45:00.111 [WEBDRIVER] [INFO] bad_cert_listener.js:3248 Accept untrusted certificates:
true

19:45:00.178 [WEBDRIVER] [INFO] driver_component.js:10710 Using native events: false

19:45:00.178 [WEBDRIVER] [INFO] driver_component.js:7487 Loading: resource://fxdriver/evaluate.js

19:45:00.180 [WEBDRIVER] [INFO] driver_component.js:7497 Done reading: resource://fxdriver/evaluate.js

19:45:00.413 [WEBDRIVER] [INFO] command_processor.js:10877 Received command: newSession

19:45:00.450 [WEBDRIVER] [INFO] session_store.js:7938 Setting preferences based on
required capabilities

19:45:00.451 [WEBDRIVER] [INFO] session_store.js:7955 Setting capability nativeEvents
(webdriver_enable_native_events) to false

19:45:00.451 [WEBDRIVER] [INFO] command_processor.js:10992 Created a new session with
id: 435e04d5-3b5b-0d4c-82e8-2c2bf4f9f42f

19:45:00.462 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: implicitlyWait

19:45:00.467 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: get

19:45:00.935 [WEBDRIVER] [INFO] bad_cert_listener.js:3237 Found preference for webdriver_accept_untrusted_certs:
true

19:45:00.935 [WEBDRIVER] [INFO] bad_cert_listener.js:3273 Allowing certificate from
site: www.facebook.com:443

19:45:00.936 [WEBDRIVER] [INFO] bad_cert_listener.js:3273 Setting all Override Bits

19:45:00.936 [WEBDRIVER] [INFO] bad_cert_listener.js:3273 Override Bits: 7

19:45:01.937 OpenGL compositor Initialized Succesfully.
Version: 2.1 INTEL-8.18.29
Vendor: Intel Inc.
Renderer: Intel HD Graphics 4000 OpenGL Engine
FBO Texture Target: TEXTURE_2D
19:45:02.395 [WEBDRIVER] [INFO] prompt_service.js:7741 Spoofing prompt service

19:45:02.397 [WEBDRIVER] [INFO] prompt_service.js:7748 Found implementation at: {7ad1b327-6dfa-46ec-9234-f2a620ea7e00}

19:45:02.398 [WEBDRIVER] [INFO] prompt_service.js:7748 Found implementation at: {1c978d25-b37f-43a8-a2d6-0c7a239ead87}

19:45:02.399 [WEBDRIVER] [INFO] prompt_service.js:7761 Finished initializing spoofed
prompt service

19:45:02.416 [WEBDRIVER] [INFO] driver_component.js:3305 request status is 0

19:45:02.436 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: getCurrentUrl

19:45:02.546 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: switchToFrame

19:45:02.548 [WEBDRIVER] [INFO] driver_component.js:8937 Switching to default content
(topmost frame)

19:45:02.553 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: findElement

19:45:02.593 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: getElementTagName

19:45:02.614 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: isElementEnabled

19:45:02.635 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: switchToFrame

19:45:02.636 [WEBDRIVER] [INFO] driver_component.js:8937 Switching to default content
(topmost frame)

19:45:02.642 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: findElement

19:45:02.647 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: getElementTagName

19:45:02.652 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: getElementAttribute

19:45:02.654 Use of getAttributeNode() is deprecated. Use getAttribute() instead. command_processor.js:6829
19:45:02.658 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: clearElement

19:45:02.670 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: sendKeysToElement

19:45:02.674 [WEBDRIVER] [INFO] command_processor.js:10298 No need to switch focus

19:45:02.697 [WEBDRIVER] [WARNING] command_processor.js:7250 Unable to find native
component: @openqa.org/nativekeyboard;1

19:45:02.698 [WEBDRIVER] [WARNING] command_processor.js:7250 TypeError: Components.classes[a]
is undefined

19:45:02.698 [WEBDRIVER] [INFO] command_processor.js:7281 Doing sendKeys in a non-native
way...

19:45:02.730 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: switchToFrame

19:45:02.735 [WEBDRIVER] [INFO] driver_component.js:8937 Switching to default content
(topmost frame)

19:45:02.741 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: findElement

19:45:02.748 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: getElementTagName

19:45:02.753 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: isElementEnabled

19:45:02.759 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: switchToFrame

19:45:02.761 [WEBDRIVER] [INFO] driver_component.js:8937 Switching to default content
(topmost frame)

19:45:02.765 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: findElement

19:45:02.771 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: getElementTagName

19:45:02.777 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: getElementAttribute

19:45:02.820 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: clearElement

19:45:02.834 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: sendKeysToElement

19:45:02.838 [WEBDRIVER] [INFO] command_processor.js:10298 No need to switch focus

19:45:02.850 [WEBDRIVER] [WARNING] command_processor.js:7250 Unable to find native
component: @openqa.org/nativekeyboard;1

19:45:02.850 [WEBDRIVER] [WARNING] command_processor.js:7250 TypeError: Components.classes[a]
is undefined

19:45:02.850 [WEBDRIVER] [INFO] command_processor.js:7281 Doing sendKeys in a non-native
way...

19:45:02.907 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: switchToFrame

19:45:02.908 [WEBDRIVER] [INFO] driver_component.js:8937 Switching to default content
(topmost frame)

19:45:02.912 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: findElement

19:45:02.913 Use of attributes' specified attribute is deprecated. It always returns
true. driver_component.js:6830
19:45:02.920 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: getElementTagName

19:45:02.926 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: isElementEnabled

19:45:02.931 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: clickElement

19:45:02.935 [WEBDRIVER] [WARNING] command_processor.js:7250 Unable to find native
component: @openqa.org/nativemouse;1

19:45:02.936 [WEBDRIVER] [WARNING] command_processor.js:7250 TypeError: Components.classes[a]
is undefined

19:45:02.936 [WEBDRIVER] [INFO] command_processor.js:10284 Falling back to synthesized
click

19:45:02.937 [WEBDRIVER] [INFO] synthetic_mouse.js:9195 SyntheticMouse.move [object
XrayWrapper [object HTMLInputElement]] 17 8

19:45:02.938 [WEBDRIVER] [INFO] synthetic_mouse.js:9205 Calling mouse.move with: 17,
8, [object XrayWrapper [object HTMLInputElement]]

19:45:02.944 [WEBDRIVER] [INFO] synthetic_mouse.js:9308 Calling fireMouseEvent mouseout
1004.86669921875, 43.41667175292969, [object XrayWrapper [object HTMLInputElement]]

19:45:02.945 [WEBDRIVER] [INFO] synthetic_mouse.js:9314 Called fireMouseEvent mouseout
1004.86669921875, 43.41667175292969, [object XrayWrapper [object HTMLInputElement]]

19:45:02.946 [WEBDRIVER] [INFO] synthetic_mouse.js:9308 Calling fireMouseEvent mouseover
1004.86669921875, 43.41667175292969, [object XrayWrapper [object HTMLInputElement]]

19:45:02.946 [WEBDRIVER] [INFO] synthetic_mouse.js:9314 Called fireMouseEvent mouseover
1004.86669921875, 43.41667175292969, [object XrayWrapper [object HTMLInputElement]]

19:45:02.947 [WEBDRIVER] [INFO] synthetic_mouse.js:9308 Calling fireMouseEvent mousemove
1004.86669921875, 43.41667175292969, [object XrayWrapper [object HTMLInputElement]]

19:45:02.948 [WEBDRIVER] [INFO] synthetic_mouse.js:9314 Called fireMouseEvent mousemove
1004.86669921875, 43.41667175292969, [object XrayWrapper [object HTMLInputElement]]

19:45:02.948 [WEBDRIVER] [INFO] synthetic_mouse.js:9212 SyntheticMouse.click [object
XrayWrapper [object HTMLInputElement]]

19:45:02.951 [WEBDRIVER] [INFO] synthetic_mouse.js:9224 About to do a bot.action.click
on [object XrayWrapper [object HTMLInputElement]]

19:45:04.650 Use of getAttributeNode() is deprecated. Use getAttribute() instead. mQmDvpcGT0t.js:48
19:45:06.724 Blocklist::_loadBlocklistFromFile: blocklist is disabled
19:45:09.951 [WEBDRIVER] [INFO] command_processor.js:3305 request status is 0

19:45:09.953 [WEBDRIVER] [INFO] command_processor.js:7513 New page loading.

19:45:10.025 [WEBDRIVER] [INFO] command_processor.js:10893 Received command: getPageSource

19:45:10.026 [WEBDRIVER] [SEVERE] session.js:3282 Lost DOM in window undefined

19:45:10.384 [WEBDRIVER] [INFO] command_processor.js:10818 Ignoring pending about:document-onload-blocker
request

Reported by yagiznizipli on 2014-01-10 17:45:35

lukeis · 2016-03-04T07:31:33Z

Also added:

19:46:00.382 1389375960382  Services.HealthReport.HealthReporter    WARN    Saved state file
does not exist.

19:46:00.382 1389375960382  Services.HealthReport.HealthReporter    WARN    No prefs data
found.

Reported by yagiznizipli on 2014-01-10 17:47:07

lukeis · 2016-03-04T07:31:33Z

This looks problematic:

  19:45:10.026 [WEBDRIVER] [SEVERE] session.js:3282 Lost DOM in window undefined

Just for debugging purposes, does it help if you sleep a few seconds before the `browser.html`
call?

Reported by jari.bakken on 2014-01-10 17:49:44

lukeis · 2016-03-04T07:31:34Z

I've added sleep(3) Again:

19:50:54.783 [WEBDRIVER] [SEVERE] session.js:3282 Lost DOM in window undefined

Reported by yagiznizipli on 2014-01-10 17:51:19

lukeis · 2016-03-04T07:31:35Z

On the other hand, if I use sleep(3) getting browser.html works, but on the other hand,
I don't have a 3 second to sleep before that action, because my automation tool should
be as fast as possible. It is using a lot of "browser.html" call, and for a 500 page
load, 1500 seconds is a lot to afford.

Do you have any suggestions except using sleep?

Reported by yagiznizipli on 2014-01-10 17:57:37

lukeis · 2016-03-04T07:31:35Z

I wasn't suggesting using sleep as a solution, but it tells us that this is a timing
issue of some sort. I'm not sure how to proceed from here though, since I can't reproduce
it locally.

Reported by jari.bakken on 2014-01-10 18:18:56

lukeis · 2016-03-04T07:31:36Z

Will it help if I capture the screen video?

Reported by yagiznizipli on 2014-01-10 18:20:08

lukeis · 2016-03-04T07:31:37Z

I don't think a video is going to help a lot. You could try upgrading to selenium-webdriver
2.39.0 and make sure you're on Firefox 23.0.1, which is what I'm using.

Reported by jari.bakken on 2014-01-10 18:26:07

lukeis · 2016-03-04T07:31:37Z

I updated to 2.39.0, and I am using Firefox 26. The problem didn't occurred, but it
takes 6 minutes to get the browser.html, any ideas to shorten the time?

"2014-01-10 20:55:34 +0200: HTML Parsing started."
"2014-01-10 21:01:09 +0200: HTML Parsing ended."

Reported by yagiznizipli on 2014-01-10 19:02:25

lukeis · 2016-03-04T07:31:38Z

On the other hand, after the first browser.html, every other request to "browser.html"
gives timeout error

Reported by yagiznizipli on 2014-01-10 19:14:30

lukeis · 2016-03-04T07:31:39Z

I can't reproduce the issue too, getting the page source takes less than a second.

"Lost DOM in window" is not a critical issue, we should change its level to 'warn'
or may be even 'info' I think.

Do you have only one message "Ignoring pending about:document-onload-blocker request"
or many ones?

Reported by barancev on 2014-02-19 07:05:01

lukeis · 2016-03-04T07:31:40Z

Closing the issue as non-actionable, there is no known way to reproduce it.

Reported by barancev on 2014-06-30 07:36:01

Status changed: Invalid

lukeis · 2016-03-04T07:31:40Z

Reported by jari.bakken on 2015-02-26 23:02:13

lukeis · 2016-03-04T07:31:41Z

Reported by luke.semerau on 2015-09-17 18:21:59

Labels added: Restrict-AddIssueComment-Commit

lukeis self-assigned this Mar 4, 2016

lukeis added Type-Defect Priority-Medium Restrict-AddIssueComment-Commit Lang-Ruby Browser-Firefox Status-Invalid labels Mar 4, 2016

lukeis closed this as completed Mar 4, 2016

SeleniumHQ locked and limited conversation to collaborators Mar 4, 2016

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Timeout loading Facebook front page #6813

Timeout loading Facebook front page #6813

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

Timeout loading Facebook front page #6813

Timeout loading Facebook front page #6813

Comments

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016

lukeis commented Mar 4, 2016