Open ddubtsov35 opened 4 years ago
mykola-mokhnach
commented
4 years ago I don't observe any server issues there. The client code requests the deletion of the same session twice and that is why the exception is thrown. Consider reviewing the logic on the client side
ddubtsov35
commented
4 years ago @mykola-mokhnach I also see deleting request twice, but this is because in first time response return unusually, without time and response code, see <-- DELETE /wd/hub/session/de93c6d8-561b-4f88-b662-40954cef5867 - - ms - -
instead
<-- DELETE /wd/hub/session/70852429-e460-43bf-a8de-a7fe8b9350f8 200 27 ms - 14
Also, i have successfull performing test log:
18:01:20 ----AFTER TEST TERMINATE APP----
18:01:20 [HTTP] --> POST /wd/hub/session/70852429-e460-43bf-a8de-a7fe8b9350f8/appium/device/terminate_app
18:01:20 [HTTP] {"bundleId":"test.app"}
18:01:20 [debug] [W3C (70852429)] Calling AppiumDriver.terminateApp() with args: ["test.app",null,null,null,"70852429-e460-43bf-a8de-a7fe8b9350f8"]
18:01:20 [debug] [XCUITest] Executing command 'terminateApp'
18:01:20 [debug] [XCUITest] Setting custom timeout to 600000 ms for 'mobileTerminateApp' command
18:01:20 [debug] [WD Proxy] Proxying [POST /wda/apps/terminate] to [POST http://localhost:8102/session/23511D55-022D-4A21-A604-E75225A7665E/wda/apps/terminate] with body: {"bundleId":"test.app"}
18:01:21 [debug] [WD Proxy] Got response with status 200: {"value":true,"sessionId":"23511D55-022D-4A21-A604-E75225A7665E","status":0}
18:01:21 [debug] [W3C (70852429)] Responding to client with driver.terminateApp() result: true
18:01:21 [HTTP] <-- POST /wd/hub/session/70852429-e460-43bf-a8de-a7fe8b9350f----AFTER TEST QUIT----
18:01:21 8/appium/device/terminate_app 200 1041 ms - 14
18:01:21 [HTTP]
18:01:21 [HTTP] --> DELETE /wd/hub/session/70852429-e460-43bf-a8de-a7fe8b9350f8
18:01:21 [HTTP] {}
18:01:21 [debug] [W3C (70852429)] Calling AppiumDriver.deleteSession() with args: ["70852429-e460-43bf-a8de-a7fe8b9350f8"]
18:01:21 [debug] [BaseDriver] Event 'quitSessionRequested' logged at 1583161281186
18:01:21 [Appium] Removing session 70852429-e460-43bf-a8de-a7fe8b9350f8 from our master session list
18:01:21 [debug] [XCUITest] Setting custom timeout to 600000 ms for 'deleteSession' command
18:01:21 [debug] [WD Proxy] Matched '/session/70852429-e460-43bf-a8de-a7fe8b9350f8' to command name 'deleteSession'
18:01:21 [debug] [WD Proxy] Proxying [DELETE /session/70852429-e460-43bf-a8de-a7fe8b9350f8] to [DELETE http://localhost:8102/session/23511D55-022D-4A21-A604-E75225A7665E] with no body
18:01:21 [debug] [WD Proxy] Got response with status 200: "{\n \"value\" : {\n\n },\n \"sessionId\" : \"CF15D077-5604-41CA-9B0E-A6419A4639CC\",\n \"status\" : 0\n}"
18:01:21 [debug] [XCUITest] Not clearing log files. Use clearSystemFiles capability to turn on.
18:01:21 [debug] [iOSLog] Stopping iOS log capture
18:01:21 [debug] [BaseDriver] Event 'quitSessionFinished' logged at 1583161281211 (18:01:21 GMT+0300 (Moscow Standard Time))
18:01:21 [debug] [W3C (70852429)] Received response: null
18:01:21 [debug] [W3C (70852429)] But deleting session, so not returning
18:01:21 [debug] [W3C (70852429)] Responding to client with driver.deleteSession() result: null
18:01:21 [HTTP] <-- DELETE /wd/hub/session/70852429-e460-43bf-a8de-a7fe8b9350f8 200 27 ms - 14
18:01:21 [HTTP]
mykola-mokhnach
commented
4 years ago It might be DELETE request times out because the server does not respond to it. The first thing I would try is to upgrade the server to the most recent version
ddubtsov35
commented
4 years ago I update appium server to v1.6.0 and this exception don't return
Hello, guys, i have a problem. I run test suite in 2 threads, and after some time in random order i have exception. This exception not crash my tests, but in time this execute exception, threads sleep 2 minutes, and this is more. I have 2 question: OR how get around exception OR how change execution command time (i try driver.manage().timeouts().setScriptTimeout(SCRIPT_TIMEOUT, TimeUnit.MILLISECONDS), but this is not working)
Appium v1.13.0 java-client 6.1.0 selenide-appium 1.0 selenide 4.12.3 testNg 7.0.0-beta1
18:02:52 ----AFTER TEST TERMINATE APP---- 18:02:52 [HTTP] --> POST /wd/hub/session/de93c6d8-561b-4f88-b662-40954cef5867/appium/device/terminate_app 18:02:52 [HTTP] {"bundleId":"test.app"} 18:02:52 [debug] [W3C (de93c6d8)] Calling AppiumDriver.terminateApp() with args: ["test.app",null,null,null,"de93c6d8-561b-4f88-b662-40954cef5867"] 18:02:52 [debug] [XCUITest] Executing command 'terminateApp' 18:02:52 [debug] [XCUITest] Setting custom timeout to 600000 ms for 'mobileTerminateApp' command 18:02:52 [debug] [WD Proxy] Proxying [POST /wda/apps/terminate] to [POST http://localhost:8102/session/2B07BD79-7435-4B83-BF10-1BEBEB64A788/wda/apps/terminate] with body: {"bundleId":"test.app"} 18:02:53 [debug] [WD Proxy] Got response with status 200: {"value":true,"sessionId":"2B07BD79-7435-4B83-BF10-1BEBEB64A788","status":0} 18:02:53 [debug] [W3C (de93c6d8)] Responding to client with driver.terminateApp() result: true 18:02:53 [HTTP] <-- POST /----AFTER TEST QUIT---- 18:02:53 wd/hub/session/de93c6d8-561b-4f88-b662-40954cef5867/appium/device/terminate_app 200 1095 ms - 14 18:02:53 [HTTP] 18:02:53 [HTTP] --> DELETE /wd/hub/session/de93c6d8-561b-4f88-b662-40954cef5867 18:02:53 [HTTP] {} 18:02:53 [debug] [W3C (de93c6d8)] Calling AppiumDriver.deleteSession() with args: ["de93c6d8-561b-4f88-b662-40954cef5867"] 18:02:53 [debug] [BaseDriver] Event 'quitSessionRequested' logged at 1583161373460 18:02:53 [Appium] Removing session de93c6d8-561b-4f88-b662-40954cef5867 from our master session list 18:02:53 [debug] [XCUITest] Setting custom timeout to 600000 ms for 'deleteSession' command 18:02:53 [debug] [WD Proxy] Matched '/session/de93c6d8-561b-4f88-b662-40954cef5867' to command name 'deleteSession' 18:02:53 [debug] [WD Proxy] Proxying [DELETE /session/de93c6d8-561b-4f88-b662-40954cef5867] to [DELETE http://localhost:8102/session/2B07BD79-7435-4B83-BF10-1BEBEB64A788] with no body 18:02:53 [debug] [WD Proxy] Got response with status 200: "{\n \"value\" : {\n\n },\n \"sessionId\" : \"A3CBB0AF-8C76-4A48-92F5-BFF0E8016F40\",\n \"status\" : 0\n}" 18:04:53 [HTTP] <-- DELETE /wd/hub/session/de93c6d8-561b-4f88-b662-40954cef5867 - - ms - - 18:04:53 [HTTP] 18:04:53 [HTTP] --> DELETE /wd/hub/session/de93c6d8-561b-4f88-b662-40954cef5867 18:04:53 [HTTP] {} 18:04:53 [debug] [W3C (de93c6d8)] Encountered internal error running command: NoSuchDriverError: A session is either terminated or not started 18:04:53 [debug] [W3C (de93c6d8)] at asyncHandler (/usr/local/lib/node_modules/appium/node_modules/appium-base-driver/lib/protocol/protocol.js:298:15) 18:04:53 [debug] [W3C (de93c6d8)] at asyncHandler (/usr/local/lib/node_modules/appium/node_modules/appium-base-driver/lib/protocol/protocol.js:489:15) 18:04:53 [debug] [W3C (de93c6d8)] at Layer.handle [as handle_request] (/usr/local/lib/node_modules/appium/node_modules/express/lib/router/layer.js:95:5) 18:04:53 [debug] [W3C (de93c6d8)] at next (/usr/local/lib/node_modules/appium/node_modules/express/lib/router/route.js:137:13) 18:04:53 [debug] [W3C (de93c6d8)] at Route.dispatch (/usr/local/lib/node_modules/appium/node_modules/express/lib/router/route.js:112:3) 18:04:53 [debug] [W3C (de93c6d8)] at Layer.handle [as handle_request] (/usr/local/lib/node_modules/appium/node_modules/express/lib/router/layer.js:95:5) 18:04:53 [debug] [W3C (de93c6d8)] at /usr/local/lib/node_modules/appium/node_modules/express/lib/router/index.js:281:22 18:04:53 [debug] [W3C (de93c6d8)] at param (/usr/local/lib/node_modules/appium/node_modules/express/lib/router/index.js:354:14) 18:04:53 [debug] [W3C (de93c6d8)] at param (/usr/local/lib/node_modules/appium/node_modules/express/lib/router/index.js:36----DRIVER.QUIT EXCEPTION---- 18:04:53 5:14) 18:04:53 [debug] [W3C (de93c6d8)] at Function.processorg.openqa.selenium.NoSuchSessionException: A session is either terminated or not started 18:04:53 Build info: version: '3.141.59', revision: 'e82be7d358', time: '2018-11-14T08:17:03' 18:04:53 System info: host: 'ci-macmini08.scnetservices.ru', ip: 'fe80:0:0:0:18ab:e867:31bb:cad0%en0', os.name: 'Mac OS X', os.arch: 'x86_64', os.version: '10.14.4', java.version: '1.8.0_191' 18:04:53 Driver info: io.appium.java_client.ios.IOSDriver 18:04:53 Capabilities {app: src/main/resources/IOS/emul..., automationName: XCUITest, browserName: , commandTimeouts: {default: 600000}, connectHardwareKeyboard: false, databaseEnabled: false, deviceName: iPhone 8, isHeadless: false, javascriptEnabled: true, locationContextEnabled: false, mjpegServerPort: 9102, networkConnectionEnabled: false, newCommandTimeout: 1800, noReset: true, platform: MAC, platformName: iOS, platformVersion: 12.2, shouldUseSingletonTestManager: false, showXcodeLog: false, takesScreenshot: true, udid: 22625D94-072D-40CB-B8F7-6E9..., wdaLocalPort: 8102, webStorageEnabled: false} 18:04:53 Session ID: de93c6d8-561b-4f88-b662-40954cef5867_par 18:04:53 ams (/usr/local/lib/node_modules/ap at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) 18:04:53 at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) 18:04:53 at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) 18:04:53 at java.lang.reflect.Constructor.newInstance(Constructor.java:423) 18:04:53 at org.openqa.selenium.remote.http.W3CHttpResponseCodec.createException(W3CHttpResponseCodec.java:187)pium/nod 18:04:53 at org.openqa.selenium.remote.http.W3CHttpResponseCodec.decode(W3CHttpResponseCodec.java:122) 18:04:53 at org.openqa.selenium.remote.http.W3CHttpResponseCodec.decode(W3CHttpResponseCodec.java:49) 18:04:53 at org.openqa.selenium.remote.HttpCommandExecutor.execute(HttpCommandExecutor.java:158) 18:04:53 at io.appium.java_client.remote.AppiumCommandExecutor.execute(AppiumCommandExecutor.java:231) 18:04:53 at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:552) 18:04:53 at io.appium.java_client.DefaultGenericMobileDriver.execute(DefaultGenericMobileDriver.java:46) 18:04:53 at io.appium.java_client.AppiumDriver.execute(AppiumDriver.java:1) 18:04:53 at io.appium.java_client.ios.IOSDriver.execute(IOSDriver.java:1) 18:04:53 at org.openqa.selenium.remote.RemoteWebDriver.quit(RemoteWebDriver.java:452) 18:04:53 at actions.actionsApp.impl.ActionsAppIOS.quit(ActionsAppIOS.java:98) 18:04:53 at baseTest.BaseTestSuite.afterTestFabric(BaseTestSuite.java:169) 18:04:53 at baseTest.BaseTestOneDevice.afterClass(BaseTestOneDevice.java:65) 18:04:53 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) 18:04:53 e at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) 18:04:53 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) 18:04:53 at java.lang.reflect.Method.invoke(Method.java:498) 18:04:53 at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:131) 18:04:53 at org.testng.internal.MethodInvocationHelper.invokeMethodConsideringTimeout(MethodInvocationHelper.java:61) 18:04:53 at org.testng.internal.Invoker.invokeConfigurationMethod(Invoker.java:511) 18:04:53 at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:241) 18:04:53 at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:144) 18:04:53 at org.testng.internal.TestMethodWorker.invokeAfterClassMethods(TestMethodWorker.java:214) 18:04:53 at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:124) 18:04:53 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) 18:04:53 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) 18:04:53 at java.lang.Thread.run(Thread.java:748) 18:04:53 _modules/express/lib/router/index.js:410:3) 18:04:53 [debug] [W3C (de93c6d8)] at next (/usr/local/lib/node_modules/appium/node_modules/express/lib/router/index.js:275:10) 18:04:53 [debug] [W3C (de93c6d8)] at logger (/usr/local/lib/node_modules/appium/node_modules/morgan/index.js:144:5) 18:04:53 [debug] [W3C (de93c6d8)] at Layer.handle [as handle_request] (/usr/local/lib/node_modules/appium/node_modules/express/lib/router/layer.js:95:5) 18:04:53 [debug] [W3C (de93c6d8)] at trim_prefix (/usr/local/lib/node_modules/appium/node_modules/express/lib/router/index.js:317:13) 18:04:53 [debug] [W3C (de93c6d8)] at /usr/local/lib/node_modules/appium/node_modules/express/lib/router/index.js:284:7 18:04:53 [debug] [W3C (de93c6d8)] at Function.process_params (/usr/local/lib/node_modules/appium/node_modules/express/lib/router/index.js:335:12) 18:04:53 [debug] [W3C (de93c6d8)] at next (/usr/local/lib/node_modules/appium/node_modules/express/lib/router/index.js:275:10) 18:04:53 [debug] [W3C (de93c6d8)] at /usr/local/lib/node_modules/appium/node_modules/body-parser/lib/read.js:130:5 18:04:53 [debug] [W3C (de93c6d8)] at invokeCallback (/usr/local/lib/node_modules/appium/node_modules/raw-body/index.js:224:16) 18:04:53 [debug] [W3C (de93c6d8)] at done (/usr/local/lib/node_modules/appium/node_modules/raw-body/index.js:213:7) 18:04:53 [debug] [W3C (de93c6d8)] at IncomingMessage.onEnd (/usr/local/lib/node_modules/appium/node_modules/raw-body/index.js:273:7) 18:04:53 [debug] [W3C (de93c6d8)] at IncomingMessage.emit (events.js:182:13) 18:04:53 [HTTP] <-- DELETE /wd/hub/session/de93c6d8-561b-4f88-b662-40954cef5867 404 18 ms - 2422 18:04:53 [HTTP]