moneyadviceservice/frontend — pull request #473 by jongilbraith (2014-07-01 14:39:53+00:00)
Title: Poltergeist

This PR addresses the issue we've been having with js tests where the on page changes we're looking for haven't happened within the default period that capybara waits for (2 seconds). We've also seen requirejs throw an error occasionally but that happened only a couple of times during my tests so I've not looked into it in any depth.

In order to investigate this I made use of the fact that Poltergeist exposes network activity information from Phantomjs at ``page.driver.network_traffic``.

I intercepted the test just after it performed the click action, dumping the time as a point of reference:

```
Jon-Gilbraith-000782:frontend[poltergeist*]$ be cucumber features/cookie_disclosure.feature:19
Using the default profile...
Feature: Cookie Disclosure Statemement
As a webmaster
I want to provide users with information about the MAS's cookie message
So that the website complies with EU cookie law

@javascript
Scenario: Acknowledging the cookie message # features/cookie_disclosure.feature:19
Given I have not previously acknowledged the cookie message # features/step_definitions/cookie_disclosure_steps.rb:10
And I visit the site and see the cookie message # features/step_definitions/cookie_disclosure_steps.rb:44
When I close the cookie message # features/step_definitions/cookie_disclosure_steps.rb:58
2014-07-01 11:59:25 +0100
[1, 10] in /Users/jgilbraith/dev.web/frontend/features/step_definitions/cookie_disclosure_steps.rb
1: Given "debug" do
2: print Time.now.to_s
3: debugger
=> 4: end
```

Then dumped out timestamps and urls of the network requests:

```
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/en
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/frontend-assets/stylesheets/basic.css
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/enhanced_responsive.css
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/requirejs/require.js
2014-07-01 10:59:23 UTC http://www.googletagmanager.com/gtm.js?id=GTM-WVFLH9
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/frontend-assets/images/icon-sprite.png
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/mas-logo.png
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/illustrated_people.png
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/promos/tools-calculators.jpg
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/promos/borrowing.jpg
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/promos/payday-loans.jpg
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/promos/free-debt-advice.jpg
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/application.js
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/modules/common.js
2014-07-01 10:59:23 UTC http://stats.g.doubleclick.net/dc.js
2014-07-01 10:59:23 UTC https://servedby.flashtalking.com/container/3230;18448;2246;iframe/?spotName=MAS_Engagement_conversion&U1=%5B%25INSERT_PAGEURL_HERE%25%5D&cachebuster=284267.01622083783
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/jquery/dist/jquery.js
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/modules/globals.js
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/modules/mas_pubsub.js
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/modules/log.js
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/modules/i18n.js
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/translations/en.js
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/frontend-assets/stylesheets/font_base64.css
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/modules/mas_collapsable.js
2014-07-01 10:59:23 UTC http://127.0.0.1:57316/assets/jquery-ujs/src/rails.js
2014-07-01 10:59:23 UTC data... truncated
2014-07-01 10:59:23 UTC data... truncated
2014-07-01 10:59:23 UTC data... truncated
2014-07-01 10:59:25 UTC http://cdn.widgets.webengage.com/js/widget/webengage-min-v-4.0.js
2014-07-01 10:59:25 UTC http://z.webengage.com/gz.js
2014-07-01 10:59:25 UTC http://127.0.0.1:57316/en/cookie-notice
2014-07-01 10:59:25 UTC http://s3.amazonaws.com/webengage-zfiles/webengage/~1341065bd/v3.js?r=23403539&u=1404212365351d795386888ab5f4c%7C1404212365351
2014-07-01 10:59:26 UTC http://c.webengage.com/e.jpg?event=The%20%3Ca%20style%3D%22color%3A%20%2300f%3B%22%20href%3D%22http%3A%2F%2Fwebengage.com%2F%22%20target%3D%22_blank%22%3EWebEngage%20(Survey%2C%20Feedback%20%26amp%3B%20Notification)%3C%2Fa%3E%20widget%20on%20this%20page%20is%20incorrectly%20configured.%20It%20is%20meant%20for%20use%20only%20on%20%3Cb%3Emoneyadviceservice.org.uk%2C%20qa.test.moneyadviceservice.org.uk%2C%20lind.org.uk%2C%20preview.test.moneyadviceservice.org.uk%2C%20localhost%3A3000%2C%20www.moneyadviceservice.org.uk%3C%2Fb%3E.&category=~1341065bd&type=error&data=%7B'version'%3A'4.0'%2C'text'%3A'The%20%3Ca%20style%3D%22color%3A%20%2300f%3B%22%20href%3D%22http%3A%2F%2Fwebengage.com%2F%22%20target%3D%22_blank%22%3EWebEngage%20(Survey%2C%20Feedback%20%26amp%3B%20Notification)%3C%2Fa%3E%20widget%20on%20this%20page%20is%20incorrectly%20configured.%20It%20is%20meant%20for%20use%20only%20on%20%3Cb%3Emoneyadviceservice.org.uk%2C%20qa.test.moneyadviceservice.org.uk%2C%20lind.org.uk%2C%20preview.test.moneyadviceservice.org.uk%2C%20localhost%3A3000%2C%20www.moneyadviceservice.org.uk%3C%2Fb%3E.'%7D&ts=1404212366051
2014-07-01 10:59:40 UTC https://servedby.flashtalking.com/spot/6/3230;18448;2246/?spotName=MAS_Engagement_conversion&U1=%5B%25INSERT_PAGEURL_HERE%25%5D&cachebuster=284267.01622083783&U1=http%3A%2F%2F127.0.0.1%3A57316%2Fen
2014-07-01 10:59:40 UTC https://servedby.flashtalking.com/container/3230;18668;2246;iframe/?spotName=_3rdPETConvert&cachebuster=279601735&lref=http%3A%2F%2F127.0.0.1%3A57316%2Fen
2014-07-01 10:59:40 UTC https://www.googleadservices.com/pagead/conversion.js
2014-07-01 10:59:40 UTC https://cdn.taboola.com/libtrc/m4cuksc/tfa.js
2014-07-01 10:59:40 UTC https://www.googleadservices.com/pagead/conversion/985371790/?value=0&label=um3gCMK28QUQjqnu1QM&guid=ON&script=0
2014-07-01 10:59:40 UTC https://ad.doubleclick.net/activity;src=2673654;type=coi_b113;cat=2-mai128;ord=1;num=%5BRandom%20Number%5D?
2014-07-01 10:59:40 UTC https://secure.quantserve.com/quant.js
2014-07-01 10:59:40 UTC https://www.googleadservices.com/pagead/conversion/985371790/?random=1404212380877&cv=7&fst=1404212380877&num=1&fmt=3&value=0&label=um3gCMK28QUQjqnu1QM&bg=ffffff&hl=en&guid=ON&u_h=900&u_w=1440&u_ah=874&u_aw=1440&u_cd=32&u_his=1&u_tz=60&u_java=false&u_nplug=0&u_nmime=0&frm=2&url=https%3A//servedby.flashtalking.com/container/3230%3B18668%3B2246%3Biframe/%3FspotName%3D_3rdPETConvert%26cachebuster%3D279601735%26lref%3Dhttp%253A%252F%252F127.0.0.1%253A57316%252Fen&ref=https%3A//servedby.flashtalking.com/container/3230%3B18448%3B2246%3Biframe/%3FspotName%3DMAS_Engagement_conversion%26U1%3D%5B%25INSERT_PAGEURL_HERE%25%5D%26cachebuster%3D284267.01622083783
2014-07-01 10:59:40 UTC https://googleads.g.doubleclick.net/pagead/viewthroughconversion/985371790/?value=0&label=um3gCMK28QUQjqnu1QM&guid=ON&script=0&ctc_id=CAIVAgAAAB0CAAAA&ct_cookie_present=false&convclickts=0&random=661711476
2014-07-01 10:59:40 UTC https://googleads.g.doubleclick.net/pagead/viewthroughconversion/985371790/?random=1110525843&cv=7&fst=1404212380877&num=1&fmt=3&value=0&label=um3gCMK28QUQjqnu1QM&bg=ffffff&hl=en&guid=ON&u_h=900&u_w=1440&u_ah=874&u_aw=1440&u_cd=32&u_his=1&u_tz=60&u_java=false&u_nplug=0&u_nmime=0&frm=2&url=https%3A//servedby.flashtalking.com/container/3230%3B18668%3B2246%3Biframe/%3FspotName%3D_3rdPETConvert%26cachebuster%3D279601735%26lref%3Dhttp%253A%252F%252F127.0.0.1%253A57316%252Fen&ref=https%3A//servedby.flashtalking.com/container/3230%3B18448%3B2246%3Biframe/%3FspotName%3DMAS_Engagement_conversion%26U1%3D%5B%25INSERT_PAGEURL_HERE%25%5D%26cachebuster%3D284267.01622083783&ctc_id=CAIVAgAAAB0CAAAA&ct_cookie_present=false&convclickts=0
2014-07-01 10:59:41 UTC https://www.google.com/ads/conversion/985371790/?value=0&label=um3gCMK28QUQjqnu1QM&guid=ON&script=0&ctc_id=CAIVAgAAAB0CAAAA&ct_cookie_present=false&random=661711476&cdct=2&convclickts=0&random=2560523558
2014-07-01 10:59:41 UTC https://www.google.com/ads/conversion/985371790/?random=1110525843&cv=7&fst=1404212380877&num=1&fmt=3&value=0&label=um3gCMK28QUQjqnu1QM&bg=ffffff&hl=en&guid=ON&u_h=900&u_w=1440&u_ah=874&u_aw=1440&u_cd=32&u_his=1&u_tz=60&u_java=false&u_nplug=0&u_nmime=0&frm=2&url=https%3A//servedby.flashtalking.com/container/3230%3B18668%3B2246%3Biframe/%3FspotName%3D_3rdPETConvert%26cachebuster%3D279601735%26lref%3Dhttp%253A%252F%252F127.0.0.1%253A57316%252Fen&ref=https%3A//servedby.flashtalking.com/container/3230%3B18448%3B2246%3Biframe/%3FspotName%3DMAS_Engagement_conversion%26U1%3D%5B%25INSERT_PAGEURL_HERE%25%5D%26cachebuster%3D284267.01622083783&ctc_id=CAIVAgAAAB0CAAAA&ct_cookie_present=false&cdct=2&convclickts=0&random=1661677394
2014-07-01 10:59:41 UTC https://www.google.co.uk/ads/conversion/985371790/?value=0&label=um3gCMK28QUQjqnu1QM&guid=ON&script=0&ctc_id=CAIVAgAAAB0CAAAA&ct_cookie_present=false&random=661711476&cdct=2&convclickts=0&random=2560523558&ipr=y
2014-07-01 10:59:41 UTC https://www.google.co.uk/ads/conversion/985371790/?random=1110525843&cv=7&fst=1404212380877&num=1&fmt=3&value=0&label=um3gCMK28QUQjqnu1QM&bg=ffffff&hl=en&guid=ON&u_h=900&u_w=1440&u_ah=874&u_aw=1440&u_cd=32&u_his=1&u_tz=60&u_java=false&u_nplug=0&u_nmime=0&frm=2&url=https%3A//servedby.flashtalking.com/container/3230%3B18668%3B2246%3Biframe/%3FspotName%3D_3rdPETConvert%26cachebuster%3D279601735%26lref%3Dhttp%253A%252F%252F127.0.0.1%253A57316%252Fen&ref=https%3A//servedby.flashtalking.com/container/3230%3B18448%3B2246%3Biframe/%3FspotName%3DMAS_Engagement_conversion%26U1%3D%5B%25INSERT_PAGEURL_HERE%25%5D%26cachebuster%3D284267.01622083783&ctc_id=CAIVAgAAAB0CAAAA&ct_cookie_present=false&cdct=2&convclickts=0&random=1661677394&ipr=y
2014-07-01 10:59:41 UTC https://pixel.quantserve.com/pixel;r=1995181212;a=p-2fHbswEM91IBo;labels=_fp.event.02%20Main%20Site%20Engaged%20Visit;fpan=1;fpa=P0-1577147283-1404212381729;ns=1;ce=1;cm=;je=0;sr=1440x900x32;enc=n;dst=1;et=1404212381728;tzo=-60;ref=https%3A%2F%2Fservedby.flashtalking.com%2Fcontainer%2F3230%3B18448%3B2246%3Biframe%2F%3FspotName%3DMAS_Engagement_conversion%26U1%3D%5B%25INSERT_PAGEURL_HERE%25%5D%26cachebuster%3D284267.01622083783;url=https%3A%2F%2Fservedby.flashtalking.com%2Fcontainer%2F3230%3B18668%3B2246%3Biframe%2F%3FspotName%3D_3rdPETConvert%26cachebuster%3D279601735%26lref%3Dhttp%253A%252F%252F127.0.0.1%253A57316%252Fen;ogl=
```

You can see from here that there's a ton of loading left to be done after the 2 second timeout window. It's not all blocking, but seems safe to assume that it might still be loading after only 2 seconds.

I extended the window to 20 seconds and I have had no more failures, seeming not to need more than a few extra seconds anyway.

Another test I did that supports this hypothesis is that I put all the webengage and flashtalking hosts into my hosts file, pointing at localhost, causing those requests to fail (and not spawn a bunch more requests).

When I did that I found that I didn't have any issues when the timeout still being 2 seconds.

If I remember correctly, these issues started when we added a bunch of javascript to the site (think it was Webengage).