Reset implicitly timeout issue. Incorrect operation with TimeoutStack object. Serenity 1.0.42 and ab

Alex Rybkin

unread,

May 26, 2015, 8:44:35 AM5/26/15

to thucydid...@googlegroups.com

Hi guys,
Have anyone faced problem below, regarding incorrect operation with timeout reset in Serenity?
Implicitly timeout in WebDriver is not reset to the previous value correctly. For example after isCurrentlyVisible method was called it creates two similar entries in TimeoutStack instance with value "0" that is used in net.thucydides.core.webdriver.WebDriverFactory.resetTimeouts() method so the implicitly timeout is not reset to the previous value and stays equal to "0" causing unexpected failures. It seems that operation with TimeoutStack while finding elements has some bugs that cause creating of duplicates of timeout values. Please investigate what can be done to fix the issue. I suggest in to be critical for those who move to serenity and actively use implicitly waits.

Seems to be a recall to present issue on github

John Smart

unread,

May 27, 2015, 9:08:58 AM5/27/15

to thucydid...@googlegroups.com, alexa...@gmail.com

If the value doesn't get reset when you call resetTimeouts(), it would be a bug. But I haven't been able to reproduce this at all - the two entries in the TimeoutStack is normal, but they should be cleared when you call the resetTimeouts()

Alex Rybkin

unread,

May 27, 2015, 6:56:40 PM5/27/15

to thucydid...@googlegroups.com, alexa...@gmail.com

Hi. I`ve created a demo project which I hope will help to reproduce the bug on your side.
You just need to import it to IDE and set paths to the chromedriver\phantomjs in your system.
https://drive.google.com/file/d/0BxvxRApe_YizdUgxYmNiZTlZQ1k/view?usp=sharing

In the demo test story tries to check visibility of different elements(present and absent in DOM). While playing around please see how implicitly wait in webdriver and pageobject is changing, how timeoutstack is filling and resetTimeout method works.
I`ve got the following log on y side:

[pool-1-thread-1] INFO HomePage - Checking if existent element visible (isVisible)
[pool-1-thread-1] INFO HomePage - TOOK: 260
[pool-1-thread-1] INFO HomePage - Current Implicitly timeout in Page Object: 5000 MILLISECONDS
[pool-1-thread-1] INFO HomePage - Checking if non-existent element visible (isVisible)
[pool-1-thread-1] INFO HomePage - TOOK: 5054
[pool-1-thread-1] INFO HomePage - Current Implicitly timeout in Page Object: 5000 MILLISECONDS
[pool-1-thread-1] INFO HomePage - Checking if non-existent element currently visible (isCurrentlyVisible)
[pool-1-thread-1] INFO HomePage - TOOK: 56
[pool-1-thread-1] INFO HomePage - Current Implicitly timeout in Page Object: 5000 MILLISECONDS
[pool-1-thread-1] INFO HomePage - Checking if non-existent element 2 visible (isVisible)
[pool-1-thread-1] INFO HomePage - TOOK: 22
[pool-1-thread-1] INFO HomePage - Current Implicitly timeout in Page Object: 5000 MILLISECONDS
[pool-1-thread-1] INFO HomePage - Restoring WebDriver Timeout manually by getDriver().manage().timeouts().implicitlyWait
[pool-1-thread-1] INFO HomePage - Checking if non-existent element 2 visible (isVisible)
[pool-1-thread-1] INFO HomePage - TOOK: 5049
[pool-1-thread-1] INFO HomePage - Current Implicitly timeout in Page Object: 5000 MILLISECONDS
[pool-1-thread-1] INFO HomePage - Setting implicitly wait to 0 by setImplicitTimeout()
[pool-1-thread-1] INFO HomePage - Checking if non-existent element 2 currently visible (isVisible)
[pool-1-thread-1] INFO HomePage - TOOK: 16
[pool-1-thread-1] INFO HomePage - Current Implicitly timeout in Page Object: 0 MILLISECONDS
[pool-1-thread-1] INFO HomePage - Restoring WebDriver Timeout manually by resetImplicitTimeout()
[pool-1-thread-1] INFO HomePage - Checking if non-existent element 2 currently visible (isVisible)
[pool-1-thread-1] INFO HomePage - TOOK: 10
[pool-1-thread-1] INFO HomePage - Current Implicitly timeout in Page Object: 0 MILLISECONDS

Thank You.

Alex Rybkin

unread,

Jun 2, 2015, 5:54:21 AM6/2/15

to thucydid...@googlegroups.com

The problem was suggested to be resolved in 1.0.49 version but there is some issue left.

As I can see the problem have not been fixed fully by the committed changes. Each method, after isCurrentlyVisible() method, is performed with 0 implicitlywait timeout despite the fact that I can see non-zero value of implicitlytimeout wait in PageObject. WebDriverFactory, WebElementImpl classes during test execution. Also I discovered that everything works as expected if we place resetImplicitTimeout() method after isCurrentlyVisible().
So the code below works incorrectly:

searchButton.
searchButton.isCurrentlyVisible();
nonExistentInDomElement.isVisible()
//the timeout for the last method is unexpectedly 0

So the code below works correctly but needs excessive method:

searchButton.
searchButton.isCurrentlyVisible();
resetImplicitTimeout();
nonExistentInDomElement.isVisible()
//the timeout for the last method is default implicitlytimeout set in properties

Please try to do additional investigation in the scope of the issue.

John Smart

unread,

Jun 2, 2015, 10:05:15 PM6/2/15

to Alex Rybkin, thucydid...@googlegroups.com

Hi Alex,

I'm not reproducing this behaviour - are you using WebElements or WebElementFacades? Here is the test that I believe corresponds to this case:

def "Implicit timeout should not be affected by isCurrently* methods"() {

given: "The #slow-loader WebElementFacade field takes 3 seconds to load"

page = openTestPageUsing("phantomjs")

when: "We override the implicit timeout to allow the slow-loader field to load"

page.setImplicitTimeout(5, SECONDS)

and: "isCurrently* methods should not use the implicit timeout"

!page.slowLoadingField.isCurrentlyVisible()

then: "we can reset the driver timeouts to the default value once we are done"

page.driver.currentImplicitTimeout.in(SECONDS) == 5

and: "we can reload a slow loading WebElementFacade normally"

page.slowLoadingField.isDisplayed()

}

Are you sure the dependencies have been updated correctly? If you continue finding this issue, could you create a pull request and add a failing test to https://github.com/serenity-bdd/serenity-core/blob/28b9b7bfd02d007582ce950667da771e65aed892/serenity-core/src/test/groovy/net/serenitybdd/core/pages/integration/WhenManagingWebdriverTimeouts.groovy that reproduces the issue?

Thanks.

John.

--
You received this message because you are subscribed to the Google Groups "Serenity BDD Users Group" group.
To unsubscribe from this group and stop receiving emails from it, send an email to thucydides-use...@googlegroups.com.
To post to this group, send email to thucydid...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

___________________________________________________
John Smart | Wakaleo Consulting | +61 407 247 642
Optimizing your software development process
http://www.wakaleo.com | john....@wakaleo.com
___________________________________________________

The dates for the 2014 BDD workshops have been scheduled! Check out our upcoming BDD/TDD Master classes and our Advanced BDD Requirements Workshops, coming soon to Sydney and Melbourne!

___________________________________________________

Alex Rybkin

unread,

Jun 3, 2015, 7:03:07 PM6/3/15

to thucydid...@googlegroups.com, alexa...@gmail.com

Hi John. I think it will be easier to post the scenario here.

Please try to execute the test below:

def "Element loading times should not be affected by isCurrently* methods"() {

 given: "The element may appear in DOM after 20 seconds"

 environmentVariables.setProperty("webdriver.timeouts.implicitlywait","20000")

 page = openTestPageUsing("firefox")

 when: "we should be able to access some element on the page"

 page.country.isCurrentlyVisible()

 then: "we should be able to wait up to 20 seconds for an element that is not in DOM jet"

page.fieldDoesNotExist.isDisplayed()

Actual result: Test is failed on the last step without timeout with text in log: "org.openqa.selenium.NoSuchElementException: Timed out after 20 seconds. Element could not be loaded".

Expected result: Test is failed on the last step with timeout 20 seconds with text in log: "org.openqa.selenium.NoSuchElementException: Timed out after 20 seconds. Element could not be loaded" and the real timeout is 20 seconds."

If the line page.country.isCurrentlyVisible() is removed then everything works as expected, page.fieldDoesNotExist.isDisplayed() executes with timeout 20 seconds.

Thank You.

John Smart

unread,

Jun 3, 2015, 8:41:28 PM6/3/15

to Alex Rybkin, thucydid...@googlegroups.com

Hi Alex,

Thanks, I think I've isolated the problem - I'll release a version 1.0.50 with the patch for you to try.

Alex Rybkin

unread,

Jun 4, 2015, 9:19:36 AM6/4/15

to thucydid...@googlegroups.com, alexa...@gmail.com

Thanks John.

I`ve checked it on 1.0.50 and everything seems to work fine now.

80Vikram

unread,

Jun 8, 2015, 10:43:58 AM6/8/15

to thucydid...@googlegroups.com

+1

All is well with latest serenity and chromedriver http://chromedriver.storage.googleapis.com/index.html?path=2.16/

@Alex , @John.

Thanks,

Vikram

Alex Rybkin

unread,

Jun 14, 2015, 10:01:38 AM6/14/15

to thucydid...@googlegroups.com, alexa...@gmail.com

John, hi again.

I've recently found that resetting implicitly wait timeout is not working properly.

Try to execute:

def "You can override the implicit wait during test execution"() {
 given: "The #slow-loader field takes 3 seconds to load"


 page = openTestPageUsing("phantomjs")
 when: "We override the implicit timeout to allow the slow-loader field to load"


 page.setImplicitTimeout(100, SECONDS)
 then: "we should be able to access the slow-loader field"
 page.firstElementItem.isVisible()
 and: "we can reset the driver timeouts to the default value once we are done"
 page.resetImplicitTimeout()
 and:
 page.fieldDoesNotExist.isVisible()
 and:
 page.driver.currentImplicitTimeout.in(SECONDS) == 2

While execution you should mention that fieldDoesNotExist will be searched for 100 seconds despite the fact that after implicitly timeout was reset it has to be searched for 2 seconds. What`s more strange about the problem, page.driver.currentImplicitTimeout.in(SECONDS) == 2 works fine and does not throw any error. Please look what can be done with the feature of timeouts managing. It looks to be pretty buggy and I`m afraid that its unexpected behavior will confuse a lot of potential users of the framework.

Thank You.

John Smart

unread,

Jun 14, 2015, 10:05:36 AM6/14/15

to Alex Rybkin, thucydid...@googlegroups.com

Hi Alex,

I'll look at this when I get a chance, but I won't have time for another week or two - but do feel free to dig into the code to see what is going on.

Thanks

John.

We love breaking down silos and helping smart teams collaborate better! Ask about our tailored on-site workshops in Agile Requirements Discovery, Behaviour Driven Development, Agile Development Practices, and Test Automation!

___________________________________________________

John Smart

unread,

Jun 15, 2015, 4:13:34 AM6/15/15

to Alex Rybkin, thucydid...@googlegroups.com

Hi Alex,

Could you try with version 1.0.54?

Николай Колев

unread,

Jun 15, 2015, 9:07:07 AM6/15/15

to thucydid...@googlegroups.com, alexa...@gmail.com

I don't know if it's related issue or not but I'm having problem with any implicit timeout. Everywhere where I have findElements, the driver waits for the time set on implicit timeout before returning any results. Not only when there are no results, but also when there are results. When I remove the implicit wait manually using driver.manage().timeouts().implicitlyWait(0, TimeUnit.miliseconds), all findElements work normally.

Николай Колев

unread,

Jun 15, 2015, 9:22:51 AM6/15/15

to thucydid...@googlegroups.com, alexa...@gmail.com

Also all waits are slow. For example waitForAbsenceOf("#someId.someclass") takes a few seconds (it uses findElements behind the scenes). Have you noticed this problem?

John Smart

unread,

Jun 15, 2015, 9:50:55 AM6/15/15

to Николай Колев, thucydid...@googlegroups.com, Alex Rybkin

What version are you using?

On 15 June 2015 at 14:22, Николай Колев <fester...@gmail.com> wrote:

Also all waits are slow. For example waitForAbsenceOf("#someId.someclass") takes a few seconds (it uses findElements behind the scenes). Have you noticed this problem?

--

You received this message because you are subscribed to the Google Groups "Serenity BDD Users Group" group.
To unsubscribe from this group and stop receiving emails from it, send an email to thucydides-use...@googlegroups.com.
To post to this group, send email to thucydid...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Alex Rybkin

unread,

Jun 15, 2015, 1:12:20 PM6/15/15

to thucydid...@googlegroups.com, alexa...@gmail.com, fester...@gmail.com

Seems to be ok on 1.0.54. I`ll play around with it for couple of days and is case of any unexpected situations will report in this thread.
Thank You.

Николай Колев

unread,

Jun 16, 2015, 3:01:17 AM6/16/15

to thucydid...@googlegroups.com, fester...@gmail.com, alexa...@gmail.com

I was using 1.0.51, but now i switched to 1.0.56 and the issue is still present. I'll play around with it and let you know if I find something.

John Smart

unread,

Jun 16, 2015, 3:10:18 AM6/16/15

to Николай Колев, thucydid...@googlegroups.com, Alex Rybkin

Well, the waitFor*() methods are meant to be slow, that's kind of the point. You should be able to manage how slow (i.e. how long they wait) using the webdriver.wait.for.timeout property.

Николай Колев

unread,

Jun 16, 2015, 3:39:54 AM6/16/15

to thucydid...@googlegroups.com, fester...@gmail.com, alexa...@gmail.com

Yes I know that, but in my case i am using waitForAbsenceOf(".somecss") and this element that I am waiting to disapear, disapears almost immediately, but the method waits untill the timeout has expired. Is this the way it should work?? We just went from thucydides to serenity and we didn't have this problem before. The waitFor* methods worked as expected (waited for the condition OR timeout after the timeout in the config file). At the moment the expected condition is met from the moment the method is called, but the method does not continue and waits for the timeout and only after this returns true. I've debugged it and in the RenderedPageObjectView -> elementIsDisplayed it went to the last catch which is timeoutexception, and was not caught on those before it.

Николай Колев

unread,

Jun 16, 2015, 6:13:28 AM6/16/15

to thucydid...@googlegroups.com, alexa...@gmail.com, fester...@gmail.com

I am looking at the old thucydides code and new serenity code for the same methods and I can see that in RenderedPageObjectView -> elementIsDisplayed is with completely different implementation. I'll pull serenity and try with the old thucydides code. If everything works fine i'll write to you John or create an issue.

вторник, 16 юни 2015 г., 10:10:18 UTC+3, John Smart написа:

Николай Колев

unread,

Jun 16, 2015, 9:21:51 AM6/16/15

to thucydid...@googlegroups.com, alexa...@gmail.com, fester...@gmail.com

So ... I downloaded the current master and tried to change RenderedPageObjectView -> elementIsDisplayed to the old implementation from thucydides. Everything works as expected when I changed it ... you can reproduce the problem with 1 simple waitForAbsenceOf(".qwerty") when there are no such elements. In this case the driver will wait for X seconds(webdriver.wait.for.timeout) before returning to execution of the next line. With the old implementation the driver checks for elements and return to execution immediately when there are no such elements and the condition is met. Here is the implementation of the method that I tried and is working for me:

public boolean elementIsDisplayed(final By byElementCriteria) {
 try { 
List<WebElement> matchingElements = driver.findElements(byElementCriteria); 
for (WebElement webElement : matchingElements) { 
WebElementFacade element = WebElementFacadeImpl.wrapWebElement(driver, webElement, 100); 
if (element.isCurrentlyVisible()) { 
return true; 
} 
} return false; 
} catch (NoSuchElementException noSuchElement) { 
LOGGER.trace("No such element " + noSuchElement); 
return false; 
} catch (StaleElementReferenceException se) { 
LOGGER.trace("Element no longer attached to the DOM " + se); 
return false; 
}
}

I guess that the current implementation which uses waitFor(ExpectedConditions.visibilityOfAllElementsLocatedBy(byElementCriteria));

Is ok BUT the driver below may be waiting for the timeout every time because in the Absence method a if(!elementIsDisplayed()) is used. So the driver waits for the timeout because the expected condition is not met and only after this returns a negative result to the absence method. Can you fix this please? If you need more info email me please.

вторник, 16 юни 2015 г., 10:10:18 UTC+3, John Smart написа:

80Vikram

unread,

Jun 17, 2015, 5:00:25 AM6/17/15

to thucydid...@googlegroups.com, alexa...@gmail.com

I tried using serenity.properties file

webdriver.timeouts.implicitlywait = 30000

but still webdriver doesn't wait for 30 sec.

I've filed an issue https://github.com/serenity-bdd/serenity-core/issues/78

Thanks,

Vikram

80Vikram

unread,

Jul 31, 2015, 9:13:10 AM7/31/15

to Serenity BDD Users Group, alexa...@gmail.com, vikra...@gmail.com

Hi John,

I'm seeing this issue is still reproducible in current version as well 1.1.1.

Can you please have a look

Thanks & Regards,

Vikram

John Smart

unread,

Jul 31, 2015, 9:14:32 AM7/31/15

to 80Vikram, Serenity BDD Users Group, Alex Rybkin

Can you create a test case that reproduces it?

80Vikram

unread,

Aug 4, 2015, 9:28:49 AM8/4/15

to Serenity BDD Users Group, vikra...@gmail.com, alexa...@gmail.com

Hi John,

I couldn't create stand alone TC to reproduce this issue yet

Below is the error log

---

(Session info: chrome=44.0.2403.125)

(Driver info: chromedriver=2.16.333243 (0bfa1d3575fc1044244f21ddb82bf870944ef961),platform=Mac OS X 10.9.5 x86_64) (WARNING: The server did not provide any stacktrace information)

Command duration or timeout: 9 milliseconds

For documentation on this error, please visit: http://seleniumhq.org/exceptions/stale_element_reference.html

Build info: version: '2.46.0', revision: '61506a4624b13675f24581e453592342b7485d71', time: '2015-06-04 10:22:50'

System info: host: '6wbuildbot.local', ip: '10.40.6.215', os.name: 'Mac OS X', os.arch: 'x86_64', os.version: '10.9.5', java.version: '1.8.0_05'

Driver info: org.openqa.selenium.chrome.ChromeDriver

Capabilities [{applicationCacheEnabled=false, rotatable=false, mobileEmulationEnabled=false, chrome={userDataDir=/var/folders/g1/66c6b4qn08d9y0q90fk5v_f00000gs/T/.org.chromium.Chromium.MKdwQC}, takesHeapSnapshot=true, databaseEnabled=false, handlesAlerts=true, hasTouchScreen=false, version=44.0.2403.125, platform=MAC, browserConnectionEnabled=false, nativeEvents=true, acceptSslCerts=true, locationContextEnabled=true, webStorageEnabled=true, browserName=chrome, takesScreenshot=true, javascriptEnabled=true, cssSelectorsEnabled=true}]

Session ID: 506e07f033bd55a2dfdd85bce5942836

at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)

at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)

at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

at java.lang.reflect.Constructor.newInstance(Constructor.java:408)

at org.openqa.selenium.remote.ErrorHandler.createThrowable(ErrorHandler.java:204)

at org.openqa.selenium.remote.ErrorHandler.throwIfResponseFailed(ErrorHandler.java:156)

at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:605)

at org.openqa.selenium.remote.RemoteWebElement.execute(RemoteWebElement.java:269)

at org.openqa.selenium.remote.RemoteWebElement.isDisplayed(RemoteWebElement.java:310)

at net.thucydides.core.annotations.locators.SmartAjaxElementLocator.isElementUsable(SmartAjaxElementLocator.java:129)

at net.thucydides.core.annotations.locators.SmartAjaxElementLocator$SlowLoadingElement.isLoaded(SmartAjaxElementLocator.java:217)

at org.openqa.selenium.support.ui.SlowLoadableComponent.get(SlowLoadableComponent.java:59)

at net.thucydides.core.annotations.locators.SmartAjaxElementLocator.ajaxFindElement(SmartAjaxElementLocator.java:138)

at net.thucydides.core.annotations.locators.SmartAjaxElementLocator.findElement(SmartAjaxElementLocator.java:93)

at org.openqa.selenium.support.pagefactory.internal.LocatingElementHandler.invoke(LocatingElementHandler.java:38)

at com.sun.proxy.$Proxy16.isEnabled(Unknown Source)

at net.serenitybdd.core.pages.WebElementFacadeImpl.isEnabled(WebElementFacadeImpl.java:539)

----------

Not sure why it's getting times out in 9 milisecons even when serenity.properties has entry

webdriver.wait.for.timeout = 30000

webdriver.timeouts.implicitlywait = 10000

80Vikram

unread,

Aug 7, 2015, 6:13:35 AM8/7/15

to Serenity BDD Users Group, vikra...@gmail.com, alexa...@gmail.com

Hi John,

Found similar failure with isEnabled( ) method , it doesn't wait for default time specified in serenity.properties

It's getting timed out in 24 miliseconds and I'm running this test cases stand alone not sure what made it change to this new value

------

Command duration or timeout: 24 milliseconds

For documentation on this error, please visit: http://seleniumhq.org/exceptions/stale_element_reference.html

Build info: version: '2.46.0', revision: '61506a4624b13675f24581e453592342b7485d71', time: '2015-06-04 10:22:50'

System info: host: '6wbuildbot.local', ip: '10.40.6.215', os.name: 'Mac OS X', os.arch: 'x86_64', os.version: '10.9.5', java.version: '1.8.0_05'

Driver info: org.openqa.selenium.chrome.ChromeDriver

Capabilities [{applicationCacheEnabled=false, rotatable=false, mobileEmulationEnabled=false, chrome={userDataDir=/var/folders/g1/66c6b4qn08d9y0q90fk5v_f00000gs/T/.org.chromium.Chromium.9nlH2A}, takesHeapSnapshot=true, databaseEnabled=false, handlesAlerts=true, hasTouchScreen=false, version=44.0.2403.130, platform=MAC, browserConnectionEnabled=false, nativeEvents=true, acceptSslCerts=true, locationContextEnabled=true, webStorageEnabled=true, browserName=chrome, takesScreenshot=true, javascriptEnabled=true, cssSelectorsEnabled=true}]

Session ID: f9894c203d10993260562d1628ae28e6