We're using WinAppDriver through Appium for performance testing. The scenario is opening the app under test 3 times, and calculating the average startup time. After closing the app and try to launch it again, the app opens, but the test fails due to a 500 unknown error from WinAppDriver.
2022-09-09 11:31:47:263 [Appium] Welcome to Appium v1.21.0
2022-09-09 11:31:47:271 [Appium] Non-default server args:
2022-09-09 11:31:47:272 [Appium] address: 127.0.0.1
2022-09-09 11:31:47:272 [Appium] logFile: D:\W\AL\G1\TestApps\Reports\UI\TemplatesDesigner\UiTests.PerformanceTests\bin\Debug\netcoreapp3.1\AppiumServerLog.txt
2022-09-09 11:31:47:330 [Appium] Appium REST http interface listener started on 127.0.0.1:4723
2022-09-09 11:31:47:462 [HTTP] --> GET /wd/hub/status
2022-09-09 11:31:47:463 [HTTP] {}
2022-09-09 11:31:47:470 [GENERIC] Calling AppiumDriver.getStatus() with args: []
2022-09-09 11:31:47:474 [GENERIC] Responding to client with driver.getStatus() result: {"build":{"version":"1.21.0"}}
2022-09-09 11:31:47:512 [HTTP] <-- GET /wd/hub/status 200 41 ms - 68
2022-09-09 11:31:47:512 [HTTP]
2022-09-09 11:31:47:663 [HTTP] --> POST /wd/hub/session
2022-09-09 11:31:47:664 [HTTP] {"desiredCapabilities":{"appium:app":"D:\\W\\AL\\G1\\TestApps\\Reports\\UI\\TemplatesDesigner\\PerformanceTestApp.WPF\\bin\\Release\\netcoreapp3.1\\ADDInformatica.TestApps.Reports.UI.TemplatesDesigner.PerformanceTestApp.WPF.exe","appium:deviceName":"WindowsPC","ms:waitForAppLaunch":30,"platformName":"Windows"},"capabilities":{"firstMatch":[{"appium:app":"D:\\W\\AL\\G1\\TestApps\\Reports\\UI\\TemplatesDesigner\\PerformanceTestApp.WPF\\bin\\Release\\netcoreapp3.1\\ADDInformatica.TestApps.Reports.UI.TemplatesDesigner.PerformanceTestApp.WPF.exe","appium:deviceName":"WindowsPC","ms:waitForAppLaunch":30,"platformName":"Windows"}]}}
2022-09-09 11:31:47:664 [W3C] Calling AppiumDriver.createSession() with args: [{"appium:app":"D:\\W\\AL\\G1\\TestApps\\Reports\\UI\\TemplatesDesigner\\PerformanceTestApp.WPF\\bin\\Release\\netcoreapp3.1\\ADDInformatica.TestApps.Reports.UI.TemplatesDesigner.PerformanceTestApp.WPF.exe","appium:deviceName":"WindowsPC","ms:waitForAppLaunch":30,"platformName":"Windows"},null,{"firstMatch":[{"appium:app":"D:\\W\\AL\\G1\\TestApps\\Reports\\UI\\TemplatesDesigner\\PerformanceTestApp.WPF\\bin\\Release\\netcoreapp3.1\\ADDInformatica.TestApps.Reports.UI.TemplatesDesigner.PerformanceTestApp.WPF.exe","appium:deviceName":"WindowsPC","ms:waitForAppLaunch":30,"platformName":"Windows"}]}]
2022-09-09 11:31:47:672 [BaseDriver] Event 'newSessionRequested' logged at 1662723107666 (13:31:47 GMT+0200 (hora de verano de Europa central))
2022-09-09 11:31:47:877 [Appium] Appium v1.21.0 creating new WindowsDriver (v1.18.1) session
2022-09-09 11:31:47:881 [BaseDriver] W3C capabilities and MJSONWP desired capabilities were provided
2022-09-09 11:31:47:881 [BaseDriver] Creating session with W3C capabilities: {
2022-09-09 11:31:47:881 [BaseDriver] "alwaysMatch": {
2022-09-09 11:31:47:882 [BaseDriver] "ms:waitForAppLaunch": 30,
2022-09-09 11:31:47:882 [BaseDriver] "platformName": "Windows",
2022-09-09 11:31:47:882 [BaseDriver] "appium:app": "D:\\W\\AL\\G1\\TestApps\\Reports\\UI\\TemplatesDesigner\\PerformanceTestApp.WPF\\bin\\Release\\netcoreapp3.1\\ADDInformatica.TestApps.Reports.UI.TemplatesDesigner.PerformanceTestApp.WPF.exe",
2022-09-09 11:31:47:883 [BaseDriver] "appium:deviceName": "WindowsPC"
2022-09-09 11:31:47:883 [BaseDriver] },
2022-09-09 11:31:47:883 [BaseDriver] "firstMatch": [
2022-09-09 11:31:47:884 [BaseDriver] {}
2022-09-09 11:31:47:884 [BaseDriver] ]
2022-09-09 11:31:47:885 [BaseDriver] }
2022-09-09 11:31:47:891 [BaseDriver] Session created with session id: 27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd
2022-09-09 11:31:47:905 [WinAppDriver] WinAppDriver exists, but the checksum did not match. Was it replaced manually?
2022-09-09 11:31:47:914 [WinAppDriver] Spawning 'C:\Program Files (x86)\Windows Application Driver\WinAppDriver.exe' with args: ["4724/wd/hub"]
2022-09-09 11:31:47:946 [WD Proxy] Matched '/status' to command name 'getStatus'
2022-09-09 11:31:47:950 [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:4724/wd/hub/status] with no body
2022-09-09 11:31:47:981 [WD Proxy] connect ECONNREFUSED 127.0.0.1:4724
2022-09-09 11:31:48:123 [WinAppDriver] Windows Application Driver listening for requests at: http://127.0.0.1:4724/wd/hub
2022-09-09 11:31:48:130 [WinAppDriver] Press ENTER to exit.
2022-09-09 11:31:48:985 [WD Proxy] Matched '/status' to command name 'getStatus'
2022-09-09 11:31:48:985 [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:4724/wd/hub/status] with no body
2022-09-09 11:31:48:992 [WinAppDriver] ==========================================
2022-09-09 11:31:48:993 [WinAppDriver] GET /wd/hub/status HTTP/1.1
2022-09-09 11:31:48:993 [WinAppDriver] Accept: application/json, */*
2022-09-09 11:31:48:993 [WinAppDriver] Connection: keep-alive
2022-09-09 11:31:48:993 [WinAppDriver] Content-Type: application/json; charset=utf-8
2022-09-09 11:31:48:994 [WinAppDriver] Host: 127.0.0.1:4724
2022-09-09 11:31:48:994 [WinAppDriver] User-Agent: appium
2022-09-09 11:31:48:998 [WinAppDriver] HTTP/1.1 200 OK
2022-09-09 11:31:48:999 [WinAppDriver] Content-Length: 146
2022-09-09 11:31:49:000 [WinAppDriver] Content-Type: application/json
2022-09-09 11:31:49:000 [WinAppDriver]
2022-09-09 11:31:49:001 [WinAppDriver] {"build":{"revision":"2003","time":"Wed Aug 26 07:56:06 2020","version":"1.2.2009"},"os":{"arch":"amd64","name":"windows","version":"10.0.20348"}}
2022-09-09 11:31:49:005 [WD Proxy] Got response with status 200: {"build":{"revision":"2003","time":"Wed Aug 26 07:56:06 2020","version":"1.2.2009"},"os":{"arch":"amd64","name":"windows","version":"10.0.20348"}}
2022-09-09 11:31:49:006 [WinAppDriver] Starting WinAppDriver session. Will timeout in '20000' ms.
2022-09-09 11:31:49:007 [WD Proxy] Matched '/session' to command name 'createSession'
2022-09-09 11:31:49:008 [WD Proxy] Proxying [POST /session] to [POST http://127.0.0.1:4724/wd/hub/session] with body: {"desiredCapabilities":{"ms:waitForAppLaunch":30,"platformName":"Windows","app":"D:\\W\\AL\\G1\\TestApps\\Reports\\UI\\TemplatesDesigner\\PerformanceTestApp.WPF\\bin\\Release\\netcoreapp3.1\\ADDInformatica.TestApps.Reports.UI.TemplatesDesigner.PerformanceTestApp.WPF.exe","deviceName":"WindowsPC"}}
2022-09-09 11:31:49:014 [WinAppDriver] ==========================================
2022-09-09 11:31:49:015 [WinAppDriver] POST /wd/hub/session HTTP/1.1
2022-09-09 11:31:49:017 [WinAppDriver] Accept: application/json, */*
2022-09-09 11:31:49:018 [WinAppDriver] Connection: keep-alive
2022-09-09 11:31:49:018 [WinAppDriver] Content-Length: 298
2022-09-09 11:31:49:019 [WinAppDriver] Content-Type: application/json; charset=utf-8
2022-09-09 11:31:49:019 [WinAppDriver] Host: 127.0.0.1:4724
2022-09-09 11:31:49:020 [WinAppDriver] User-Agent: appium
2022-09-09 11:31:49:021 [WinAppDriver]
2022-09-09 11:31:49:022 [WinAppDriver] {"desiredCapabilities":{"ms:waitForAppLaunch":30,"platformName":"Windows","app":"D:\\W\\AL\\G1\\TestApps\\Reports\\UI\\TemplatesDesigner\\PerformanceTestApp.WPF\\bin\\Release\\netcoreapp3.1\\ADDInformatica.TestApps.Reports.UI.TemplatesDesigner.PerformanceTestApp.WPF.exe","deviceName":"WindowsPC"}}
2022-09-09 11:32:26:582 [WD Proxy] Got response with status 200: {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0,"value":{"app":"D:\\W\\AL\\G1\\TestApps\\Reports\\UI\\TemplatesDesigner\\PerformanceTestApp.WPF\\bin\\Release\\netcoreapp3.1\\ADDInformatica.TestApps.Reports.UI.TemplatesDesigner.PerformanceTestApp.WPF.exe","ms:waitForAppLaunch":30,"platformName":"Windows"}}
2022-09-09 11:32:26:583 [WD Proxy] Determined the downstream protocol as 'MJSONWP'
2022-09-09 11:32:26:584 [Appium] New WindowsDriver session created successfully, session 27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd added to master session list
2022-09-09 11:32:26:585 [WinAppDriver] HTTP/1.1 200 OK
2022-09-09 11:32:26:585 [WinAppDriver] Content-Length: 321
2022-09-09 11:32:26:585 [WinAppDriver] Content-Type: application/json
2022-09-09 11:32:26:586 [WinAppDriver]
2022-09-09 11:32:26:586 [WinAppDriver] {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0,"value":{"app":"D:\\W\\AL\\G1\\TestApps\\Reports\\UI\\TemplatesDesigner\\PerformanceTestApp.WPF\\bin\\Release\\netcoreapp3.1\\ADDInformatica.TestApps.Reports.UI.TemplatesDesigner.PerformanceTestApp.WPF.exe","ms:waitForAppLaunch":30,"platformName":"Windows"}}
2022-09-09 11:32:26:587 [BaseDriver] Event 'newSessionStarted' logged at 1662723146587 (13:32:26 GMT+0200 (hora de verano de Europa central))
2022-09-09 11:32:26:588 [W3C (27eebfce)] Cached the protocol value 'W3C' for the new session 27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd
2022-09-09 11:32:26:588 [W3C (27eebfce)] Responding to client with driver.createSession() result: {"capabilities":{"ms:waitForAppLaunch":30,"platformName":"Windows","app":"D:\\W\\AL\\G1\\TestApps\\Reports\\UI\\TemplatesDesigner\\PerformanceTestApp.WPF\\bin\\Release\\netcoreapp3.1\\ADDInformatica.TestApps.Reports.UI.TemplatesDesigner.PerformanceTestApp.WPF.exe","deviceName":"WindowsPC"}}
2022-09-09 11:32:26:590 [HTTP] <-- POST /wd/hub/session 200 38926 ms - 352
2022-09-09 11:32:26:591 [HTTP]
2022-09-09 11:32:26:623 [HTTP] --> POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/timeouts
2022-09-09 11:32:26:624 [HTTP] {"implicit":30000}
2022-09-09 11:32:26:628 [W3C (27eebfce)] Driver proxy active, passing request on via HTTP proxy
2022-09-09 11:32:26:631 [WD Proxy] Matched '/wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/timeouts' to command name 'timeouts'
2022-09-09 11:32:26:633 [Protocol Converter] Will send the following request bodies to /timeouts: [{"type":"implicit","ms":30000}]
2022-09-09 11:32:26:635 [WD Proxy] Proxying [POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/timeouts] to [POST http://127.0.0.1:4724/wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/timeouts] with body: {"type":"implicit","ms":30000}
2022-09-09 11:32:26:637 [WinAppDriver] ==========================================
2022-09-09 11:32:26:638 [WinAppDriver] POST /wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/timeouts HTTP/1.1
2022-09-09 11:32:26:638 [WinAppDriver] Accept: application/json, */*
2022-09-09 11:32:26:638 [WinAppDriver] Connection: keep-alive
2022-09-09 11:32:26:639 [WinAppDriver] Content-Length: 30
2022-09-09 11:32:26:639 [WinAppDriver] Content-Type: application/json; charset=utf-8
2022-09-09 11:32:26:639 [WinAppDriver] Host: 127.0.0.1:4724
2022-09-09 11:32:26:640 [WinAppDriver] User-Agent: appium
2022-09-09 11:32:26:641 [WD Proxy] Got response with status 200: {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0}
2022-09-09 11:32:26:642 [WD Proxy] Replacing sessionId E220063C-E1F7-408E-B6F8-BB41E584B492 with 27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd
2022-09-09 11:32:26:643 [HTTP] <-- POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/timeouts 200 20 ms - 65
2022-09-09 11:32:26:644 [HTTP]
2022-09-09 11:32:26:644 [WinAppDriver] HTTP/1.1 200 OK
2022-09-09 11:32:26:645 [WinAppDriver] Content-Length: 63
2022-09-09 11:32:26:645 [WinAppDriver] Content-Type: application/json
2022-09-09 11:32:26:645 [WinAppDriver]
2022-09-09 11:32:26:645 [WinAppDriver] {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0}
2022-09-09 11:32:26:650 [HTTP] --> POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element
2022-09-09 11:32:26:651 [HTTP] {"using":"accessibility id","value":"paneRichEdit"}
2022-09-09 11:32:26:658 [W3C (27eebfce)] Calling AppiumDriver.findElement() with args: ["accessibility id","paneRichEdit","27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd"]
2022-09-09 11:32:26:659 [BaseDriver] Valid locator strategies for this request: xpath, id, name, class name, accessibility id
2022-09-09 11:32:26:671 [WD Proxy] Matched '/element' to command name 'findElement'
2022-09-09 11:32:26:672 [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:4724/wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/element] with body: {"using":"accessibility id","value":"paneRichEdit"}
2022-09-09 11:32:26:683 [WinAppDriver] ==========================================
2022-09-09 11:32:26:684 [WinAppDriver] POST /wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/element HTTP/1.1
2022-09-09 11:32:26:684 [WinAppDriver] Accept: application/json, */*
2022-09-09 11:32:26:685 [WinAppDriver] Connection: keep-alive
2022-09-09 11:32:26:685 [WinAppDriver] Content-Length: 51
2022-09-09 11:32:26:685 [WinAppDriver] Content-Type: application/json; charset=utf-8
2022-09-09 11:32:26:686 [WinAppDriver] Host: 127.0.0.1:4724
2022-09-09 11:32:26:686 [WinAppDriver] User-Agent: appium
2022-09-09 11:32:26:686 [WinAppDriver]
2022-09-09 11:32:26:686 [WinAppDriver] {"using":"accessibility id","value":"paneRichEdit"}
2022-09-09 11:32:28:104 [WinAppDriver] HTTP/1.1 200 OK
2022-09-09 11:32:28:104 [WinAppDriver] Content-Length: 102
2022-09-09 11:32:28:104 [WinAppDriver] Content-Type: application/json
2022-09-09 11:32:28:104 [WinAppDriver]
2022-09-09 11:32:28:104 [WinAppDriver] {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0,"value":{"ELEMENT":"7.11560.41029017"}}
2022-09-09 11:32:28:104 [WD Proxy] Got response with status 200: {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0,"value":{"ELEMENT":"7.11560.41029017"}}
2022-09-09 11:32:28:104 [W3C (27eebfce)] Responding to client with driver.findElement() result: {"element-6066-11e4-a52e-4f735466cecf":"7.11560.41029017","ELEMENT":"7.11560.41029017"}
2022-09-09 11:32:28:110 [HTTP] <-- POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element 200 1459 ms - 97
2022-09-09 11:32:28:110 [HTTP]
2022-09-09 11:32:28:116 [HTTP] --> POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element/7.11560.41029017/click
2022-09-09 11:32:28:117 [HTTP] {}
2022-09-09 11:32:28:122 [W3C (27eebfce)] Driver proxy active, passing request on via HTTP proxy
2022-09-09 11:32:28:126 [WD Proxy] Matched '/wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element/7.11560.41029017/click' to command name 'click'
2022-09-09 11:32:28:126 [WD Proxy] Proxying [POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element/7.11560.41029017/click] to [POST http://127.0.0.1:4724/wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/element/7.11560.41029017/click] with body: {}
2022-09-09 11:32:28:130 [WinAppDriver] ==========================================
2022-09-09 11:32:28:130 [WinAppDriver] POST /wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/element/7.11560.41029017/click HTTP/1.1
2022-09-09 11:32:28:130 [WinAppDriver] Accept: application/json, */*
2022-09-09 11:32:28:131 [WinAppDriver] Connection: keep-alive
2022-09-09 11:32:28:131 [WinAppDriver] Content-Length: 2
2022-09-09 11:32:28:131 [WinAppDriver] Content-Type: application/json; charset=utf-8
2022-09-09 11:32:28:132 [WinAppDriver] Host: 127.0.0.1:4724
2022-09-09 11:32:28:132 [WinAppDriver] User-Agent: appium
2022-09-09 11:32:28:133 [WinAppDriver]
2022-09-09 11:32:28:134 [WinAppDriver] {}
2022-09-09 11:32:28:518 [WinAppDriver] HTTP/1.1 200 OK
2022-09-09 11:32:28:519 [WinAppDriver] Content-Length: 63
2022-09-09 11:32:28:519 [WinAppDriver] Content-Type: application/json
2022-09-09 11:32:28:519 [WinAppDriver]
2022-09-09 11:32:28:519 [WinAppDriver] {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0}
2022-09-09 11:32:28:521 [WD Proxy] Got response with status 200: {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0}
2022-09-09 11:32:28:521 [WD Proxy] Replacing sessionId E220063C-E1F7-408E-B6F8-BB41E584B492 with 27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd
2022-09-09 11:32:28:524 [HTTP] <-- POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element/7.11560.41029017/click 200 406 ms - 65
2022-09-09 11:32:28:524 [HTTP]
2022-09-09 11:32:28:531 [HTTP] --> POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element
2022-09-09 11:32:28:531 [HTTP] {"using":"accessibility id","value":"paneRichEdit"}
2022-09-09 11:32:28:532 [W3C (27eebfce)] Calling AppiumDriver.findElement() with args: ["accessibility id","paneRichEdit","27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd"]
2022-09-09 11:32:28:533 [BaseDriver] Valid locator strategies for this request: xpath, id, name, class name, accessibility id
2022-09-09 11:32:28:535 [WD Proxy] Matched '/element' to command name 'findElement'
2022-09-09 11:32:28:535 [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:4724/wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/element] with body: {"using":"accessibility id","value":"paneRichEdit"}
2022-09-09 11:32:28:544 [WinAppDriver] ==========================================
2022-09-09 11:32:28:545 [WinAppDriver] POST /wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/element HTTP/1.1
2022-09-09 11:32:28:546 [WinAppDriver] Accept: application/json, */*
2022-09-09 11:32:28:546 [WinAppDriver] Connection: keep-alive
2022-09-09 11:32:28:547 [WinAppDriver] Content-Length: 51
2022-09-09 11:32:28:547 [WinAppDriver] Content-Type: application/json; charset=utf-8
2022-09-09 11:32:28:548 [WinAppDriver] Host: 127.0.0.1:4724
2022-09-09 11:32:28:549 [WinAppDriver] User-Agent: appium
2022-09-09 11:32:28:549 [WinAppDriver]
2022-09-09 11:32:28:550 [WinAppDriver] {"using":"accessibility id","value":"paneRichEdit"}
2022-09-09 11:32:29:882 [WinAppDriver] HTTP/1.1 200 OK
2022-09-09 11:32:29:882 [WinAppDriver] Content-Length: 102
2022-09-09 11:32:29:882 [WinAppDriver] Content-Type: application/json
2022-09-09 11:32:29:882 [WinAppDriver]
2022-09-09 11:32:29:883 [WinAppDriver] {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0,"value":{"ELEMENT":"7.11560.41029017"}}
2022-09-09 11:32:29:884 [WD Proxy] Got response with status 200: {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0,"value":{"ELEMENT":"7.11560.41029017"}}
2022-09-09 11:32:29:885 [W3C (27eebfce)] Responding to client with driver.findElement() result: {"element-6066-11e4-a52e-4f735466cecf":"7.11560.41029017","ELEMENT":"7.11560.41029017"}
2022-09-09 11:32:29:885 [HTTP] <-- POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element 200 1355 ms - 97
2022-09-09 11:32:29:885 [HTTP]
2022-09-09 11:32:29:896 [HTTP] --> POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element/7.11560.41029017/value
2022-09-09 11:32:29:897 [HTTP] {"text":"","value":[""]}
2022-09-09 11:32:29:898 [W3C (27eebfce)] Driver proxy active, passing request on via HTTP proxy
2022-09-09 11:32:29:900 [WD Proxy] Matched '/wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element/7.11560.41029017/value' to command name 'setValue'
2022-09-09 11:32:29:900 [WD Proxy] Proxying [POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element/7.11560.41029017/value] to [POST http://127.0.0.1:4724/wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/element/7.11560.41029017/value] with body: {"text":"","value":[""]}
2022-09-09 11:32:29:903 [WinAppDriver] ==========================================
2022-09-09 11:32:29:904 [WinAppDriver] POST /wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/element/7.11560.41029017/value HTTP/1.1
2022-09-09 11:32:29:904 [WinAppDriver] Accept: application/json, */*
2022-09-09 11:32:29:905 [WinAppDriver] Connection: keep-alive
2022-09-09 11:32:29:907 [WinAppDriver] Content-Length: 30
2022-09-09 11:32:29:907 [WinAppDriver] Content-Type: application/json; charset=utf-8
2022-09-09 11:32:29:907 [WinAppDriver] Host: 127.0.0.1:4724
2022-09-09 11:32:29:910 [WinAppDriver] User-Agent: appium
2022-09-09 11:32:29:913 [WinAppDriver]
2022-09-09 11:32:29:913 [WinAppDriver] {"text":"","value":[""]}
2022-09-09 11:32:30:123 [WinAppDriver] HTTP/1.1 200 OK
2022-09-09 11:32:30:123 [WinAppDriver] Content-Length: 63
2022-09-09 11:32:30:124 [WinAppDriver] Content-Type: application/json
2022-09-09 11:32:30:124 [WinAppDriver]
2022-09-09 11:32:30:124 [WinAppDriver] {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0}
2022-09-09 11:32:30:125 [WD Proxy] Got response with status 200: {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0}
2022-09-09 11:32:30:126 [WD Proxy] Replacing sessionId E220063C-E1F7-408E-B6F8-BB41E584B492 with 27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd
2022-09-09 11:32:30:129 [HTTP] <-- POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element/7.11560.41029017/value 200 231 ms - 65
2022-09-09 11:32:30:129 [HTTP]
2022-09-09 11:32:30:133 [HTTP] --> POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/appium/app/close
2022-09-09 11:32:30:134 [HTTP] {}
2022-09-09 11:32:30:142 [W3C (27eebfce)] Driver proxy active, passing request on via HTTP proxy
2022-09-09 11:32:30:160 [WD Proxy] Matched '/wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/appium/app/close' to command name 'closeApp'
2022-09-09 11:32:30:160 [WD Proxy] Proxying [POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/appium/app/close] to [POST http://127.0.0.1:4724/wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/appium/app/close] with body: {}
2022-09-09 11:32:30:162 [WinAppDriver] ==========================================
2022-09-09 11:32:30:163 [WinAppDriver] POST /wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/appium/app/close HTTP/1.1
2022-09-09 11:32:30:163 [WinAppDriver] Accept: application/json, */*
2022-09-09 11:32:30:163 [WinAppDriver] Connection: keep-alive
2022-09-09 11:32:30:164 [WinAppDriver] Content-Length: 2
2022-09-09 11:32:30:164 [WinAppDriver] Content-Type: application/json; charset=utf-8
2022-09-09 11:32:30:165 [WinAppDriver] Host: 127.0.0.1:4724
2022-09-09 11:32:30:165 [WinAppDriver] User-Agent: appium
2022-09-09 11:32:36:619 [WinAppDriver] HTTP/1.1 200 OK
2022-09-09 11:32:36:620 [WinAppDriver] Content-Length: 63
2022-09-09 11:32:36:620 [WinAppDriver] Content-Type: application/json
2022-09-09 11:32:36:620 [WinAppDriver]
2022-09-09 11:32:36:622 [WinAppDriver] {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0}
2022-09-09 11:32:36:623 [WD Proxy] Got response with status 200: {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0}
2022-09-09 11:32:36:624 [WD Proxy] Replacing sessionId E220063C-E1F7-408E-B6F8-BB41E584B492 with 27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd
2022-09-09 11:32:36:630 [HTTP] <-- POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/appium/app/close 200 6492 ms - 65
2022-09-09 11:32:36:633 [HTTP]
2022-09-09 11:32:36:641 [HTTP] --> POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element
2022-09-09 11:32:36:641 [HTTP] {"using":"accessibility id","value":"PART_NoButton1"}
2022-09-09 11:32:36:642 [W3C (27eebfce)] Calling AppiumDriver.findElement() with args: ["accessibility id","PART_NoButton1","27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd"]
2022-09-09 11:32:36:642 [BaseDriver] Valid locator strategies for this request: xpath, id, name, class name, accessibility id
2022-09-09 11:32:36:644 [WD Proxy] Matched '/element' to command name 'findElement'
2022-09-09 11:32:36:645 [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:4724/wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/element] with body: {"using":"accessibility id","value":"PART_NoButton1"}
2022-09-09 11:32:36:649 [WinAppDriver] ==========================================
2022-09-09 11:32:36:649 [WinAppDriver] POST /wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/element HTTP/1.1
2022-09-09 11:32:36:650 [WinAppDriver] Accept: application/json, */*
2022-09-09 11:32:36:650 [WinAppDriver] Connection: keep-alive
2022-09-09 11:32:36:650 [WinAppDriver] Content-Length: 53
2022-09-09 11:32:36:650 [WinAppDriver] Content-Type: application/json; charset=utf-8
2022-09-09 11:32:36:650 [WinAppDriver] Host: 127.0.0.1:4724
2022-09-09 11:32:36:650 [WinAppDriver] User-Agent: appium
2022-09-09 11:32:36:652 [WinAppDriver]
2022-09-09 11:32:36:652 [WinAppDriver] {"using":"accessibility id","value":"PART_NoButton1"}
2022-09-09 11:32:36:985 [WinAppDriver] HTTP/1.1 200 OK
2022-09-09 11:32:36:985 [WinAppDriver] Content-Length: 102
2022-09-09 11:32:36:986 [WinAppDriver] Content-Type: application/json
2022-09-09 11:32:36:986 [WinAppDriver]
2022-09-09 11:32:36:986 [WinAppDriver] {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0,"value":{"ELEMENT":"7.11560.45362212"}}
2022-09-09 11:32:36:987 [WD Proxy] Got response with status 200: {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0,"value":{"ELEMENT":"7.11560.45362212"}}
2022-09-09 11:32:36:988 [W3C (27eebfce)] Responding to client with driver.findElement() result: {"element-6066-11e4-a52e-4f735466cecf":"7.11560.45362212","ELEMENT":"7.11560.45362212"}
2022-09-09 11:32:36:989 [HTTP] <-- POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element 200 348 ms - 97
2022-09-09 11:32:36:990 [HTTP]
2022-09-09 11:32:36:996 [HTTP] --> POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element/7.11560.45362212/click
2022-09-09 11:32:36:996 [HTTP] {}
2022-09-09 11:32:36:997 [W3C (27eebfce)] Driver proxy active, passing request on via HTTP proxy
2022-09-09 11:32:36:998 [WD Proxy] Matched '/wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element/7.11560.45362212/click' to command name 'click'
2022-09-09 11:32:37:003 [WD Proxy] Proxying [POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element/7.11560.45362212/click] to [POST http://127.0.0.1:4724/wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/element/7.11560.45362212/click] with body: {}
2022-09-09 11:32:37:008 [WinAppDriver] ==========================================
2022-09-09 11:32:37:008 [WinAppDriver] POST /wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/element/7.11560.45362212/click HTTP/1.1
2022-09-09 11:32:37:008 [WinAppDriver] Accept: application/json, */*
2022-09-09 11:32:37:008 [WinAppDriver] Connection: keep-alive
2022-09-09 11:32:37:008 [WinAppDriver] Content-Length: 2
2022-09-09 11:32:37:008 [WinAppDriver] Content-Type: application/json; charset=utf-8
2022-09-09 11:32:37:012 [WinAppDriver] Host: 127.0.0.1:4724
2022-09-09 11:32:37:012 [WinAppDriver] User-Agent: appium
2022-09-09 11:32:37:012 [WinAppDriver]
2022-09-09 11:32:37:013 [WinAppDriver] {}
2022-09-09 11:32:37:338 [WD Proxy] Got response with status 200: {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0}
2022-09-09 11:32:37:339 [WD Proxy] Replacing sessionId E220063C-E1F7-408E-B6F8-BB41E584B492 with 27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd
2022-09-09 11:32:37:343 [HTTP] <-- POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/element/7.11560.45362212/click 200 345 ms - 65
2022-09-09 11:32:37:344 [HTTP]
2022-09-09 11:32:37:345 [WinAppDriver] HTTP/1.1 200 OK
2022-09-09 11:32:37:346 [WinAppDriver] Content-Length: 63
2022-09-09 11:32:37:346 [WinAppDriver] Content-Type: application/json
2022-09-09 11:32:37:346 [WinAppDriver]
2022-09-09 11:32:37:347 [WinAppDriver] {"sessionId":"E220063C-E1F7-408E-B6F8-BB41E584B492","status":0}
2022-09-09 11:32:37:353 [HTTP] --> POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/appium/app/launch
2022-09-09 11:32:37:354 [HTTP] {}
2022-09-09 11:32:37:365 [W3C (27eebfce)] Driver proxy active, passing request on via HTTP proxy
2022-09-09 11:32:37:367 [WD Proxy] Matched '/wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/appium/app/launch' to command name 'launchApp'
2022-09-09 11:32:37:368 [WD Proxy] Proxying [POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/appium/app/launch] to [POST http://127.0.0.1:4724/wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/appium/app/launch] with body: {}
2022-09-09 11:32:37:373 [WinAppDriver] ==========================================
2022-09-09 11:32:37:374 [WinAppDriver] POST /wd/hub/session/E220063C-E1F7-408E-B6F8-BB41E584B492/appium/app/launch HTTP/1.1
2022-09-09 11:32:37:375 [WinAppDriver] Accept: application/json, */*
2022-09-09 11:32:37:375 [WinAppDriver] Connection: keep-alive
2022-09-09 11:32:37:375 [WinAppDriver] Content-Length: 2
2022-09-09 11:32:37:377 [WinAppDriver] Content-Type: application/json; charset=utf-8
2022-09-09 11:32:37:377 [WinAppDriver] Host: 127.0.0.1:4724
2022-09-09 11:32:37:378 [WinAppDriver] User-Agent: appium
2022-09-09 11:32:37:379 [WinAppDriver]
2022-09-09 11:32:37:379 [WinAppDriver] {}
2022-09-09 11:33:12:620 [WinAppDriver] HTTP/1.1 500 Internal Error
2022-09-09 11:33:12:621 [WinAppDriver] Content-Length: 133
2022-09-09 11:33:12:621 [WinAppDriver] Content-Type: application/json
2022-09-09 11:33:12:621 [WinAppDriver]
2022-09-09 11:33:12:622 [WinAppDriver] {"status":13,"value":{"error":"unknown error","message":"An unknown error occurred in the remote end while processing the command."}}
2022-09-09 11:33:12:623 [WD Proxy] Got response with status 500: {"status":13,"value":{"error":"unknown error","message":"An unknown error occurred in the remote end while processing the command."}}
2022-09-09 11:33:12:719 [W3C] Matched W3C error code 'unknown error' to UnknownError
2022-09-09 11:33:12:774 [HTTP] <-- POST /wd/hub/session/27eebfce-8b7a-4e5e-b9ee-a9cc6cad07dd/appium/app/launch 500 35416 ms - 884
2022-09-09 11:33:12:775 [HTTP]
Thanks in advance.
Hi,
We're using WinAppDriver through Appium for performance testing. The scenario is opening the app under test 3 times, and calculating the average startup time. After closing the app and try to launch it again, the app opens, but the test fails due to a 500 unknown error from WinAppDriver.
Here is the log:
Appium version: 1.21.0
WinAppDriver: 1.2.1
Is there any way of further inspecting this "unknown error"?
Thanks in advance.