search

thoughtbot / capybara-webkit

A Capybara driver for headless WebKit to test JavaScript web apps
https://thoughtbot.com/open-source
MIT License
1.97k stars 428 forks source link

Cucumber/Capybara response error 'Unable to load URL` #667

Closed GolfyMcG closed 9 years ago

GolfyMcG commented 9 years ago

I've been struggling with this issue for a few days and can't figure out what's causing the problem. The test suite runs fine on TravisCI, and locally when I restart my computer. After doing something locally though, I keep getting the same error message:

Unable to load URL: http://localhost.dev:3001/en/users/sign_in because of error loading http://localhost.dev:3001/en/users/sign_in: Unknown error (Capybara::Webkit::InvalidResponseError)

Here is the full webkit-debug trace:

Using the default profile...
..........Finished "EnableLogging" with response "Success()"
Wrote response true ""
Received "Visit"
Started "Visit"
Load started
"Visit" started page load
Started request to "http://localhost.dev:3001/en/users/sign_in"
Finished "Visit" with response "Success()"
Received 0 from "http://localhost.dev:3001/en/users/sign_in"
Page finished with false
Load finished
Page load from command finished
Wrote response false "{"class":"InvalidResponseError","message":"Unable to load URL: http://localhost.dev:3001/en/users/sign_in because of error loading http://localhost.dev:3001/en/users/sign_in: Unknown error"}"
F-Received "Reset"
Started "Reset"
undefined|0|SECURITY_ERR: DOM Exception 18: An attempt was made to break through the security policy of the user agent.
Finished "Reset" with response "Success()"
Wrote response true ""
Received "FindXpath"
Started "FindXpath"
Finished "FindXpath" with response "Success()"
Wrote response true ""
..........F--------

(::) failed steps (::)

Unable to load URL: http://localhost.dev:3001/en/users/sign_in because of error loading http://localhost.dev:3001/en/users/sign_in: Unknown error (Capybara::Webkit::InvalidResponseError)

This comes up anywhere in the app that I try to visit a path. From what I understand, the "Unknown error" is from qt, not capybara-webkit, but I'm not quite sure who would be best to ask. I am using DNSmasq for subdomains and we have multiple languages so localhost:3000 is redirected to www.localhost.dev:3000/en.

Current versions of things: capybara 2.4.1 capybara-webkit 1.1.0 cucumber 1.3.14 cucumber-rails 1.4.0 pg 0.7.1 rails 4.0.0 ruby 2.1.2

dnsmasq 2.71 postgresql 9.3.5 qt 4.8.6 OSX - Mavericks 10.9.4

Edit 1: Stack Overflow Edit 2: This is a rails app Edit 3: test.log gist

GolfyMcG commented 9 years ago

Also posted on SO: http://stackoverflow.com/questions/25875766/capybara-webkit-unable-to-load-url

jferris commented 9 years ago

Is this a Rails app? I'd try looking through the test.log around where the request fails. You may also want to play with show_exceptions in config/environments/test.rb, as that can mask failures.

GolfyMcG commented 9 years ago

I can post the test log file shortly but I couldn't find anything useful myself.

On Tuesday, September 16, 2014, Joe Ferris notifications@github.com wrote:

Is this a Rails app? I'd try looking through the test.log around where the request fails. You may also want to play with show_exceptions in config/environments/test.rb, as that can mask failures.

— Reply to this email directly or view it on GitHub https://github.com/thoughtbot/capybara-webkit/issues/667#issuecomment-55791498 .

Alex Villa Johns Hopkins University, Class of 2012 Mechanical Engineering (240) 506-8597 avilla0429@gmail.com

GolfyMcG commented 9 years ago

BTW, this is a Rails App. Here is the log file: https://gist.github.com/GolfyMcG/060053eba51a9ba69722

GolfyMcG commented 9 years ago

I also changed show_exceptions and there were no additional details.

jferris commented 9 years ago

I don't see any of the URLs from capybara-webkit's log in your test.log. Are you sure you don't have Capybara configured to hit your development server instead? Anything related in development.log?

GolfyMcG commented 9 years ago

Nothing is being written to development.log. The output from test.log is everything produced from one of the (numerous) failing scenarios.

GolfyMcG commented 9 years ago

I restarted my computer to get this to pass (for now) and here is the test.log for a successful run:

https://gist.github.com/GolfyMcG/b8c59ed618e3fd95344b

jferris commented 9 years ago

The test.log looks strange to me. It doesn't show the usual Rails controller output I'm used to. Here's an example from the app I'm working on now:

Started POST "/repositories/name-1/licenses" for 127.0.0.1 at 2014-09-16 15:44:53 -0400
Processing by LicensesController#create as HTML
  Parameters: {"repository_id"=>"name-1"}
  User Load (0.4ms)  SELECT  "users".* FROM "users"  WHERE "users"."remember_token" = '955eb53676171de461eedb247029b0616105ae98'  ORDER BY "users"."id" ASC LIMIT 1
  Subscription Load (0.2ms)  SELECT  "subscriptions".* FROM "subscriptions"  WHERE "subscriptions"."user_id" = $1 LIMIT 1  [["user_id", 2]]
  Product Load (0.3ms)  SELECT  "products".* FROM "products"  WHERE "products"."slug" = 'name-1'  ORDER BY "products"."id" ASC LIMIT 1
  Plan Load (0.2ms)  SELECT  "plans".* FROM "plans"  WHERE "plans"."id" = $1 LIMIT 1  [["id", 1]]
  CACHE (0.0ms)  SELECT  "products".* FROM "products"  WHERE "products"."slug" = 'name-1'  ORDER BY "products"."id" ASC LIMIT 1
  SQL (0.4ms)  INSERT INTO "licenses" ("created_at", "licenseable_id", "licenseable_type", "updated_at", "user_id") VALUES ($1, $2, $3, $4, $5) RETURNING "id"  [["created_at", "2014-09-16 19:44:53.417049"], ["licenseable_id", 1], ["licenseable_type", "Product"], ["updated_at", "2014-09-16 19:44:53.417049"], ["user_id", 2]]
Redirected to http://www.example.com/name-1
Completed 302 Found in 29ms (ActiveRecord: 2.6ms)

Your log doesn't have any lines like "Started GET to ..." or "Processing by xController." This could be because you're using an alternate logging formatter.

On the other hand, your capybara-webkit log is making requests like this: Started request to "http://localhost.dev:3001/en/users/sign_in"

While your log is reporting requests like this: GET http://localhost:9200/ [status:200, request:0.004s, query:n/a]

The paths, domains, and port numbers don't match up. Can you explain your setup a little more so that I can understand your logs?

jferris commented 9 years ago

Okay, your second log includes those lines I expected, so I assume that:

How do you spin up the server on localhost.dev:3001? Are you doing it by hand? Are you using Spork or anything?

My best guess is that the background thread/process running your app server is dying at some point, so capybara-webkit can no longer connect to it.

GolfyMcG commented 9 years ago

localhost:9200 is my local elasticsearch instance. localhost.dev:3001 is the test app itself

jferris commented 9 years ago

What manages the app running on localhost.dev:3001? Usually, Rack/Rails apps are served in a background thread by Capybara on a random port. This thread usually spins up for each test run.

GolfyMcG commented 9 years ago

We're not using Spork so I suppose it's by hand? I apologize for my lack of understanding but I've always assumed that the rails environment was loaded somehow in the cucumber/capybara support file:

The most relevant section of that to me is:

#features/support/env.rb
Capybara.server_port = 3001
Capybara.always_include_port = true
Capybara.default_host = 'localhost.dev'
Capybara.app_host = 'http://localhost.dev'
jferris commented 9 years ago

Are you sure you need those configuration options? The usual behavior is to have Capybara spin up your app locally on a random port, and it can generally figure out the host and such by itself.

GolfyMcG commented 9 years ago

Potentially - restarting my computer fixed everything for the time being, as it has in the past. I'm not sure what I do to break it but when it does break again, I'll look at removing some of those options. I believe we do need them though because we are testing subdomain activity and didn't want to rely on something external like lvh.me.

jferris commented 9 years ago

Alright; I'm going to close this, as it doesn't seem like a bug with capybara-webkit, but feel free to comment again if you learn anything new.

GolfyMcG commented 9 years ago

Will do - thank you for helping bounce ideas around! ᐧ

On Tue, Sep 16, 2014 at 4:29 PM, Joe Ferris notifications@github.com wrote:

Alright; I'm going to close this, as it doesn't seem like a bug with capybara-webkit, but feel free to comment again if you learn anything new.

— Reply to this email directly or view it on GitHub https://github.com/thoughtbot/capybara-webkit/issues/667#issuecomment-55808507 .

Alex Villa Johns Hopkins University, Class of 2012 Mechanical Engineering (240) 506-8597 avilla0429@gmail.com

GolfyMcG commented 9 years ago

Found a solution I believe for anyone down the line:

http://apple.stackexchange.com/questions/26616/dns-not-resolving-on-mac-os

Has nothing to do with capybara-webkit but just in case anyone gets this strange error down the line, they can try this : /

Zapotek commented 8 years ago

I'm getting the same error on Kubuntu, I've installed the dependencies as described in: https://github.com/thoughtbot/capybara-webkit/wiki/Installing-Qt-and-compiling-capybara-webkit#debian-testing-unstable-stable-wheezy-ubuntu

The interesting part is that the same operation succeeds the first time but raises an error the second one.

     Capybara::Webkit::InvalidResponseError:
       Unable to load URL: http://127.0.0.1:46172/sites/1 because of error loading http://127.0.0.1:46172/sites/1: Unknown error
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-webkit-1.8.0/lib/capybara/webkit/browser.rb:305:in `check'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-webkit-1.8.0/lib/capybara/webkit/browser.rb:211:in `command'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-webkit-1.8.0/lib/capybara/webkit/browser.rb:31:in `find_xpath'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-webkit-1.8.0/lib/capybara/webkit/driver.rb:53:in `find_xpath'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/node/base.rb:107:in `find_xpath'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/query.rb:110:in `block in resolve_for'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/node/base.rb:80:in `synchronize'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/query.rb:106:in `resolve_for'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/node/finders.rb:34:in `block in find'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/node/base.rb:80:in `synchronize'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/node/finders.rb:32:in `find'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/node/document.rb:23:in `text'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/queries/text_query.rb:17:in `resolve_for'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/node/matchers.rb:454:in `block in assert_text'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/node/base.rb:84:in `synchronize'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/node/matchers.rb:453:in `assert_text'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/session.rb:686:in `block (2 levels) in <class:Session>'
     # /home/zapotek/.rvm/gems/ruby-2.2.3/gems/capybara-2.6.2/lib/capybara/rspec/matchers.rb:64:in `matches?'
     # ./spec/features/sites/edit_spec.rb:467:in `block (5 levels) in <top (required)>'

The operation is quite simple:

Is there some more information I can provide that would help? The test.log file doesn't show anything that stands out.

Zapotek commented 8 years ago

I did some more digging by monkey-patching the Capybara::Webkit::Browser class to print the involved commands.

Success (first try):

"SetTimeout"
[
    [0] -1
]
"ok\n"
"Visit"
[
    [0] "http://127.0.0.1:43445/sites/1/edit"
]
"ok\n"
"FindXpath"
[
    [0] ".//input[./@type = 'submit' or ./@type = 'reset' or ./@type = 'image' or ./@type = 'button'][((./@id = 'Linux, Apache, MySQL, PHP' or ./@value = 'Linux, Apache, MySQL, PHP') or ./@title = 'Linux, Apache, MySQL, PHP')] | .//input[./@type = 'image'][./@alt = 'Linux, Apache, MySQL, PHP'] | .//button[(((./@id = 'Linux, Apache, MySQL, PHP' or ./@value = 'Linux, Apache, MySQL, PHP') or normalize-space(string(.)) = 'Linux, Apache, MySQL, PHP') or ./@title = 'Linux, Apache, MySQL, PHP')] | .//input[./@type = 'image'][./@alt = 'Linux, Apache, MySQL, PHP']"
]
"ok\n"
"Node"
[
    [0] "visible",
    [1] false,
    [2] "1"
]
"ok\n"
"Node"
[
    [0] "tagName",
    [1] false,
    [2] "1"
]
"ok\n"
"Node"
[
    [0] "attribute",
    [1] false,
    [2] "1",
    [3] "disabled"
]
"ok\n"
"Node"
[
    [0] "leftClick",
    [1] false,
    [2] "1"
]
"ok\n"
"FindCss"
[
    [0] "#sidebar button#site_profile-submit"
]
"ok\n"
"Node"
[
    [0] "visible",
    [1] false,
    [2] "2"
]
"ok\n"
"Node"
[
    [0] "leftClick",
    [1] false,
    [2] "2"
]
"ok\n"
"FindXpath"
[
    [0] "/html"
]
"ok\n"
"Node"
[
    [0] "visible",
    [1] false,
    [2] "1"
]
"ok\n"
"Node"
[
    [0] "text",
    [1] false,
    [2] "1"
]
"ok\n"
"Reset"
[]
"ok\n"
"SetTimeout"
[
    [0] -1
]
"ok\n"
"FindXpath"
[
    [0] "/html/body/*"
]
"ok\n"

Failure (second try):

"Visit"
[
    [0] "http://127.0.0.1:43445/sites/1/edit"
]
"ok\n"
"FindXpath"
[
    [0] ".//input[./@type = 'submit' or ./@type = 'reset' or ./@type = 'image' or ./@type = 'button'][((./@id = 'Linux, Apache, MySQL, PHP' or ./@value = 'Linux, Apache, MySQL, PHP') or ./@title = 'Linux, Apache, MySQL, PHP')] | .//input[./@type = 'image'][./@alt = 'Linux, Apache, MySQL, PHP'] | .//button[(((./@id = 'Linux, Apache, MySQL, PHP' or ./@value = 'Linux, Apache, MySQL, PHP') or normalize-space(string(.)) = 'Linux, Apache, MySQL, PHP') or ./@title = 'Linux, Apache, MySQL, PHP')] | .//input[./@type = 'image'][./@alt = 'Linux, Apache, MySQL, PHP']"
]
"ok\n"
"Node"
[
    [0] "visible",
    [1] false,
    [2] "1"
]
"ok\n"
"Node"
[
    [0] "tagName",
    [1] false,
    [2] "1"
]
"ok\n"
"Node"
[
    [0] "attribute",
    [1] false,
    [2] "1",
    [3] "disabled"
]
"ok\n"
"Node"
[
    [0] "leftClick",
    [1] false,
    [2] "1"
]
"ok\n"
"FindCss"
[
    [0] "#sidebar button#site_profile-submit"
]
"ok\n"
"Node"
[
    [0] "visible",
    [1] false,
    [2] "2"
]
"ok\n"
"Node"
[
    [0] "leftClick",
    [1] false,
    [2] "2"
]
"ok\n"
"FindXpath"
[
    [0] "/html"
]
"failure\n"
"Reset"
[]
"ok\n"
"SetTimeout"
[
    [0] -1
]
"ok\n"
"FindXpath"
[
    [0] "/html/body/*"
]
"ok\n"

The command that fails the second time around is:

"FindXpath"
[
    [0] "/html"
]

I'm guessing this means that after clicking #sidebar button#site_profile-submit there's no valid HTML response?

EDIT: When I try to visit one of the test URLs via Firefox I get connection reset errors, which could explain the situation. Does that have anything to do with capybara-webkit?

Zapotek commented 8 years ago

I finally found the solution. The default Capybara.server is :webrick which was causing random failures, once I set it to :puma everything worked.