[🐛 Bug]: Command isElementEnabled returning error 'stale element reference' does not call the onAfterCommand #13921
Description
Have you read the Contributing Guidelines on issues?
- I have read the Contributing Guidelines on issues.
WebdriverIO Version
9.3.1
Node.js Version
v18.20.4
Mode
WDIO Testrunner
Which capabilities are you using?
Config {
"runner": "local",
"waitforTimeout": 5000,
"connectionRetryTimeout": 10000,
"connectionRetryCount": 3,
"framework": "mocha",
"specs": [
"../../src/tests/**/*.test.ts"
],
"mochaOpts": {
"ui": "bdd",
"timeout": 240000,
"retries": 0
},
"reporters": [
[
"allure",
{
"outputDir": "logs/allure-results",
"addConsoleLogs": true
}
],
[
"spec",
{
"showPreface": false,
"realtimeReporting": false
}
]
],
"services": [
[
"appium",
{
"args": {
"port": 4723,
"relaxedSecurity": true,
"log": "./logs/appium.log",
"logFilters": "./appiumPasswordLogFilters.json"
}
}
]
],
"capabilities": [
{
"platformName": "Android",
"appium:udid": "masked",
"appium:automationName": "UiAutomator2",
"appium:appPackage": "com.my.package",
"appium:appActivity": "MainActivity",
"appium:newCommandTimeout": 240,
"appium:noReset": true,
"goto:caps": {
"isLocalRun": true,
"iosEnterpriseBuild": false,
"testUserEmail": "",
"isDevMode": true
},
"appium:settings[allowInvisibleElements]": true,
"appium:locale": "en_US",
"appium:language": ""
}
]What happened?
One line: Some afterCommand events are not triggered when a request fails!
In short, the problem is that we do not have the same number of calls to the beforeCommand and afterCommand. For example, the allure-reporter starts more steps than it can end, which generates a weird report and can even make the generation step hang!
The problem is related to the GET request of isElementEnabled, which returned a 404 with the error stale element reference (See log below). In this case, it throws an error here so the then of the request.makeRequest here will not proceed and will not do the required emit('result') that trigger the afterCommand. In consequence, we will lose a endStephave a different
What is your expected behavior?
All beforeCommand trigger a equivalent afterCommand even when a request fails!
In short, I assume that the request.makeRequest here needs a catch that will do the this.emit('result' for the afterCommand to get triggered.
However, doing so will result in an error that people may not expect, so I wonder about the impact.
Anyway, I added the below catch for fun, finally making all the startStep and endStep even.
.catch((err) => {
log4.error("ERROR", err);
this.emit("result", { command, method, endpoint, body, result: { error: err } });
throw err;
});
If someone can guide me on the proper changes, I can try to open a PR.
The options I'm seeing:
- Add the catch and emit the error as a result
- Remove the throws so the then can trigger correctly
- Implement a new emit('error') that would also trigger a newafterCommandError that would end steps in error and so fix the problem without sending an unexpected error result
How to reproduce the bug.
I have not yet found a way to reduce my example so that it can be shared. I'll try soon to share reproducible bug!
Relevant log output
beforeCommand {
command: 'isElementEnabled',
method: 'GET',
endpoint: '/session/:sessionId/element/00000000-0000-1bac-0000-12a400000c98/enabled',
body: {}
}
response {
statusCode: 404,
body: {
value: {
error: 'stale element reference',
message: 'androidx.test.uiautomator.StaleObjectException',
stacktrace: 'io.appium.uiautomator2.common.exceptions.StaleElementReferenceException: androidx.test.uiautomator.StaleObjectException\n' +
'\tat io.appium.uiautomator2.handler.request.SafeRequestHandler.handle(SafeRequestHandler.java:63)\n' +
'\tat io.appium.uiautomator2.server.AppiumServlet.handleRequest(AppiumServlet.java:259)\n' +
'\tat io.appium.uiautomator2.server.AppiumServlet.handleHttpRequest(AppiumServlet.java:253)\n' +
'\tat io.appium.uiautomator2.http.ServerHandler.channelRead(ServerHandler.java:77)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:366)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:352)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:345)\n' +
'\tat io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:366)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:352)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:345)\n' +
'\tat io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:435)\n' +
'\tat io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293)\n' +
'\tat io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267)\n' +
'\tat io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:250)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:366)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:352)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:345)\n' +
'\tat io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:266)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:366)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:352)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:345)\n' +
'\tat io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1294)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:366)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:352)\n' +
'\tat io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:911)\n' +
'\tat io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:131)\n' +
'\tat io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:611)\n' +
'\tat io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:552)\n' +
'\tat io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:466)\n' +
'\tat io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:438)\n' +
'\tat io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:140)\n' +
'\tat io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144)\n' +
'\tat java.lang.Thread.run(Thread.java:1012)\n' +
'Caused by: androidx.test.uiautomator.StaleObjectException\n' +
'\tat androidx.test.uiautomator.UiObject2.getAccessibilityNodeInfo(UiObject2.java:1018)\n' +
'\tat androidx.test.uiautomator.UiObject2.isEnabled(UiObject2.java:450)\n' +
'\tat io.appium.uiautomator2.model.UiObject2Element.getAttribute(UiObject2Element.java:100)\n' +
'\tat io.appium.uiautomator2.handler.GetElementAttribute.safeHandle(GetElementAttribute.java:24)\n' +
'\tat io.appium.uiautomator2.handler.request.SafeRequestHandler.handle(SafeRequestHandler.java:59)\n' +
'\t... 33 more\n'
}
}
}
beforeCommand {
command: 'findElement',
method: 'POST',
endpoint: '/session/:sessionId/element',
body: { using: 'xpath', value: '//android.widget.EditText' }
}
response {
statusCode: 200,
body: {
value: {
'element-6066-11e4-a52e-4f735466cecf': '00000000-0000-1bac-0000-130200000c98',
ELEMENT: '00000000-0000-1bac-0000-130200000c98'
}
}
}
afterCommand {
command: 'findElement',
method: 'POST',
endpoint: '/session/:sessionId/element',
body: { using: 'xpath', value: '//android.widget.EditText' },
result: {
value: {
'element-6066-11e4-a52e-4f735466cecf': '00000000-0000-1bac-0000-130200000c98',
ELEMENT: '00000000-0000-1bac-0000-130200000c98'
}
}
}
Nb of steps missing end steps: 1
beforeCommand {
command: 'isElementEnabled',
method: 'GET',
endpoint: '/session/:sessionId/element/00000000-0000-1bac-0000-12a400000c98/enabled',
body: {}
}
response {
statusCode: 404,
body: {
value: {
error: 'stale element reference',
message: "The element 'By.xpath: //android.widget.EditText' is not linked to the same object in DOM anymore",
stacktrace: "io.appium.uiautomator2.common.exceptions.StaleElementReferenceException: The element 'By.xpath: //android.widget.EditText' is not linked to the same object in DOM anymore\n" +
'\tat io.appium.uiautomator2.model.ElementsCache.restore(ElementsCache.java:122)\n' +
'\tat io.appium.uiautomator2.model.ElementsCache.get(ElementsCache.java:153)\n' +
'\tat io.appium.uiautomator2.handler.GetElementAttribute.safeHandle(GetElementAttribute.java:23)\n' +
'\tat io.appium.uiautomator2.handler.request.SafeRequestHandler.handle(SafeRequestHandler.java:59)\n' +
'\tat io.appium.uiautomator2.server.AppiumServlet.handleRequest(AppiumServlet.java:259)\n' +
'\tat io.appium.uiautomator2.server.AppiumServlet.handleHttpRequest(AppiumServlet.java:253)\n' +
'\tat io.appium.uiautomator2.http.ServerHandler.channelRead(ServerHandler.java:77)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:366)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:352)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:345)\n' +
'\tat io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:366)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:352)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:345)\n' +
'\tat io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:435)\n' +
'\tat io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293)\n' +
'\tat io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267)\n' +
'\tat io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:250)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:366)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:352)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:345)\n' +
'\tat io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:266)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:366)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:352)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:345)\n' +
'\tat io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1294)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:366)\n' +
'\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:352)\n' +
'\tat io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:911)\n' +
'\tat io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:131)\n' +
'\tat io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:611)\n' +
'\tat io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:552)\n' +
'\tat io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:466)\n' +
'\tat io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:438)\n' +
'\tat io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:140)\n' +
'\tat io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144)\n' +
'\tat java.lang.Thread.run(Thread.java:1012)\n'
}
}
}
isElementEnabled
beforeCommand {
command: 'isElementEnabled',
method: 'GET',
endpoint: '/session/:sessionId/element/00000000-0000-1bac-0000-130200000c98/enabled',
body: {}
}
response { statusCode: 200, body: { value: true } }
afterCommand {
command: 'isElementEnabled',
method: 'GET',
endpoint: '/session/:sessionId/element/00000000-0000-1bac-0000-130200000c98/enabled',
body: {},
result: { value: true }
}
Nb of steps missing end steps: 2
Starting test: "before all" hook for given an authenticated user @smoke @androidOnly
Starting test: should navigate back @smoke
Starting test: should navigate back @smoke
Test
beforeCommand {
command: 'terminateApp',
method: 'POST',
endpoint: '/session/:sessionId/appium/device/terminate_app',
body: { appId: 'com.my.package' }
}
response { statusCode: 200, body: { value: true } }
afterCommand {
command: 'terminateApp',
method: 'POST',
endpoint: '/session/:sessionId/appium/device/terminate_app',
body: { appId: 'com.my.packaget' },
result: { value: true }
}
Nb of steps missing end steps: 2Code of Conduct
- I agree to follow this project's Code of Conduct
Is there an existing issue for this?
- I have searched the existing issues