Appium session not deleted because of driver quit issue during browser automation using appium

Hi,

I want to run tests in chrome browser on android mobile. I’ve a GRID, with few Android devices connected. Note: I am able to launch the chrome browser on mobile, open the website\URL and login to site successfully. But device is not released \freed.

Problem: I find errors in driver.quit() statement “org.openqa.selenium.UnsupportedCommandException: unknown command: session”

In appium server logs, I found that chromedriver starts on a different port 9515 (does not use 4723 default port by appium). I see that first appium creates a session 23644e9a-1aa0-4274-be27-08dc4cc7b409 and then chromedriver overrides the session with 569533ea9095daefc052f0e2ee38b394

At end, I found that chromedriver could exit but I don’t see a reference back to old appium session and find statement as [Proxied response received with status 404: “unknown command: sessions/”]. This leads to problem in device release\free and device remains locked state always which is problematic for subsequent tests.

Can someone help me in resolving this issue. This is a critical issue that i’ve to solve asap. Please let me know know if you need any information for troubleshooting.

I am passing following desired capabilities in my test.

DesiredCapabilities capabilities = new DesiredCapabilities();

   capabilities.setCapability(CapabilityType.BROWSER_NAME, browser);

   //capabilities.setCapability("deviceName", "4d00b81de1133037");

   capabilities.setCapability("version",version);

   capabilities.setCapability("deviceName", device);

   capabilities.setCapability("platformVersion", platformversion);

   capabilities.setCapability("platformName", platformName);

   capabilities.setCapability("orientation", "LANDSCAPE");

   capabilities.setCapability("app", app);   

  

   capabilities.setCapability("deviceCategory", category);

   driver = new AppiumDriver(new URL("http://127.0.0.1:4723/wd/hub"), capabilities);

Full Appium Server Log


C:\Windows\system32>appium -a 172.16.93.110 -p 4723 -U 4d0097864ebc3163

body-parser deprecated urlencoded: explicitly specify “extended: true” for extended parsing lib\server\main.js:99:23

info: Welcome to Appium v1.1.0 (REV e433bbc31511f199287db7724e1ce692bcb32117)

info: Appium REST http interface listener started on 172.16.93.110:4723

info: Non-default server args: {“udid”:“4d0097864ebc3163”,“address”:“172.16.93.110”}

debug: Appium request initiated at /wd/hub/sessions/

debug: Request received with params: {}

debug: Responding to client with success: {“status”:0,“value”:[]}

GET /wd/hub/sessions/ 200 10.667 ms - 23

debug: Appium request initiated at /wd/hub/session

debug: Request received with params: {“desiredCapabilities”:{“deviceCategory”:“phone”,“platformName”:“android”,“version”:“4.4.3”,“orientation”:“LANDSCAPE”,“deviceName”:“Samsung Galaxy S5”,"platfo

rmVersion":“4.4.3”,“browserName”:“chrome”,“app”:“chrome”}}

info: The following desired capabilities were provided, but not recognized by appium. They will be passed on to any other services running on this server. : deviceCategory, version

debug: Looks like we want chrome on android

debug: Creating new appium session 23644e9a-1aa0-4274-be27-08dc4cc7b409

debug: Preparing device for session

debug: Not checking whether app is present since we are assuming it’s already on the device

info: Checking whether adb is present

debug: Using adb from C:\Android-SDK\sdk\platform-tools\adb.exe

info: Trying to find a connected android device

debug: Getting connected devices…

debug: executing: “C:\Android-SDK\sdk\platform-tools\adb.exe” devices

debug: 1 device(s) connected

info: Setting device id to 4d0097864ebc3163

debug: Waiting for device to be ready and to respond to shell commands (timeout = 5)

debug: executing: “C:\Android-SDK\sdk\platform-tools\adb.exe” -s 4d0097864ebc3163 wait-for-device

debug: executing: “C:\Android-SDK\sdk\platform-tools\adb.exe” -s 4d0097864ebc3163 shell “echo ‘ready’”

info: Starting logcat capture

debug: Pushing unlock helper app to device…

debug: executing: “C:\Android-SDK\sdk\platform-tools\adb.exe” -s 4d0097864ebc3163 install “C:\Users\vdl\AppData\Roaming\npm\node_modules\appium\build\unlock_apk\unlock_apk-debug.apk”

debug: executing: “C:\Android-SDK\sdk\platform-tools\adb.exe” -s 4d0097864ebc3163 shell “dumpsys window”

info: Writing dumpsys output to C:\Users\vdl\AppData\Roaming\npm\node_modules\appium.dumpsys.log

debug: Screen already unlocked, continuing.

debug: Creating Chrome session

debug: Ensuring Chromedriver exists

debug: Killing any old chromedrivers, running: FOR /F “usebackq tokens=5” %a in (netstat -nao ^| findstr /R /C:"9515 ") do (FOR /F “usebackq” %b in (`TASKLIST /FI “PID eq %a” ^| findstr /I chro

medriver.exe`) do (IF NOT %b=="" TASKKILL /F /PID %b))

debug: No old chromedrivers seemed to exist

debug: Spawning chromedriver with: C:\Users\vdl\AppData\Roaming\npm\node_modules\appium\build\chromedriver\windows\chromedriver.exe

debug: [CHROMEDRIVER] Starting ChromeDriver (v2.9.248315) on port 9515

debug: Making http request with opts: {“url”:"http://127.0.0.1:9515/wd/hub/session",“method”:“POST”,“json”:{“sessionId”:null,“desiredCapabilities”:{“chromeOptions”:{“androidPackage”:"com.android.

chrome",“androidDeviceSerial”:“4d0097864ebc3163”}}}}

debug: Successfully started chrome session

debug: Overriding session id with “569533ea9095daefc052f0e2ee38b394”

debug: Device launched! Ready for commands

debug: Setting command timeout to the default of 60 secs

debug: Appium session started with sessionId 569533ea9095daefc052f0e2ee38b394

POST /wd/hub/session 303 8461.494 ms - 9

debug: Appium request initiated at /wd/hub/session/569533ea9095daefc052f0e2ee38b394

debug: Request received with params: {}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/session/569533ea9095daefc052f0e2ee38b394",“method”:"GET”}

debug: Proxied response received with status 200: "{“sessionId”:“569533ea9095daefc052f0e2ee38b394”,“status”:0,“value”:{“acceptSslCerts”:true,“applicationCacheEnabled”:false,"browserC

onnectionEnabled":false,“browserName”:“chrome”,“chrome”:{},“cssSelectorsEnabled”:true,“databaseEnabled”:false,“handlesAlerts”:true,“javascriptEnabled”:true,"locationContextEnabled

“:true,“nativeEvents”:true,“platform”:“ANDROID”,“rotatable”:false,“takesHeapSnapshot”:true,“takesScreenshot”:true,“version”:“33.0.1750.517”,“webStorageEnabled”:true}}”

GET /wd/hub/session/569533ea9095daefc052f0e2ee38b394 200 8.015 ms - 476

debug: Appium request initiated at /wd/hub/session/569533ea9095daefc052f0e2ee38b394/url

debug: Request received with params: {“url”:“https://myturbotax.intuit.com/”}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/session/569533ea9095daefc052f0e2ee38b394/url",“method”:“POST”,“json”:{“url”:"https://myturbotax.intuit.com/”}}

debug: Appium request initiated at /wd/hub/sessions/

debug: Request received with params: {}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/sessions/",“method”:"GET”}

debug: Proxied response received with status 404: “unknown command: sessions/”

GET /wd/hub/sessions/ 404 11.711 ms - 26

debug: Appium request initiated at /wd/hub/sessions/

debug: Request received with params: {}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/sessions/",“method”:"GET”}

debug: Proxied response received with status 404: “unknown command: sessions/”

GET /wd/hub/sessions/ 404 11.522 ms - 26

debug: Proxied response received with status 200: {“sessionId”:“569533ea9095daefc052f0e2ee38b394”,“status”:0,“value”:null}

POST /wd/hub/session/569533ea9095daefc052f0e2ee38b394/url 200 9696.754 ms - 72

debug: Appium request initiated at /wd/hub/session/569533ea9095daefc052f0e2ee38b394/execute

debug: Request received with params: {“args”:[],“script”:“return navigator.userAgent”}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:"http://127.0.0.1:9515/wd/hub/session/569533ea9095daefc052f0e2ee38b394/execute",“method”:“POST”,“json”:{“args”:[],“script”:"return navigator.userAgent

"}}

debug: Proxied response received with status 200: {“sessionId”:“569533ea9095daefc052f0e2ee38b394”,“status”:0,“value”:"Mozilla/5.0 (Linux; Android 4.4.2; SM-G900H Build/KOT49H) AppleWebKit/537.36

(KHTML, like Gecko) Chrome/33.0.1750.517 Mobile Safari/537.36"}

POST /wd/hub/session/569533ea9095daefc052f0e2ee38b394/execute 200 159.364 ms - 208

debug: Appium request initiated at /wd/hub/session/569533ea9095daefc052f0e2ee38b394/timeouts/implicit_wait

debug: Request received with params: {“ms”:10000}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/session/569533ea9095daefc052f0e2ee38b394/timeouts/implicit_wait",“method”:“POST”,“json”:{"ms”:10000}}

debug: Proxied response received with status 200: {“sessionId”:“569533ea9095daefc052f0e2ee38b394”,“status”:0,“value”:null}

POST /wd/hub/session/569533ea9095daefc052f0e2ee38b394/timeouts/implicit_wait 200 17.704 ms - 72

debug: Appium request initiated at /wd/hub/sessions/

debug: Request received with params: {}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/sessions/",“method”:"GET”}

debug: Proxied response received with status 404: “unknown command: sessions/”

GET /wd/hub/sessions/ 404 11.536 ms - 26

debug: Appium request initiated at /wd/hub/session/569533ea9095daefc052f0e2ee38b394/element

debug: Request received with params: {“using”:“id”,“value”:“ius-userid”}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/session/569533ea9095daefc052f0e2ee38b394/element",“method”:“POST”,“json”:{“using”:“id”,“value”:"ius-userid”}}

debug: Proxied response received with status 200: {“sessionId”:“569533ea9095daefc052f0e2ee38b394”,“status”:0,“value”:{“ELEMENT”:“0.9901202775072306-1”}}

POST /wd/hub/session/569533ea9095daefc052f0e2ee38b394/element 200 145.967 ms - 102

debug: Appium request initiated at /wd/hub/session/569533ea9095daefc052f0e2ee38b394/element/0.9901202775072306-1/value

debug: Request received with params: {“id”:“0.9901202775072306-1”,“value”:[“[email protected]”]}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:"http://127.0.0.1:9515/wd/hub/session/569533ea9095daefc052f0e2ee38b394/element/0.9901202775072306-1/value",“method”:“POST”,“json”:{“id”:"0.99012027750

72306-1",“value”:[“[email protected]”]}}

debug: Proxied response received with status 200: {“sessionId”:“569533ea9095daefc052f0e2ee38b394”,“status”:0,“value”:null}

POST /wd/hub/session/569533ea9095daefc052f0e2ee38b394/element/0.9901202775072306-1/value 200 2473.142 ms - 72

debug: Appium request initiated at /wd/hub/session/569533ea9095daefc052f0e2ee38b394/element

debug: Request received with params: {“using”:“id”,“value”:“ius-password”}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/session/569533ea9095daefc052f0e2ee38b394/element",“method”:“POST”,“json”:{“using”:“id”,“value”:"ius-password”}}

debug: Proxied response received with status 200: {“sessionId”:“569533ea9095daefc052f0e2ee38b394”,“status”:0,“value”:{“ELEMENT”:“0.9901202775072306-2”}}

POST /wd/hub/session/569533ea9095daefc052f0e2ee38b394/element 200 484.153 ms - 102

debug: Appium request initiated at /wd/hub/sessions/

debug: Request received with params: {}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/sessions/",“method”:"GET”}

debug: Proxied response received with status 404: “unknown command: sessions/”

GET /wd/hub/sessions/ 404 12.791 ms - 26

debug: Appium request initiated at /wd/hub/session/569533ea9095daefc052f0e2ee38b394/element/0.9901202775072306-2/value

debug: Request received with params: {“id”:“0.9901202775072306-2”,“value”:[“helloworld”]}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:"http://127.0.0.1:9515/wd/hub/session/569533ea9095daefc052f0e2ee38b394/element/0.9901202775072306-2/value",“method”:“POST”,“json”:{“id”:"0.99012027750

72306-2",“value”:[“helloworld”]}}

debug: Proxied response received with status 200: {“sessionId”:“569533ea9095daefc052f0e2ee38b394”,“status”:0,“value”:null}

POST /wd/hub/session/569533ea9095daefc052f0e2ee38b394/element/0.9901202775072306-2/value 200 800.511 ms - 72

debug: Appium request initiated at /wd/hub/session/569533ea9095daefc052f0e2ee38b394/element

debug: Request received with params: {“using”:“id”,“value”:“ius-sign-in-submit-btn”}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/session/569533ea9095daefc052f0e2ee38b394/element",“method”:“POST”,“json”:{“using”:“id”,“value”:"ius-sign-in-submit-btn”}

}

debug: Proxied response received with status 200: {“sessionId”:“569533ea9095daefc052f0e2ee38b394”,“status”:0,“value”:{“ELEMENT”:“0.9901202775072306-3”}}

POST /wd/hub/session/569533ea9095daefc052f0e2ee38b394/element 200 103.400 ms - 102

debug: Appium request initiated at /wd/hub/session/569533ea9095daefc052f0e2ee38b394/element/0.9901202775072306-3/click

debug: Request received with params: {“id”:“0.9901202775072306-3”}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:"http://127.0.0.1:9515/wd/hub/session/569533ea9095daefc052f0e2ee38b394/element/0.9901202775072306-3/click",“method”:“POST”,“json”:{“id”:"0.99012027750

72306-3"}}

debug: Appium request initiated at /wd/hub/sessions/

debug: Request received with params: {}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/sessions/",“method”:"GET”}

debug: Proxied response received with status 404: “unknown command: sessions/”

GET /wd/hub/sessions/ 404 12.844 ms - 26

debug: Proxied response received with status 200: {“sessionId”:“569533ea9095daefc052f0e2ee38b394”,“status”:0,“value”:null}

POST /wd/hub/session/569533ea9095daefc052f0e2ee38b394/element/0.9901202775072306-3/click 200 4188.520 ms - 72

debug: Appium request initiated at /wd/hub/sessions/

debug: Request received with params: {}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/sessions/",“method”:"GET”}

debug: Proxied response received with status 404: “unknown command: sessions/”

GET /wd/hub/sessions/ 404 12.572 ms - 26

debug: Appium request initiated at /wd/hub/session

debug: Request received with params: {}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/session",“method”:"DELETE”}

debug: Proxied response received with status 404: “unknown command: session”

DELETE /wd/hub/session 404 12.595 ms - 24

debug: Appium request initiated at /wd/hub/sessions/

debug: Request received with params: {}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/sessions/",“method”:"GET”}

debug: Proxied response received with status 404: “unknown command: sessions/”

GET /wd/hub/sessions/ 404 12.662 ms - 26

debug: Appium request initiated at /wd/hub/sessions/

debug: Request received with params: {}

debug: Proxying command to 127.0.0.1:9515

debug: Making http request with opts: {“url”:“http://127.0.0.1:9515/wd/hub/sessions/",“method”:"GET”}

debug: Proxied response received with status 404: “unknown command: sessions/”

GET /wd/hub/sessions/ 404 14.681 ms - 26

Thanks,

Parveen

I am facing the same problem,did you find any solution ?

facing same issue… did ya find any solution?