Skip to content

[#75] Fix a timing bug with poltergeist/turbolinks #76

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Aug 5, 2014

Conversation

xionon
Copy link
Contributor

@xionon xionon commented Aug 5, 2014

There's a timing bug in ViewHelperTest that randomly results in
ReferenceError: Turbolinks Not Found. This causes unrelated builds
to fail, which gums up the whole open source works.

Per https://github.com/teampoltergeist/poltergeist#timing-problems, the
suggested way of fixing this is to just add calls to sleep.

If you wish to test this in the future, use the shell code:

for i in seq 1 10; do rake appraisal; done

This should give you enough test runs to hit the timing bug at least
once.

There's a timing bug in ViewHelperTest that randomly results in
```ReferenceError: Turbolinks Not Found```. This causes unrelated builds
to fail, which gums up the whole open source works.

Per https://github.com/teampoltergeist/poltergeist#timing-problems, the
suggested way of fixing this is to just add calls to sleep.

If you wish to test this in the future, use the shell code:

```for i in `seq 1 10`; do rake appraisal; done```

This should give you enough test runs to hit the timing bug at least
once.
@jtmalinowski
Copy link
Collaborator

I have been working with some more sophisticated scenarios with Capybara lately - I think depending on the version either wait_until or synchronize would work here as the best solution - but even they are not recommended. Adding sleeps definitely isn't recommended. Anyway, you wrote the code that works and fixes this - I didn't - so this must be appreciated. Big thanks @xionon! We just need to slightly improve it a little :)

@xionon
Copy link
Contributor Author

xionon commented Aug 6, 2014

@JakubMal I'd love to see your scenarios, I'm not up-to-date with Capybara and would definitely appreciate looking at something more sophisticated. And I totally agree this needs improvement. I tried, but I was unable to get wait_until to work properly.

# wait_until was removed from Capybara 2
require 'timeout'
def wait_until
  Timeout.timeout(Capybara.default_wait_time) do
    until value = yield
      sleep 0.1
    end
  end
  value
end
# ...snip...
wait_until { page.evaluate_javascript 'typeof Turbolinks !== "undefined"' }
page.execute_script('Turbolinks.visit("/pages/2");')

At most, it would sleep one cycle, but still throw a ReferenceError. After spending about 2 hours trying to get that to work, I gave up and put in sleep.

FWIW, I haven't been able to find anyone else on Github that is testing Turbolinks by calling Turbolinks.visit. The official Turbolinks repository isn't any help - it looks like their tests are just "call console.log, visually confirm that it worked."

@jtmalinowski
Copy link
Collaborator

Because you need to rescue, otherwise your wait_until looks ok - but Capybara 2 has synchronize built in which does just this.
Also: Why is content-based asserting not fine?

@xionon
Copy link
Contributor Author

xionon commented Aug 7, 2014

@JakubMal

Because you need to rescue, otherwise your wait_until looks ok - but Capybara 2 has synchronize built in which does just this.

The code in the block wouldn't raise an error - it's just evaluating the response. That's what's weird about it - typeof Turbolinks would return "object", but calling Turbolinks.visit would throw a reference error. I'm not familiar with synchronize, maybe that would work better.

Also: Why is content-based asserting not fine?

I didn't write the test, I was only trying to fix it. I think the original intent was to assert that the Turbolinks library itself would keep working with ReactJS. The test probably needs a refactor.

@jtmalinowski
Copy link
Collaborator

Sorry I had a certain preconception of how this should be solved, and assumed you were thinking about it the same way. There is a couple of problems with your solution:

Which version of Capybara supports page.evaluate_javascript 'typeof Turbolinks !== "undefined"' ? Mine does support page.execute_script 'typeof Turbolinks !== "undefined"' which returns nil so it looks like you weren't testing anything?

However - I cannot reproduce the problem with: for i in seq 1 10; do rake appraisal; done so what I did was this:

wait_for_turbolinks_to_be_available()
page.execute_script '_Turbolinks = Turbolinks;'
page.execute_script 'delete Turbolinks;'
page.execute_script 'setTimeout(function () { Turbolinks = _Turbolinks; }, 1000)'

I hope it is self-explaining. Then this:

wait_until { page.execute_script('Turbolinks.visit("/pages/2");') }
assert page.has_content?('Hello Alice')

with this code in test_helper:

require 'timeout'
require 'capybara/rails'
require 'capybara/poltergeist'

# last resort!
def wait_until
  Timeout.timeout(Capybara.default_wait_time) do

    successful = false
    begin
      begin
        yield
        successful = true
      rescue Capybara::Poltergeist::JavascriptError
        successful = false
        sleep 0.1
      end
    end until successful

  end
end

Would you mind trying to reproduce using the above code? (without my faking the Turbolinks not being loaded)

One more thing - I think you can see that this snippet doesn't test anything:

assert page.has_content?('Hello Alice')

# Try Turbolinks javascript API.
wait_until { page.execute_script('Turbolinks.visit("/pages/2");') }
assert page.has_content?('Hello Alice')

visit is asynchronous, so the assert is done before a new page is loaded.

If you confirm that you cannot reproduce the problem with my code - I'll follow with a PR.

@xionon
Copy link
Contributor Author

xionon commented Aug 8, 2014

I'm totally fine with ripping the direct calls to Turbolinks.visit out of the test suite. I'm pretty sure that nobody in the world is actually testing Turbolinks this way, and I'm not surprised that it's flakey. If you search Github for "test Turbolinks.visit", we are the only Ruby repository that actually is testing it like this.

For example, Steve Klabnik's performance test of Turbolinks just uses click_link.

I cannot reproduce the problem with: for i in seq 1 10; do rake appraisal; done

That's really strange! Did you try more than 10 runs? For me, it's not guaranteed that I'll get the error, but it usually shows up 1-in-10 times. Note that a failure doesn't halt execution of the test suite, and since it takes so long to run if you aren't watching it you'll have to scroll.

Which version of Capybara supports page.evaluate_javascript 'typeof Turbolinks !== "undefined"' ? Mine does support page.execute_script 'typeof Turbolinks !== "undefined"' which returns nil so it looks like you weren't testing anything?

I'm very sorry, I was typing from memory, not copying working code, and it looks like my example included a typo. The correct call isevaluate_script, which returns the value of the execution. execute_script just runs the code and returns nil. More on the README. The history for the README on github.com/jnicklas/capybara shows this as being available as far back as 2010.

One more thing - I think you can see that this snippet doesn't test anything:

That's why I was testing to see if Turbolinks was undefined. But then I was still getting errors, so I gave up and used sleep.

If you confirm that you cannot reproduce the problem with my code - I'll follow with a PR.

I threw some puts in your code block, and it's definitely working in some cases:

Yield was unsuccessful, sleeping for 0.1
Yield was successful, returning true

However, I am somewhat reliably seeing this:

PhantomJS has crashed. Please read the crash reporting guide at https://github.com/ariya/phantomjs/wiki/Crash-Reporting and file a bug report at https://github.com/ariya/phantomjs/issues/new with the crash dump file attached: /tmp/79609223-ACFB-45EC-B7D6-79A047415E25.dmp
 = 0.27 s
  1) Error:
test_react_ujs_works_with_Turbolinks(ViewHelperTest):
Capybara::Poltergeist::DeadClient: PhantomJS client died while processing {"name":"execute","args":["Turbolinks.visit(\"/pages/1\");"]}
    /Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/poltergeist-1.5.1/lib/capybara/poltergeist/server.rb:33:in `send'
    /Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/poltergeist-1.5.1/lib/capybara/poltergeist/browser.rb:270:in `command'
    /Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/poltergeist-1.5.1/lib/capybara/poltergeist/browser.rb:110:in `execute'
    /Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/poltergeist-1.5.1/lib/capybara/poltergeist/driver.rb:134:in `execute_script'
    /Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/capybara-2.4.1/lib/capybara/session.rb:512:in `execute_script'
    /Users/alech/personal/react-rails/test/view_helper_test.rb:89:in `block (2 levels) in <class:ViewHelperTest>'
    /Users/alech/personal/react-rails/test/view_helper_test.rb:24:in `block in wait_until'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/timeout.rb:66:in `timeout'
    /Users/alech/personal/react-rails/test/view_helper_test.rb:18:in `wait_until'
    /Users/alech/personal/react-rails/test/view_helper_test.rb:89:in `block in <class:ViewHelperTest>'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/minitest/unit.rb:1301:in `run'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/test/unit/testcase.rb:17:in `run'
    /Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/activesupport-3.2.19/lib/active_support/testing/setup_and_teardown.rb:36:in `block in run'
    /Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/activesupport-3.2.19/lib/active_support/callbacks.rb:436:in `_run__3033053979345895873__setup__4237587085358944638__callbacks'
    /Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/activesupport-3.2.19/lib/active_support/callbacks.rb:405:in `__run_callback'
    /Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/activesupport-3.2.19/lib/active_support/callbacks.rb:385:in `_run_setup_callbacks'
    /Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/activesupport-3.2.19/lib/active_support/callbacks.rb:81:in `run_callbacks'
    /Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/activesupport-3.2.19/lib/active_support/testing/setup_and_teardown.rb:35:in `run'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/minitest/unit.rb:919:in `block in _run_suite'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/minitest/unit.rb:912:in `map'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/minitest/unit.rb:912:in `_run_suite'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/test/unit.rb:657:in `block in _run_suites'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/test/unit.rb:655:in `each'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/test/unit.rb:655:in `_run_suites'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/minitest/unit.rb:867:in `_run_anything'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/minitest/unit.rb:1060:in `run_tests'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/minitest/unit.rb:1047:in `block in _run'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/minitest/unit.rb:1046:in `each'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/minitest/unit.rb:1046:in `_run'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/minitest/unit.rb:1035:in `run'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/test/unit.rb:21:in `run'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/test/unit.rb:774:in `run'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/test/unit.rb:366:in `block (2 levels) in autorun'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/test/unit.rb:27:in `run_once'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/test/unit.rb:365:in `block in autorun'

With a 10x run, I saw this error 4 times. I'm running this on a 15" Retina Macbook Pro, 2.7ghz i7.

@xionon
Copy link
Contributor Author

xionon commented Aug 8, 2014

@jtmalinowski
Copy link
Collaborator

It makes sense to move to click_link.

What's your Phantomjs version? Does this error happen only for rails < 4.0 ?

@xionon
Copy link
Contributor Author

xionon commented Aug 9, 2014

What's your Phantomjs version?

1.9.7

Does this error happen only for rails < 4.0 ?

That would be interesting, but no 😢. I've seen it at least with = 4.0:

>> BUNDLE_GEMFILE=/Users/alech/personal/react-rails/gemfiles/rails_4.0.gemfile bundle exec rake
Run options: --seed 47937

# Running:

.....
Yield was successful, returning true

Yield was unsuccessful, sleeping for 0.1
PhantomJS has crashed. Please read the crash reporting guide at https://github.com/ariya/phantomjs/wiki/Crash-Reporting and file a bug report at https://github.com/ariya/phantomjs/issues/new with the crash dump file attached: /tmp/787FBDAE-BFEF-44F7-9156-0DA0085AA83D.dmp
E.......

Finished in 9.922476s, 1.3102 runs/s, 3.8297 assertions/s.

  1) Error:
ViewHelperTest#test_react_ujs_works_with_Turbolinks:
Capybara::Poltergeist::DeadClient: PhantomJS client died while processing {"name":"execute","args":["Turbolinks.visit(\"/pages/1\");"]}
    poltergeist (1.5.1) lib/capybara/poltergeist/server.rb:33:in `send'
    poltergeist (1.5.1) lib/capybara/poltergeist/browser.rb:270:in `command'
    poltergeist (1.5.1) lib/capybara/poltergeist/browser.rb:110:in `execute'
    poltergeist (1.5.1) lib/capybara/poltergeist/driver.rb:134:in `execute_script'
    capybara (2.4.1) lib/capybara/session.rb:512:in `execute_script'
    /Users/alech/personal/react-rails/test/view_helper_test.rb:89:in `block (2 levels) in <class:ViewHelperTest>'
    /Users/alech/personal/react-rails/test/view_helper_test.rb:24:in `block in wait_until'
    /Users/alech/.rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/timeout.rb:66:in `timeout'
    /Users/alech/personal/react-rails/test/view_helper_test.rb:18:in `wait_until'
    /Users/alech/personal/react-rails/test/view_helper_test.rb:89:in `block in <class:ViewHelperTest>'
    minitest (5.3.5) lib/minitest/test.rb:106:in `block (3 levels) in run'
    minitest (5.3.5) lib/minitest/test.rb:204:in `capture_exceptions'
    minitest (5.3.5) lib/minitest/test.rb:103:in `block (2 levels) in run'
    minitest (5.3.5) lib/minitest/test.rb:256:in `time_it'
    minitest (5.3.5) lib/minitest/test.rb:102:in `block in run'
    minitest (5.3.5) lib/minitest.rb:317:in `on_signal'
    minitest (5.3.5) lib/minitest/test.rb:276:in `with_info_handler'
    minitest (5.3.5) lib/minitest/test.rb:101:in `run'
    minitest (5.3.5) lib/minitest.rb:759:in `run_one_method'
    minitest (5.3.5) lib/minitest.rb:293:in `run_one_method'
    minitest (5.3.5) lib/minitest.rb:287:in `block (2 levels) in run'
    minitest (5.3.5) lib/minitest.rb:286:in `each'
    minitest (5.3.5) lib/minitest.rb:286:in `block in run'
    minitest (5.3.5) lib/minitest.rb:317:in `on_signal'
    minitest (5.3.5) lib/minitest.rb:306:in `with_info_handler'
    minitest (5.3.5) lib/minitest.rb:285:in `run'
    minitest (5.3.5) lib/minitest.rb:149:in `block in __run'
    minitest (5.3.5) lib/minitest.rb:149:in `map'
    minitest (5.3.5) lib/minitest.rb:149:in `__run'
    minitest (5.3.5) lib/minitest.rb:126:in `run'
    minitest (5.3.5) lib/minitest.rb:55:in `block in autorun'

13 runs, 38 assertions, 0 failures, 1 errors, 0 skips
rake aborted!
Command failed with status (1): [ruby -I"lib:lib:test" -I"/Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/rake-10.3.2/lib" "/Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/gems/rake-10.3.2/lib/rake/rake_test_loader.rb" "test/**/*_test.rb" ]
/Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/bin/ruby_executable_hooks:15:in `eval'
/Users/alech/.rvm/gems/ruby-2.0.0-p481@react-rails/bin/ruby_executable_hooks:15:in `<main>'
Tasks: TOP => default => test
(See full trace by running task with --trace)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants