Support for Drupal 7 is ending on 5 January 2025—it’s time to migrate to Drupal 10! Learn about the many benefits of Drupal 10 and find migration tools in our resource center.
Problem/Motivation
While debugging #2830485: \Drupal\Tests\outside_in\FunctionalJavascript\OutsideInBlockFormTest fails randomly we found that Javascript conditions/assertions always do an unnecessary 100ms wait and created https://github.com/jcalderonzumba/MinkPhantomJSDriver/pull/68 , which was accepted and released. We should use this new version now in Drupal to shave off a couple of seconds when running tests.
Proposed resolution
jcalderonzumba/gastonjs v1.0.2 v1.2.0 PhantomJS API based server for webpage automation
jcalderonzumba/mink-phantomjs-driver v0.3.1 v0.3.3 PhantomJS driver for Mink framework
Comment | File | Size | Author |
---|---|---|---|
#128 | 2832672-128.patch | 3.1 KB | martin107 |
Comments
Comment #2
klausiPatch.
Comment #4
klausiVery interesting. So with this patch we immediately see even more JavascriptTestBase fails. assertWaitOnAjaxRequest() looks most suspicious to me because it has a way too generic JS condition that might not apply correctly in all instances.
A JS condition should test for example if an element is visible. Checking if jQuery is active is not specific enough and seems dangerous to me.
Next steps for this issue:
1) Make a patch that runs Drupal\Tests\views_ui\FunctionalJavascript\FilterCriteriaTest 50 times which reliably fails all the time.
2) Try to remove all assertWaitOnAjaxRequest() from FilterCriteriaTest and replace them with proper visibility conditions until the 50 test runs pass.
Comment #5
klausiHere is a patch that repeats the failing test 50 times and should always fail.
Comment #7
klausiLet's try a proper JS condition instead of the dubios assertWaitOnAjaxRequest() where the test fails.
Comment #9
klausiSo the modified javascript condition also fails on the testbot. But only on PHP 5 on the testbot, not on PHP 7. Same locally, everything passing for me.
Let's see how long the JS assertion actually takes on the testbot and if it runs into the timeout.
Comment #10
klausiComment #12
klausiDoes an even higher timeout help?
Comment #14
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedI applied the patch in #12 and ran the tests via run-tests and directly via phpunit on php 5.5 and 7.1.
I had 1 fail on 5.5 so far locally, so it's actually reproducable. I added screenhots:
I attached 2 screenshots, one for which the test passed and one for a failed test.
As you can see the progress indicator is missing. It seems then that the click on the button somehow failed. No matter how you wait, with this version of Mink (upgraded from 1.6 to 1.7) / jcalderonzumba this test will always randomly fail.
So, is this a bug in Mink / jcalderonzumba or in Drupal?
Comment #15
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedThis got me thinking a little more. Might the failed click have something to do with the random fails in #2830485: \Drupal\Tests\outside_in\FunctionalJavascript\OutsideInBlockFormTest fails randomly?
Both have something to do with clicking a button..
EDIT:
I looked a little closer to the changes from 0.3.1 to 0.3.3, there is a little more to this upgrade than it seems at first sight.
Other changes not in the CHANGELOG:
- The dependencies are updated, making Mink switch from ~1.6 to ~1.7
- The way Javascript code is evaluated is changed (https://github.com/jcalderonzumba/MinkPhantomJSDriver/commit/c25bba0357d...)
Comment #16
klausi@michielnugter: nice research!
I tried to reproduce locally on Ubuntu with PHP 5.5, but PhantomJS randomly hangs again (already reported by other people at https://github.com/ariya/phantomjs/issues/14286 ).
So I have to continue my guessing game here by triggering the testbot. Let's try to click the link before the fail in a different way and see if that works.
Comment #18
klausiSo that also made no difference.
Reverting back to the original test and clicking repeatedly in a while loop, let's see if that makes the test pass.
Comment #19
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedYup, that makes it work..
Maybe debounce() or something like that is causing problems?
Comment #20
klausiLet's try some waiting before the click instead.
Comment #22
klausiOoops, wrong patch file, fixed that.
I don't understand views-admin.js. It has a hidden "Add filter group" button but it adds an artificial link with an event handler that then clicks the button. Why can't we just show the button in place of the link?
At this point my working theory is that the "Create new filter group" link is visible but views-admin.js is not done yet attaching the behavior to click the button. What would be a good jQuery condition that we could use in the test to make sure the event handlers are ready for the link?
Comment #23
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedI see the problem now.
If you click on the "And/Or Rearrange" button an ajax request is fired, returning the HTML for the pop-up. The ajax requests is finished but it also triggers loading additional JavaScript files. After these files are loaded (I assume) Drupal starts executing the behaviors.
The test however continues immediately and it's pretty much random if the test succeeds (the javascript files are loaded fast and behaviors are executed) or failes (loading takes a bit longer and behaviors aren't executed yet).
Funny thing: our performance gain (not waiting an extra 100ms) actually exposed this bug. Before the testbot had an extra 100ms to finish which was enough apparently..
Comment #24
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedI created #2837676: Provide a better way to validate all javascript activity is completed which could be a fix for this issue. I'd like to know if the created issue is a good solution for this problem.
Comment #25
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commented#2837676: Provide a better way to validate all javascript activity is completed is in and should have fixed our random fail for this issue. However, because the usage of assertWaitOnAjaxRequest is discouraged and still required I think we should add a comment for this testcase to indicate the wait is required in this case.
Would this be in scope for this issue?
Comment #26
klausiYes, absolutely.
The patch needs work anyway because the current blind wait for 500ms is surely not good enough.
Comment #27
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedThe 500ms is not required anymore as the assertWaitOnAjaxRequest now waits for the complete request to finish, yay :)
I updated the test to either use the new wait methods or document why they're not used. I attached a 50x version as well to see if it doesn't trigger random fails.
Comment #28
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedComment #30
klausiThat does not work, test is failing now at line 65.
Comment #31
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedChecked the logs, the fail is random unfortunately.
Changed the implementation slightly to make it wait for the UI first and then the ajax request.
Comment #32
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedComment #36
droplet CreditAttribution: droplet commentedShould / Can we split into 2 issues?
One for upgrade
One for improving & fixed
Comment #37
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedsounds like a plan, we have to postpone this one for the fix-issue though..
Comment #38
klausiNo, we can only upgrade with all tests passing. Tests have to be green at all times.
Comment #40
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedI think the problem may be with that the link was available in the DOM but not yet visible. I changed the way the button is checked. It now passes locally using run-tests.sh.
Comment #42
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedRight 8.4.x...
Comment #43
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedComment #45
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedTime for some coffee I guess.
Retried the package upgrade..
Comment #47
droplet CreditAttribution: droplet commentedWhat does the bot say?
Comment #50
droplet CreditAttribution: droplet commentedComment #52
droplet CreditAttribution: droplet commented@michielnugter's patch worked on my local too.
What does bot say again?
Comment #54
droplet CreditAttribution: droplet commentedchecking the test log, some of them are passed and it took almost 10 sec to execute it. Increasing the timeout.
Comment #56
droplet CreditAttribution: droplet commentedI could see above test is failed.
https://dispatcher.drupalci.org/job/drupal_patches/329/console
last test, what if it doesn't upgrade the mink driver?
Comment #58
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedI was able to reproduce the random fails locally now on 8.4.x using run-tests.sh :(
Comment #59
tacituseu CreditAttribution: tacituseu commentedJust checking something, not sure this is the best way to do this.
Comment #61
tacituseu CreditAttribution: tacituseu commentedOnce more...
Comment #63
tacituseu CreditAttribution: tacituseu commentedSome more tracking...
Comment #65
tacituseu CreditAttribution: tacituseu commentedComment #66
tacituseu CreditAttribution: tacituseu commentedComment #67
tacituseu CreditAttribution: tacituseu commentedWhat happens is
'#views-add-group-link'
is created and.on('click.views-rearrange-filter-handler', $.proxy(this, 'clickAddGroupButton'));
is bound just fine, but in failed tests it never actually triggers, because inmisses the link, it clicks just above it ;)
For details search
phantomjs.err.log
for: "( QEvent::Type(MouseButtonPress) ) QPoint(252,".- the good ones have:
Mouse Event: "mousedown" ( QEvent::Type(MouseButtonPress) ) QPoint(252,324) ) 1 1
and a couple of lines higher result of
.position()
on it:result QVariant(QString, "{\"value\":{\"top\":313,\"right\":357,\"left\":146,\"bottom\":335,\"width\":211,\"height\":22}}")
- the bad one have:
Mouse Event: "mousedown" ( QEvent::Type(MouseButtonPress) ) QPoint(252,300) ) 1 1
result QVariant(QString, "{\"value\":{\"top\":289,\"right\":357,\"left\":146,\"bottom\":311,\"width\":211,\"height\":22}}")
So possibly late .css load or some element (button) hiding script makes it "jump".
Screenshots from #14 were very helpful, attached confirmation patch just makes the button easier target.
Comment #69
tacituseu CreditAttribution: tacituseu commentedForgot to include
run-tests.sh
...Comment #70
tacituseu CreditAttribution: tacituseu commentednow with test from #55, changed selector to 'named_exact' because:
Comment #72
tacituseu CreditAttribution: tacituseu commentedFailing now have
.position()
:result QVariant(QString, "{\"value\":{\"top\":269,\"right\":357,\"left\":146,\"bottom\":330,\"width\":211,\"height\":61}}")
and the good ones:
result QVariant(QString, "{\"value\":{\"top\":293,\"right\":357,\"left\":146,\"bottom\":354,\"width\":211,\"height\":61}}")
Comment #73
droplet CreditAttribution: droplet commented@tacituseu,
Are you a member of tesbot team? how do you obtain the debug message from d.org testbot?
Comment #74
tacituseu CreditAttribution: tacituseu commented@droplet: 'View results on dispatcher' then 'Build Artifacts', not a member
Comment #76
droplet CreditAttribution: droplet commentedThanks @tacituseu!
Comment #78
droplet CreditAttribution: droplet commentedvery unstable :s
#73 JS one worked anyway.
Comment #79
tacituseu CreditAttribution: tacituseu commentedI wonder...
Comment #81
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedWhat I can conclude from all the tests above is that it might be the case that it might be possible that the add button could not be clicked.
I've been looking at the behavior of the dialog in views and there is some animation going on when opening the dialog and iteracting with it.
I think the test should wait somehow for everything to finish moving and initializing before continueing the test. It seems the jQuery :animate doesn't catch this yet. I think a random wait of even 1 ms in javascript would fix this because of the way the javascript engine works.
Gone think about this.
Comment #82
droplet CreditAttribution: droplet commentedComment #83
tacituseu CreditAttribution: tacituseu commentedMore guessing, 24 is just such a nice number, and it happens to be the .gif size.
Edit: doesn't look like it.
Comment #85
droplet CreditAttribution: droplet commentedProblems come from dialog.position.js. To see if it's true.
EDIT:
Patch is failed but this is a NEW failing point.
The problem is really come from dialog.position.js. It displayed at half bottom part first, and then move to middle aligned with non-animated CSS.
During the movement, PhantomJS performed a click.
For now, as a temp workaround for random failture,
1. Commit Patch #73, the JS patch first.
2. [new issue] Introduce a '.is-loaded' class #82 (Or checking jQuery UI to see if there's already an option for that)
3. [new issue, must-do] Rewrite dialog.position.js for better performance.
Thanks ALL.
Comment #87
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedI have an alternative solution which checks on the dialog beeing opened or not via javascript. I added a javascript file via a test module to enable this.
Might be needed to move the test module and rename it, for now it's to see what you think of this direction.
@droplet:
1: As this isn't a random failure currently occuring on the test-bot I'd say we should wait untill we have a solution we can all agree on. As long as we don't update the PhantomJS driver this test will not fail randomly.
2: I think I actually have that with this patch right? Using a different approach though..
3: If and when we rewrite something I'd say we should wait and do it in ES6, seems like wasted effort to do it earlier and it's not that bad currently I think.
Comment #88
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedIs it really this kind of a day... Patch now attached..
Comment #90
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedRedid the update via composer, hope it works this time.
Question: shouldn't I only add composer.json and not the .lock?
Comment #91
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedComment #93
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedThird time's the charm?
Comment #95
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedgrrrrr
Comment #97
droplet CreditAttribution: droplet commentedReally? So assertWaitOnAjaxRequest make the diff? Comment #7x ~ #8x of my patches are not upgrade the Mink driver.
We have custom event in dialog.position.js. the last event is
.trigger('dialogContentResize');
Anyway, anyone knows how to enable SEVEN theme in D8 testcase? I wonder if testbot will fail with Seven or not.
Comment #98
Lendude@droplet, something along these lines should work (taken from a webtest in #2701829: Extension objects should not implement \Serializable, so might not translate 1-1)
Comment #99
droplet CreditAttribution: droplet commentedComment #101
droplet CreditAttribution: droplet commentedI hope I'm wrong, we spend such long time for 1px diff. What does the bot say?
Comment #102
droplet CreditAttribution: droplet commentedDamn! It passed! So that Mink PhantomJS or PhantomJs itself perform a click on boundary edges.
We should run JSTest on SEVEN theme instead that we have more human reviews on it. It will not shake.
Comment #103
tacituseu CreditAttribution: tacituseu commented@droplet according to debug log it first gets the bounding box of the link e.g. for a good run:
{\"top\":313,\"right\":357,\"left\":146,\"bottom\":335,\"width\":211,\"height\":22}}")
and then calculates middle point (QPoint(252,324)
) and simulates mousedown/mouseup on those coordinates, but for bad run Y turns out at 300px and just before simulated click the link moves by 24px down, so it is no longer in that place.Also observe in your video from #102, @0:09 just after the dialog pops up there is something funny going on with
.ui-dialog-titlebar
seems to have 2 bottom borders spread around 20 pixels apart, it disappears in the same frame the dropdown for 'Add/Or Rearrange' does.Edit: looks like it is from:
<div class="views-override clearfix form--inline views-offset-top" data-drupal-views-offset="top"></div>
.Comment #104
droplet CreditAttribution: droplet commentedUmmm.. Unexplainable... Anyway, the video is captured from Chrome, with CPU throttled (20x slowdown).
The movement from the video less than 24px. And if it clicking on the middle point, it may not miss clicking. (Assume it will click on the element even when it's shaking since the big button on #78 is also working.)
And the only thing I found that about 24px is the padding of
.views-ui-dialog .scroll
.ui-dialog-titlebar
added after Modal is shown:And this event changed the CSS overflow also.
here: #2849628: Strange bar in View UI filters Modal when there are no filter options
Comment #105
tacituseu CreditAttribution: tacituseu commented@droplet: For 24px difference I meant in #67, the bounding box fits the screenshot from #14 (https://www.drupal.org/files/issues/filter.test.passes.jpg), your video looks different, maybe different browser or some changes in HEAD since.
Comment #106
LendudeWell if we really want comprehensive test coverage, we should run all BTB test (so including all JTB test) on all core themes, since the theme can have a big impact on things being clickable/seen/active.
But running them on Seven might not be a bad idea. No idea how much impact that would have on the test run times.
Comment #107
tacituseu CreditAttribution: tacituseu commentedAttached are annotated relevant parts of the log from #66 + a picture from #14, in #67 I tried to test it by making button larger so it would be clicked at least on the edge even by bad click, but dialog.position.js compensated (results in #72) and moved the whole dialog.
Comment #108
tacituseu CreditAttribution: tacituseu commentedFixed typo,
Comment #109
tacituseu CreditAttribution: tacituseu commentedGot it! screenshots from testbot https://www.drupal.org/pift-ci-job/590102, also patch that produces them. Check /jenkins-drupal_patches-1127/artifacts/simpletest/ for the rest.
Creation of .jpg delays it enough to pass but it grabs the screen at the right moment to show what actually happens.
Edit: '-after-findbyid-views-add-group-link.jpg' should be really named '-after-waitForElementVisible-views-add-group-link.jpg' didn't want to re-roll/re-test just for that.
Comment #110
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commented@tacituseu
1. Cool to learn some more about the test-bot and how to create screenshots. Thanks for that!
2. Very good to have proof that that the problem with the random fail is indeed the dialog positioning!
I created a follow-up patch on my previous attempt (interdiff is for that), I changed it a little to trigger after the event fired by the dialog resize. On my machine it passed 25x in a row. Let's see what the test-bot thinks of this and if it's actually a good solution, I'd love feedback on that.
Comment #111
klausiunrelated composer.lock changes - please update your composer installation before running composer update.
debug statement that should be removed?
missing newline at the end of file
what is an "aftercreate"? the code is not doing any "aftercreate"?
wait - so we can only test this if we enable a special dialog_test module? That seems wrong, why can't we come up with a test case that always works? Or fix Views UI instead so that a simple link does not jump around unexpectedly?
Comment #112
tacituseu CreditAttribution: tacituseu commentedThe
dialog.position.js::resetSize()
might be getting triggered because as part of.click()
simulation PhantomJS doesscrollIntoView()
on#views-add-group-link
, so it might be a race within.click()
on client side with 20ms debounce onresetSize()
Comment #113
Mixologicwow. I didnt even know we could take screenshots with the existing testbots. But Im glad I decided to grab the simpletest directory as an artifact just in case people needed it.
Comment #114
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commented@klausi:
1, 2, 3 and 4:
Sorry about that, fixed in this patch.
5:
It's not Views UI but the dialog implementation that's causing this. After opening a dialog a resize / position is triggered to make sure the dialog is viewed in the center of the page. This is triggered debounced on window resize which in turn is triggered on dialog creation. (dialog.position.js lines 92-109).
The code/implementation is not wrong, it has it's use. I don't know if the repositioning/resize can be done in css but I think a javascript solution will be required.
I couldn't think of a way to be able to wait on all resize events to be done without the test module. It can't be done with a single line of javascript because the resize is debounced a wait on event is not enough.
The only alternative to the test module is adding a css class after the dialog is finished as @droplet did in #82.
So to make the dialog opened state testable we either need to:
- Change the core javascript and add the class (#82)
- Add the test module
- I can't think of another solution but would love to see suggestions :)
Comment #115
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedSetting to Major, allthough I'm not 100% sure. The dialog problem and random fails occured in another issue for me:
See:
https://www.drupal.org/node/2846428#comment-11938505
We need to fix the random error, should be split this off into a seperate issue?
Comment #116
michielnugter CreditAttribution: michielnugter as a volunteer and at Synetic commentedI created a separate issue for the dialog assertion change as it could be relavant for other issues (webdriver) as well.
Postponed this issue untill #2856047: Avoid random failures in JavascriptTestBase when testing functionality in a dialog is in.
Comment #117
jibranComment #119
jibranComment #120
jibranHere is a new patch after removing #2856047: Avoid random failures in JavascriptTestBase when testing functionality in a dialog bits also uploaded a combined patch.
Comment #123
alexpottWe need to update at least the driver urgently for PHP 7.2 support - see #2929477: Update jcalderonzumba/mink-phantomjs-driver
Comment #125
jibranReroll.
Comment #127
jibranNeeds another reroll after #2876669: Fix dependency version requirement declarations in components
Comment #128
martin107 CreditAttribution: martin107 as a volunteer commentedreroll
Comment #129
martin107 CreditAttribution: martin107 as a volunteer commentedComment #132
LendudeSince we use Webdriver now, I'm pretty sure we don't care about upgrading these anymore.
But many thanks for the excellent research done here!