Firefox no longer connects to url

Spleeding1 commented 5 years ago

I was using older versions of everything, then one day it didn't work. I installed all the latest and greatest, but nothing changed. If you need more, let me know.

System

Version: geckodriver 0.23.0 ( 2018-10-04)
Platform: macOS Mojave 10.14.2 (18C54)
Firefox: Quantum 64.0 (64-bit)
Selenium: Selenium-Python (with Django 2.1), 3.141.0

Testcase

 <!DOCTYPE html>
    <body>
      <p>Hello!</p>
    </body>
  </html>

Stacktrace

Traceback (most recent call last):
  File "/Users/------/Software/------/ce_profiles/tests/functional_tests/test_function_add_new_customer_page.py", line 48, in test_add_new_customer
    self.get_page('/customer/add-new', window='xs')
  File "/Users/------/Software/------/base_tests/base_FunctionalTest.py", line 70, in get_page
    self.live_server_url + url_extention
  File "/Users/------/Software/------/------_venv/lib/python3.7/site-packages/selenium/webdriver/remote/webdriver.py", line 333, in get
    self.execute(Command.GET, {'url': url})
  File "/Users/------Software/------/------_venv/lib/python3.7/site-packages/selenium/webdriver/remote/webdriver.py", line 321, in execute
    self.error_handler.check_response(response)
  File "/Users/------/Software/------/------_venv/lib/python3.7/site-packages/selenium/webdriver/remote/errorhandler.py", line 242, in check_response
    raise exception_class(message, screen, stacktrace)
selenium.common.exceptions.WebDriverException: Message: Reached error page: about:neterror?e=connectionFailure&u=http%3A//localhost%3A62727/customer/add-new&c=UTF-8&f=regular&d=Firefox%20can%E2%80%99t%20establish%20a%20connection%20to%20the%20server%20at%20localhost%3A62727.

Trace-level log

1545449670968   mozrunner::runner   INFO    Running command: "/Applications/Firefox.app/Contents/MacOS/firefox-bin" "-marionette" "-foreground" "-no-remote" "-profile" "/var/folders/54/sp5mhspj40b7kbj5r8gbzb2m0000gn/T/rust_mozprofile.DvAefwVmjolt"
1545449671345   addons.webextension.screenshots@mozilla.org WARN    Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: resource://pdf.js/
1545449671346   addons.webextension.screenshots@mozilla.org WARN    Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: about:reader*
Can't find symbol 'GetGraphicsResetStatus'.
1545449672575   Marionette  INFO    Listening on port 62740
1545449672612   Marionette  WARN    TLS certificate errors will be ignored for this session
1545449672764   Marionette  INFO    Stopped listening on port 62740
JavaScript error: resource://gre/modules/Sqlite.jsm, line 841: Error: Connection is not open.

whimboo commented 5 years ago

We requested a trace level log when filing an issue, but the above is just an info level one. Please consult https://firefox-source-docs.mozilla.org/testing/geckodriver/geckodriver/TraceLogs.html in how to correctly record a trace log.

Spleeding1 commented 5 years ago

My mistake

1546517665535   mozrunner::runner   INFO    Running command: "/Applications/Firefox.app/Contents/MacOS/firefox-bin" "-marionette" "-foreground" "-no-remote" "-profile" "/var/folders/54/sp5mhspj40b7kbj5r8gbzb2m0000gn/T/rust_mozprofile.4cCrhYkkmKWS"
1546517665536   geckodriver::marionette DEBUG   Waiting 60s to connect to browser on 127.0.0.1:56914
1546517665939   addons.webextension.screenshots@mozilla.org WARN    Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: resource://pdf.js/
1546517665939   addons.webextension.screenshots@mozilla.org WARN    Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: about:reader*
1546517666030   Marionette  DEBUG   Received observer notification profile-after-change
1546517666119   Marionette  DEBUG   Received observer notification command-line-startup
1546517666119   Marionette  DEBUG   Received observer notification nsPref:changed
1546517666119   Marionette  DEBUG   Init aborted (running=false, enabled=true, finalUIStartup=false)
1546517666313   Marionette  DEBUG   Received observer notification toplevel-window-ready
Can't find symbol 'GetGraphicsResetStatus'.
1546517667016   Marionette  DEBUG   Received observer notification sessionstore-windows-restored
1546517667016   Marionette  DEBUG   Waiting for delayed startup...
1546517667125   Marionette  DEBUG   Setting recommended pref security.turn_off_all_security_so_that_viruses_can_take_over_this_computer to true
1546517667125   Marionette  DEBUG   Setting recommended pref apz.content_response_timeout to 60000
1546517667125   Marionette  DEBUG   Setting recommended pref browser.contentblocking.introCount to 99
1546517667125   Marionette  DEBUG   Setting recommended pref browser.download.panel.shown to true
1546517667125   Marionette  DEBUG   Setting recommended pref browser.newtabpage.enabled to false
1546517667126   Marionette  DEBUG   Setting recommended pref browser.pagethumbnails.capturing_disabled to true
1546517667126   Marionette  DEBUG   Setting recommended pref browser.search.update to false
1546517667126   Marionette  DEBUG   Setting recommended pref browser.tabs.disableBackgroundZombification to false
1546517667126   Marionette  DEBUG   Setting recommended pref browser.tabs.warnOnCloseOtherTabs to false
1546517667126   Marionette  DEBUG   Setting recommended pref browser.tabs.warnOnOpen to false
1546517667126   Marionette  DEBUG   Setting recommended pref browser.usedOnWindows10.introURL to 
1546517667126   Marionette  DEBUG   Setting recommended pref browser.urlbar.suggest.searches to false
1546517667127   Marionette  DEBUG   Setting recommended pref datareporting.policy.dataSubmissionPolicyAccepted to false
1546517667127   Marionette  DEBUG   Setting recommended pref dom.disable_beforeunload to true
1546517667127   Marionette  DEBUG   Setting recommended pref dom.disable_open_during_load to false
1546517667127   Marionette  DEBUG   Setting recommended pref dom.file.createInChild to true
1546517667127   Marionette  DEBUG   Setting recommended pref dom.max_chrome_script_run_time to 0
1546517667127   Marionette  DEBUG   Setting recommended pref dom.max_script_run_time to 0
1546517667127   Marionette  DEBUG   Setting recommended pref extensions.getAddons.cache.enabled to false
1546517667127   Marionette  DEBUG   Setting recommended pref extensions.webservice.discoverURL to http://%(server)s/dummy/discoveryURL
1546517667127   Marionette  DEBUG   Setting recommended pref network.http.prompt-temp-redirect to false
1546517667127   Marionette  DEBUG   Setting recommended pref network.http.speculative-parallel-limit to 0
1546517667127   Marionette  DEBUG   Setting recommended pref security.fileuri.strict_origin_policy to false
1546517667127   Marionette  DEBUG   Setting recommended pref security.notification_enable_delay to 0
1546517667127   Marionette  DEBUG   Setting recommended pref signon.autofillForms to false
1546517667128   Marionette  DEBUG   Setting recommended pref signon.rememberSignons to false
1546517667128   Marionette  DEBUG   Setting recommended pref toolkit.cosmeticAnimations.enabled to false
1546517667154   Marionette  INFO    Listening on port 56914
1546517667154   Marionette  DEBUG   Remote service is active
1546517667172   geckodriver::marionette DEBUG   Connection established on 127.0.0.1:56914. Waiting for Marionette handshake
1546517667177   Marionette  DEBUG   Accepted connection 0 from 127.0.0.1:56933
1546517667178   geckodriver::marionette DEBUG   Connected to Marionette
1546517667184   Marionette  TRACE   0 -> [0,1,"WebDriver:NewSession",{"acceptInsecureCerts":true,"browserName":"firefox"}]
1546517667185   Marionette  WARN    TLS certificate errors will be ignored for this session
1546517667216   Marionette  DEBUG   [4294967297] Frame script loaded
1546517667216   Marionette  DEBUG   [4294967297] Frame script registered
1546517667219   Marionette  TRACE   0 <- [1,1,null,{"sessionId":"f54daff6-b9a3-6c43-a98b-c5b35adeecfd","capabilities":{"browserName":"firefox","browserVersion":"64.0" ... ozprofile.4cCrhYkkmKWS","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
1546517667222   webdriver::server   DEBUG   <- 200 OK {"value":{"sessionId":"f54daff6-b9a3-6c43-a98b-c5b35adeecfd","capabilities":{"acceptInsecureCerts":true,"browserName":"firefox","browserVersion":"64.0","moz:accessibilityChecks":false,"moz:geckodriverVersion":"0.23.0","moz:headless":false,"moz:processID":34946,"moz:profile":"/var/folders/54/sp5mhspj40b7kbj5r8gbzb2m0000gn/T/rust_mozprofile.4cCrhYkkmKWS","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"pageLoadStrategy":"normal","platformName":"mac","platformVersion":"18.2.0","rotatable":false,"setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"unhandledPromptBehavior":"dismiss and notify"}}}
1546517667223   webdriver::server   DEBUG   -> POST /session/f54daff6-b9a3-6c43-a98b-c5b35adeecfd/url {"url": "http://localhost:56900/_test"}
1546517667231   Marionette  TRACE   0 -> [0,2,"WebDriver:Navigate",{"url":"http://localhost:56900/_test"}]
1546517667236   Marionette  DEBUG   [4294967297] Received DOM event beforeunload for about:blank
1546517667248   Marionette  DEBUG   [4294967297] Received DOM event beforeunload for about:blank
1546517667249   Marionette  DEBUG   [4294967297] Received DOM event pagehide for about:blank
1546517667342   Marionette  DEBUG   [4294967297] Received DOM event DOMContentLoaded for about:neterror?e=connectionFailure&u=http%3A//localhost%3A56900/_test&c=UTF-8&f=regular&d=Firefox%20can%E2%80%99t%20establish%20a%20connection%20to%20the%20server%20at%20localhost%3A56900.
1546517667343   Marionette  TRACE   0 <- [1,2,{"error":"unknown error","message":"Reached error page: about:neterror?e=connectionFailure&u=http%3A//localhost%3A56900/ ... eadyState@chrome://marionette/content/listener.js:275:21\nhandleEvent@chrome://marionette/content/listener.js:243:9\n"},null]
1546517667343   webdriver::server   DEBUG   <- 500 Internal Server Error {"value":{"error":"unknown error","message":"Reached error page: about:neterror?e=connectionFailure&u=http%3A//localhost%3A56900/_test&c=UTF-8&f=regular&d=Firefox%20can%E2%80%99t%20establish%20a%20connection%20to%20the%20server%20at%20localhost%3A56900.","stacktrace":"WebDriverError@chrome://marionette/content/error.js:178:5\nUnknownError@chrome://marionette/content/error.js:483:5\nhandleReadyState@chrome://marionette/content/listener.js:275:21\nhandleEvent@chrome://marionette/content/listener.js:243:9\n"}}
1546517667344   webdriver::server   DEBUG   -> DELETE /session/f54daff6-b9a3-6c43-a98b-c5b35adeecfd 
1546517667345   Marionette  TRACE   0 -> [0,3,"Marionette:Quit",{"flags":["eForceQuit"]}]
1546517667345   Marionette  INFO    Stopped listening on port 56914
1546517667389   Marionette  TRACE   0 <- [1,3,null,{"cause":"shutdown"}]
1546517667444   webdriver::server   DEBUG   Deleting session
1546517667454   Marionette  TRACE   0 -> [0,4,"Marionette:Quit",{"flags":["eForceQuit"]}]
1546517667455   Marionette  TRACE   0 <- [1,4,{"error":"invalid session id","message":"Tried to run command without establishing a connection","stacktrace":"WebDriver ... et@chrome://marionette/content/server.js:236:8\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:490:9\n"},null]
1546517667458   Marionette  DEBUG   Closed connection 0
JavaScript error: resource://gre/modules/Sqlite.jsm, line 841: Error: Connection is not open.
1546517667524   Marionette  DEBUG   Received observer notification xpcom-will-shutdown
1546517667524   Marionette  DEBUG   Resetting recommended pref security.turn_off_all_security_so_that_viruses_can_take_over_this_computer
1546517667524   Marionette  DEBUG   Resetting recommended pref apz.content_response_timeout
1546517667524   Marionette  DEBUG   Resetting recommended pref browser.contentblocking.introCount
1546517667524   Marionette  DEBUG   Resetting recommended pref browser.download.panel.shown
1546517667524   Marionette  DEBUG   Resetting recommended pref browser.newtabpage.enabled
1546517667524   Marionette  DEBUG   Resetting recommended pref browser.pagethumbnails.capturing_disabled
1546517667524   Marionette  DEBUG   Resetting recommended pref browser.search.update
1546517667524   Marionette  DEBUG   Resetting recommended pref browser.tabs.disableBackgroundZombification
1546517667524   Marionette  DEBUG   Resetting recommended pref browser.tabs.warnOnCloseOtherTabs
1546517667525   Marionette  DEBUG   Resetting recommended pref browser.tabs.warnOnOpen
1546517667525   Marionette  DEBUG   Resetting recommended pref browser.usedOnWindows10.introURL
1546517667525   Marionette  DEBUG   Resetting recommended pref browser.urlbar.suggest.searches
1546517667525   Marionette  DEBUG   Resetting recommended pref datareporting.policy.dataSubmissionPolicyAccepted
1546517667525   Marionette  DEBUG   Resetting recommended pref dom.disable_beforeunload
1546517667525   Marionette  DEBUG   Resetting recommended pref dom.disable_open_during_load
1546517667525   Marionette  DEBUG   Resetting recommended pref dom.file.createInChild
1546517667525   Marionette  DEBUG   Resetting recommended pref dom.max_chrome_script_run_time
1546517667525   Marionette  DEBUG   Resetting recommended pref dom.max_script_run_time
1546517667525   Marionette  DEBUG   Resetting recommended pref extensions.getAddons.cache.enabled
1546517667525   Marionette  DEBUG   Resetting recommended pref extensions.webservice.discoverURL
1546517667525   Marionette  DEBUG   Resetting recommended pref network.http.prompt-temp-redirect
1546517667526   Marionette  DEBUG   Resetting recommended pref network.http.speculative-parallel-limit
1546517667526   Marionette  DEBUG   Resetting recommended pref security.fileuri.strict_origin_policy
1546517667526   Marionette  DEBUG   Resetting recommended pref security.notification_enable_delay
1546517667526   Marionette  DEBUG   Resetting recommended pref signon.autofillForms
1546517667526   Marionette  DEBUG   Resetting recommended pref signon.rememberSignons
1546517667526   Marionette  DEBUG   Resetting recommended pref toolkit.cosmeticAnimations.enabled
1546517667526   Marionette  DEBUG   Remote service is inactive
1546517667761   geckodriver::marionette DEBUG   Browser process stopped: exit code: 0
1546517667771   webdriver::server   DEBUG   <- 200 OK {"value":null}

whimboo commented 5 years ago

As you can see Firefox reached a neterror page with a connectionFailure message when Marionette requested a page load for http://localhost:56900/_test. That could mean that there is no web server running at this port, or some other software (like antivirus) is preventing access to this local port.

Spleeding1 commented 5 years ago

It runs ok with Safari and Chrome. Is there anything I can check?

whimboo commented 5 years ago

I would suggest that you create a HTTP log while running your test. You would have to add two environment variables for the Firefox process. Details see https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging#Mac_OS_X. Note the files are huge, but compression should make it possible that you could upload one of those as attachment here.

Or use other network sniffing tools like Wireshark.

Spleeding1 commented 5 years ago

Apparently Wireshark is magical. I tried to record as per Mozilla, but it didn't work and locked up the port and rendered it useless. I rebooted my computer and ran my test. To my surprise it passed. So I tried the '--parallel' option and it sent me back to the error I had before. I recorded a failure (non-parallel) and decided to reboot again to record a success. After recording the success, I tried to get it to fail again, but I cannot get it to. I am attaching both files, but I guess the issue is resolved?

failureFile.txt successFile.txt

whimboo commented 5 years ago

Can you please explain what you mean with --parallel?

In regards of the logs... So yes, in case of failure the connection is always reset when the other end tries to send data to Firefox. You can see this by the RST flag in the response:

No. Time Source Destination Protocol Length Info 98 2.708348 ::1 ::1 TCP 64 50503 → 50537 [RST, ACK] Seq=1 Ack=1 Win=0 Len=0

Firefox then tries again to re-create a connection but also that one is rejected. So there is clearly no problem with geckodriver here. But I'm not sure if Firefox misbehaves here, or if it is a combination with another tool on your system. If you have a firewall enabled try to disable it. Same for any AV software. Maybe this gives an indication.

Spleeding1 commented 5 years ago

When you run tests with Django, you can run multiple tests at the same time with the --parallel flag

python3 manage.py test

runs 1 test at time
test time = Ran 96 tests in 47.618s

python3 manage.py test --parallel

runs 1 test file per core (in my case upto 8)
test time = Ran 96 tests in 18.303s

I actually switched to Chrome as a result of this because it was testing 15-20 seconds faster than Firefox.

Django --parallel

whimboo commented 5 years ago

Ok, thanks. So what happens when you reduce the number of parallel processes? Do you see the same problem when running even only on two cores?

Spleeding1 commented 5 years ago

Well, once it failed(when it did fail) even running 1 single test would produce the same result. Both network trace files I submitted were of a single test, not with the --parallel option.

whimboo commented 5 years ago

Did you already follow my proposals from 2 days ago and tested with the Firewall and maybe other AV software disabled?

Also when this problem happens can you reach the failed to load URL manually in a different instance of Firefox or another browser? Or use curl for it... Just catch the exception and add a sleep which would give you enough time for those steps to execute.

Spleeding1 commented 5 years ago

Well, I would have if it would still fail. But I did manage to create a new failure:

python3 manage.py test --parallel while testing, ctrl-c in Terminal to cancel the testing ran test again

It throws errors exactly where I canceled the test. I switched driver to Chrome, same thing. I restarted computer, same thing. New error:

selenium.common.exceptions.InvalidSessionIdException: Message: Tried to run command without establishing a connection

I may have cancelled a test last time that started the other problem.

whimboo commented 5 years ago

That might be a problem with the test or the Selenium client. In such a case you are trying to use a session which hasn't been started yet.

lock[bot] commented 5 years ago

This issue has been automatically locked since there has not been any recent activity after it was closed. If you have run into an issue you think is related, please open a new issue.

mozilla / geckodriver