feat: add retry once with reconnection to the remote debugger to reduce no response condtion error #2334

KazuCocoa · 2024-02-28T09:27:22Z

I observed that a remote debugger session could have no response situation by the web inspector. I assumed re-connection and retry again could help for this since the condition did not keep to the next session.

This PR confirmed that when driver.find_element :xpath, "//*" got a timeout in the atom execution, reconnected, and re-sent the same request again to the same WebView context; it returned the expected response. My test was a real device. For the simulator, maybe it won't reach this retrial. I haven't observed this case in simulators so far.

This behavior is kind of frequently occurs in iOS 17 x Safari 17. Thus, I wondered if we could do this trick as a workaround. Hopefully, Apple will improve this case, but for now, this retrial at least helps our mobile safari/webview automation for iOS 17.

Technically, maybe this can be only for iOS 17/safari 17. iOS 16/Safari 16 is stabler than this iOS/safari 17 case, so the current expectation is iOS 16/safari 16 may not reach the retrial. (No issues exist even iOS 16 and lower reach this retry, so I haven't added version check)

Log with this retrial example. This logs is a recovery case by this PR change.

HTTP] --> POST /session/c5300bd3-0b8c-462c-8905-a030ee1d7928/element
[HTTP] {"using":"xpath","value":"//*"}
[XCUITestDriver@fe18 (c5300bd3)] Calling AppiumDriver.findElement() with args: ["xpath","//*","c5300bd3-0b8c-462c-8905-a030ee1d7928"]
[XCUITestDriver@fe18 (c5300bd3)] Executing command 'findElement'
[XCUITestDriver@fe18 (c5300bd3)] Valid locator strategies for this request: xpath, id, name, class name, -ios predicate string, -ios class chain, accessibility id, css selector
[XCUITestDriver@fe18 (c5300bd3)] Waiting up to 0 ms for condition
[RemoteDebugger] Executing atom 'find_element_fragment' with 'args=["xpath","//*",null]; frames='
[RemoteDebugger] Executing 'find_element_fragment' atom in default context
[RemoteDebugger] Sending javascript command: '(function(){return (function(){var ba=this||sel...'
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1', target 'page-45' (id: 90): 'Runtime.evaluate'
[RemoteDebugger] Page changed: {
[RemoteDebugger]   "1": {
[RemoteDebugger]     "WIRTitleKey": "",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "about:blank",
[RemoteDebugger]     "WIRPageIdentifierKey": 1,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022",
[RemoteDebugger]     "WIRConnectionIdentifierKey": "91a8261a-898b-4786-be68-2d31a99b9567"
[RemoteDebugger]   },
[RemoteDebugger]   "2": {
[RemoteDebugger]     "WIRTitleKey": "Grammarly for Safari — Extension Background Content",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "safari-web-extension://9DEC5547-BBBF-4DE0-9E21-41CD62B14C23/_generated_background_page.html",
[RemoteDebugger]     "WIRPageIdentifierKey": 2,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   },
[RemoteDebugger]   "3": {
[RemoteDebugger]     "WIRTitleKey": "1Password 7 — Extension Background Content",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "safari-web-extension://4C42F3A6-BDB9-45F5-A91F-47CF43EFA4FD/background/background.html",
[RemoteDebugger]     "WIRPageIdentifierKey": 3,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   }
[RemoteDebugger] }
[XCUITestDriver@fe18 (c5300bd3)] Remote debugger notified us of a new page listing: {"appIdKey":"4022","pageArray":[{"id":1,"title":"","url":"about:blank","isKey":true},{"id":2,"title":"Grammarly for Safari — Extension Background Content","url":"safari-web-extension://9DEC5547-BBBF-4DE0-9E21-41CD62B14C23/_generated_background_page.html","isKey":false},{"id":3,"title":"1Password 7 — Extension Background Content","url":"safari-web-extension://4C42F3A6-BDB9-45F5-A91F-47CF43EFA4FD/background/background.html","isKey":false}]}
[XCUITestDriver@fe18 (c5300bd3)] Checking if page needs to load
[XCUITestDriver@fe18 (c5300bd3)] New page listing is same as old, doing nothing
[XCUITestDriver@fe18 (c5300bd3)] Redirected from 'https://www.rakuten.co.jp/' to 'about:blank'
[RemoteDebugger] Received page change notice for app 'PID:4022' but the listing has not changed. Ignoring.
[RemoteDebugger] Page changed: {
[RemoteDebugger]   "1": {
[RemoteDebugger]     "WIRTitleKey": "",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "about:blank",
[RemoteDebugger]     "WIRPageIdentifierKey": 1,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022",
[RemoteDebugger]     "WIRConnectionIdentifierKey": "91a8261a-898b-4786-be68-2d31a99b9567"
[RemoteDebugger]   },
[RemoteDebugger]   "2": {
[RemoteDebugger]     "WIRTitleKey": "Grammarly for Safari — Extension Background Content",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "safari-web-extension://9DEC5547-BBBF-4DE0-9E21-41CD62B14C23/_generated_background_page.html",
[RemoteDebugger]     "WIRPageIdentifierKey": 2,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   },
[RemoteDebugger]   "3": {
[RemoteDebugger]     "WIRTitleKey": "1Password 7 — Extension Background Content",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "safari-web-extension://4C42F3A6-BDB9-45F5-A91F-47CF43EFA4FD/background/background.html",
[RemoteDebugger]     "WIRPageIdentifierKey": 3,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   }
[RemoteDebugger] }
[XCUITestDriver@fe18 (c5300bd3)] Remote debugger notified us of a new page listing: {"appIdKey":"4022","pageArray":[{"id":1,"title":"","url":"about:blank","isKey":true},{"id":2,"title":"Grammarly for Safari — Extension Background Content","url":"safari-web-extension://9DEC5547-BBBF-4DE0-9E21-41CD62B14C23/_generated_background_page.html","isKey":false},{"id":3,"title":"1Password 7 — Extension Background Content","url":"safari-web-extension://4C42F3A6-BDB9-45F5-A91F-47CF43EFA4FD/background/background.html","isKey":false}]}
[XCUITestDriver@fe18 (c5300bd3)] Checking if page needs to load
[XCUITestDriver@fe18 (c5300bd3)] New page listing is same as old, doing nothing
[RemoteDebugger] Page changed: {
[RemoteDebugger]   "1": {
[RemoteDebugger]     "WIRTitleKey": "楽天市場",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "https://www.rakuten.co.jp/",
[RemoteDebugger]     "WIRPageIdentifierKey": 1,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022",
[RemoteDebugger]     "WIRConnectionIdentifierKey": "91a8261a-898b-4786-be68-2d31a99b9567"
[RemoteDebugger]   },
[RemoteDebugger]   "2": {
[RemoteDebugger]     "WIRTitleKey": "Grammarly for Safari — Extension Background Content",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "safari-web-extension://9DEC5547-BBBF-4DE0-9E21-41CD62B14C23/_generated_background_page.html",
[RemoteDebugger]     "WIRPageIdentifierKey": 2,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   },
[RemoteDebugger]   "3": {
[RemoteDebugger]     "WIRTitleKey": "1Password 7 — Extension Background Content",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "safari-web-extension://4C42F3A6-BDB9-45F5-A91F-47CF43EFA4FD/background/background.html",
[RemoteDebugger]     "WIRPageIdentifierKey": 3,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   }
[RemoteDebugger] }
[XCUITestDriver@fe18 (c5300bd3)] Remote debugger notified us of a new page listing: {"appIdKey":"4022","pageArray":[{"id":1,"title":"楽天市場","url":"https://www.rakuten.co.jp/","isKey":true},{"id":2,"title":"Grammarly for Safari — Extension Background Content","url":"safari-web-extension://9DEC5547-BBBF-4DE0-9E21-41CD62B14C23/_generated_background_page.html","isKey":false},{"id":3,"title":"1Password 7 — Extension Background Content","url":"safari-web-extension://4C42F3A6-BDB9-45F5-A91F-47CF43EFA4FD/background/background.html","isKey":false}]}
[XCUITestDriver@fe18 (c5300bd3)] Checking if page needs to load
[XCUITestDriver@fe18 (c5300bd3)] New page listing is same as old, doing nothing
[XCUITestDriver@fe18 (c5300bd3)] Redirected from 'about:blank' to 'https://www.rakuten.co.jp/'
[XCUITestDriver@fe18 (c5300bd3)] Matched '/alert/text' to command name 'getAlertText'
[XCUITestDriver@fe18 (c5300bd3)] Proxying [GET /alert/text] to [GET http://192.168.5.3:8100/session/0623AFF5-4B67-489F-B6F8-0ACD98F7DF6C/alert/text] with no body
[XCUITestDriver@fe18 (c5300bd3)] connect ECONNREFUSED 192.168.5.3:8100
[XCUITestDriver@fe18 (c5300bd3)] Matched '/alert/text' to command name 'getAlertText'
[XCUITestDriver@fe18 (c5300bd3)] Proxying [GET /alert/text] to [GET http://192.168.5.3:8100/session/0623AFF5-4B67-489F-B6F8-0ACD98F7DF6C/alert/text] with no body
[XCUITestDriver@fe18 (c5300bd3)] connect ECONNREFUSED 192.168.5.3:8100
[XCUITestDriver@fe18 (c5300bd3)] Matched '/alert/text' to command name 'getAlertText'
[XCUITestDriver@fe18 (c5300bd3)] Proxying [GET /alert/text] to [GET http://192.168.5.3:8100/session/0623AFF5-4B67-489F-B6F8-0ACD98F7DF6C/alert/text] with no body
[XCUITestDriver@fe18 (c5300bd3)] connect ECONNREFUSED 192.168.5.3:8100
[XCUITestDriver@fe18 (c5300bd3)] Matched '/alert/text' to command name 'getAlertText'
[XCUITestDriver@fe18 (c5300bd3)] Proxying [GET /alert/text] to [GET http://192.168.5.3:8100/session/0623AFF5-4B67-489F-B6F8-0ACD98F7DF6C/alert/text] with no body
[XCUITestDriver@fe18 (c5300bd3)] connect ECONNREFUSED 192.168.5.3:8100
[RemoteDebugger] Received page change notice for app 'PID:4022' but the listing has not changed. Ignoring.
[RemoteDebugger] Page changed: {
[RemoteDebugger]   "1": {
[RemoteDebugger]     "WIRTitleKey": "楽天市場",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "https://www.rakuten.co.jp/",
[RemoteDebugger]     "WIRPageIdentifierKey": 1,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022",
[RemoteDebugger]     "WIRConnectionIdentifierKey": "91a8261a-898b-4786-be68-2d31a99b9567"
[RemoteDebugger]   },
[RemoteDebugger]   "2": {
[RemoteDebugger]     "WIRTitleKey": "Grammarly for Safari — Extension Background Content",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "safari-web-extension://9DEC5547-BBBF-4DE0-9E21-41CD62B14C23/_generated_background_page.html",
[RemoteDebugger]     "WIRPageIdentifierKey": 2,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   },
[RemoteDebugger]   "3": {
[RemoteDebugger]     "WIRTitleKey": "1Password 7 — Extension Background Content",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "safari-web-extension://4C42F3A6-BDB9-45F5-A91F-47CF43EFA4FD/background/background.html",
[RemoteDebugger]     "WIRPageIdentifierKey": 3,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   }
[RemoteDebugger] }
[XCUITestDriver@fe18 (c5300bd3)] Remote debugger notified us of a new page listing: {"appIdKey":"4022","pageArray":[{"id":1,"title":"楽天市場","url":"https://www.rakuten.co.jp/","isKey":true},{"id":2,"title":"Grammarly for Safari — Extension Background Content","url":"safari-web-extension://9DEC5547-BBBF-4DE0-9E21-41CD62B14C23/_generated_background_page.html","isKey":false},{"id":3,"title":"1Password 7 — Extension Background Content","url":"safari-web-extension://4C42F3A6-BDB9-45F5-A91F-47CF43EFA4FD/background/background.html","isKey":false}]}
[XCUITestDriver@fe18 (c5300bd3)] Checking if page needs to load
...
[XCUITestDriver@fe18 (c5300bd3)] Proxying [GET /alert/text] to [GET http://192.168.5.3:8100/session/0623AFF5-4B67-489F-B6F8-0ACD98F7DF6C/alert/text] with no body
[XCUITestDriver@fe18 (c5300bd3)] connect ECONNREFUSED 192.168.5.3:8100
[XCUITestDriver@fe18 (c5300bd3)] Error received while executing atom: operation timed out
[XCUITestDriver@fe18 (c5300bd3)] Retry to send the same request after re-connecting to the remote debugger.
[RemoteDebugger] Disconnecting from remote debugger
[RemoteDebugger] Cleaning up listeners
[RemoteDebugger] Remote Debugger version 11.0.2
[RemoteDebugger] useNewSafari --> false
[RemoteDebugger] Checking which communication style to use (Safari on platform version '17.0')
[RemoteDebugger] Platform version equal or higher than '12.2': true
[RemoteDebugger] Setting communication protocol: using Target-based communication
[RemoteDebugger] Sending connection key request
[RemoteDebugger] Sending '_rpc_reportIdentifier:' message (id: 0): 'setConnectionKey'
[XCUITestDriver@fe18 (c5300bd3)] Attempting to set context to 'WEBVIEW_4022.1' from 'NATIVE_APP'
[RemoteDebugger] Selecting page '1' on app 'PID:4022' and forwarding socket setup
[RemoteDebugger] Sending '_rpc_forwardIndicateWebView:' message to app 'PID:4022', page '1' (id: 2): 'indicateWebView'
[RemoteDebugger] Sending to Web Inspector took 22ms
[RemoteDebugger] Sending to Web Inspector took 3ms
[RemoteDebugger] Sending '_rpc_forwardIndicateWebView:' message to app 'PID:4022', page '1' (id: 4): 'indicateWebView'
[RemoteDebugger] Sending to Web Inspector took 1ms
[RemoteDebugger] Sending '_rpc_forwardSocketSetup:' message to app 'PID:4022', page '1' (id: 6): 'setSenderKey'
[RemoteDebugger] Sending to Web Inspector took 1ms
[RemoteDebugger] Sender key set
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1' (id: 8): 'Inspector.enable'
[RemoteDebugger] Sending to Web Inspector took 1ms
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1' (id: 10): 'Page.enable'
[RemoteDebugger] Sending to Web Inspector took 1ms
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1' (id: 12): 'Network.enable'
[RemoteDebugger] Sending to Web Inspector took 1ms
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1' (id: 14): 'Runtime.enable'
[RemoteDebugger] Sending to Web Inspector took 0ms
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1' (id: 16): 'Heap.enable'
[RemoteDebugger] Sending to Web Inspector took 1ms
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1' (id: 18): 'Debugger.enable'
[RemoteDebugger] Sending to Web Inspector took 1ms
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1' (id: 20): 'Console.enable'
[RemoteDebugger] Sending to Web Inspector took 1ms
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1' (id: 22): 'Inspector.initialized'
[RemoteDebugger] Sending to Web Inspector took 0ms
[RemoteDebugger] Sending javascript command: 'document.readyState;'
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1' (id: 24): 'Runtime.evaluate'
[RemoteDebugger] Received connected automation availability state: "WIRAutomationAvailabilityAvailable"
[RemoteDebugger] Received connected applications list: PID:4022
[RemoteDebugger] Received connected driver list: {}
[RemoteDebugger] Notified that new application 'PID:4079' has connected
[RemoteDebugger] Page changed: {
[RemoteDebugger]   "1": {
[RemoteDebugger]     "WIRTitleKey": "楽天市場",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "https://www.rakuten.co.jp/",
[RemoteDebugger]     "WIRPageIdentifierKey": 1,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   },
[RemoteDebugger]   "2": {
[RemoteDebugger]     "WIRTitleKey": "Grammarly for Safari — Extension Background Content",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "safari-web-extension://9DEC5547-BBBF-4DE0-9E21-41CD62B14C23/_generated_background_page.html",
[RemoteDebugger]     "WIRPageIdentifierKey": 2,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   },
[RemoteDebugger]   "3": {
[RemoteDebugger]     "WIRTitleKey": "1Password 7 — Extension Background Content",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "safari-web-extension://4C42F3A6-BDB9-45F5-A91F-47CF43EFA4FD/background/background.html",
[RemoteDebugger]     "WIRPageIdentifierKey": 3,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   }
[RemoteDebugger] }
[XCUITestDriver@fe18 (c5300bd3)] Remote debugger notified us of a new page listing: {"appIdKey":"4022","pageArray":[{"id":1,"title":"楽天市場","url":"https://www.rakuten.co.jp/","isKey":false},{"id":2,"title":"Grammarly for Safari — Extension Background Content","url":"safari-web-extension://9DEC5547-BBBF-4DE0-9E21-41CD62B14C23/_generated_background_page.html","isKey":false},{"id":3,"title":"1Password 7 — Extension Background Content","url":"safari-web-extension://4C42F3A6-BDB9-45F5-A91F-47CF43EFA4FD/background/background.html","isKey":false}]}
[XCUITestDriver@fe18 (c5300bd3)] We are in the middle of selecting a page, ignoring
[RemoteDebugger] Target created for app 'PID:4022' and page '1': {"targetId":"page-45","type":"page"}
[RemoteDebugger] Page changed: {
[RemoteDebugger]   "1": {
[RemoteDebugger]     "WIRTitleKey": "楽天市場",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "https://www.rakuten.co.jp/",
[RemoteDebugger]     "WIRPageIdentifierKey": 1,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022",
[RemoteDebugger]     "WIRConnectionIdentifierKey": "af6b2c0c-3703-484f-93c6-bf89983412ca"
[RemoteDebugger]   },
[RemoteDebugger]   "2": {
[RemoteDebugger]     "WIRTitleKey": "Grammarly for Safari — Extension Background Content",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "safari-web-extension://9DEC5547-BBBF-4DE0-9E21-41CD62B14C23/_generated_background_page.html",
[RemoteDebugger]     "WIRPageIdentifierKey": 2,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   },
[RemoteDebugger]   "3": {
[RemoteDebugger]     "WIRTitleKey": "1Password 7 — Extension Background Content",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",
[RemoteDebugger]     "WIRURLKey": "safari-web-extension://4C42F3A6-BDB9-45F5-A91F-47CF43EFA4FD/background/background.html",
[RemoteDebugger]     "WIRPageIdentifierKey": 3,
[RemoteDebugger]     "WIRHostApplicationIdentifierKey": "PID:4022"
[RemoteDebugger]   }
[RemoteDebugger] }
[XCUITestDriver@fe18 (c5300bd3)] Remote debugger notified us of a new page listing: {"appIdKey":"4022","pageArray":[{"id":1,"title":"楽天市場","url":"https://www.rakuten.co.jp/","isKey":true},{"id":2,"title":"Grammarly for Safari — Extension Background Content","url":"safari-web-extension://9DEC5547-BBBF-4DE0-9E21-41CD62B14C23/_generated_background_page.html","isKey":false},{"id":3,"title":"1Password 7 — Extension Background Content","url":"safari-web-extension://4C42F3A6-BDB9-45F5-A91F-47CF43EFA4FD/background/background.html","isKey":false}]}
[XCUITestDriver@fe18 (c5300bd3)] We are in the middle of selecting a page, ignoring
[RemoteDebugger] Page readiness check timed out after 5000ms
[RemoteDebugger] Waiting for page readiness
[RemoteDebugger] Page load timer not a timer. Creating new timer
[RemoteDebugger] Sending javascript command: 'document.readyState;'
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1', target 'page-45' (id: 26): 'Runtime.evaluate'
[RemoteDebugger] Handling message (id: '9')
[RemoteDebugger] Handling message (id: '11')
[RemoteDebugger] Handling message (id: '13')
[RemoteDebugger] Handling message (id: '15')
[RemoteDebugger] Handling message (id: '17')
[RemoteDebugger] Handling message (id: '19')
[RemoteDebugger] Handling message (id: '21')
[RemoteDebugger] Handling message (id: '23')
[RemoteDebugger] Handling message (id: '25')
[RemoteDebugger] Setting communication protocol: using Target-based communication
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1', target 'page-45' (id: 28): 'Runtime.evaluate'
[RemoteDebugger] Received data response from send (id: 26): '"complete"'
[RemoteDebugger] Received data response from send (id: 28): '"complete"'
[RemoteDebugger] Sending to Web Inspector took 91ms
[RemoteDebugger] Sending to Web Inspector took 5150ms
[RemoteDebugger] Document readyState is 'complete'
[RemoteDebugger] Page is ready in 3.08525ms
[RemoteDebugger] Selected page after 5174ms
[RemoteDebugger] Starting to listen for JavaScript console
[RemoteDebugger] Starting to listen for network events
[RemoteDebugger] Executing atom 'find_element_fragment' with 'args=["xpath","//*",null]; frames='
[RemoteDebugger] Executing 'find_element_fragment' atom in default context
[RemoteDebugger] Sending javascript command: '(function(){return (function(){var ba=this||sel...'
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1', target 'page-45' (id: 30): 'Runtime.evaluate'
[RemoteDebugger] Received data response from send (id: 30): '"{\"status\":0,\"value\":{\"ELEMENT\":\":wdc:1709111893015\"}}"'
[RemoteDebugger] Sending to Web Inspector took 188ms
[RemoteDebugger] Received result for atom 'find_element_fragment' execution: {"ELEMENT":":wdc:1709111893015"}
[XCUITestDriver@fe18 (c5300bd3)] Responding to client with driver.findElement() result: {"element-6066-11e4-a52e-4f735466cecf":":wdc:1709111893015","ELEMENT":":wdc:1709111893015"}
[HTTP] <-- POST /session/c5300bd3-0b8c-462c-8905-a030ee1d7928/element 200 125641 ms - 101
[HTTP]

mykola-mokhnach · 2024-02-28T13:29:41Z

I believe this approach could be improved.

Obviously the original issue lies somewhere in the remote debugger client implementation, and prevents us from getting a proper response to Runtime.evaluate requests (RD simply does not respond). I believe this might be happening because we don't respect some important event after which such request could be send to a page. Maybe, it is just a classic race condition.

For example:

[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1' (id: 24): 'Runtime.evaluate'
[RemoteDebugger] Page readiness check timed out after 5000ms

and then we never see any response to the request identified by 24, which means it might be just stuck somewhere inside RD internals since we did not send it in time or did not send it with correct arguments.

What we could try now:

Track RD interaction on iOS 17 to make sure we properly mimic what Safari debugger does
Apply a dumb, but still effective technique by sending the page readiness request periodically and monitor when we actually receive a response to it

KazuCocoa · 2024-02-28T17:23:23Z

Let me dig into the response message tonight.

After:

[XCUITestDriver@fe18 (c5300bd3)] Retry to send the same request after re-connecting to the remote debugger.
[RemoteDebugger] Disconnecting from remote debugger
[RemoteDebugger] Cleaning up listeners
[RemoteDebugger] Remote Debugger version 11.0.2

was after re-connected one. So the no response was for

[RemoteDebugger] Executing 'find_element_fragment' atom in default context
[RemoteDebugger] Sending javascript command: '(function(){return (function(){var ba=this||sel...'
[RemoteDebugger] Sending '_rpc_forwardSocketData:' message to app 'PID:4022', page '1', target 'page-45' (id: 90): 'Runtime.evaluate'
[RemoteDebugger] Page changed: {
[RemoteDebugger]   "1": {
[RemoteDebugger]     "WIRTitleKey": "",
[RemoteDebugger]     "WIRTypeKey": "WIRTypeWebPage",

Before the
https://gist.github.com/KazuCocoa/692859d44d9608f028c6af85eda29636 is the full appium server log. [RemoteDebugger] Disconnecting from remote debugger is by this pr change.

I'll split the timeout change as another pr btw.

debugging : https://github.com/appium/appium-remote-debugger/compare/debug?expand=1

KazuCocoa · 2024-07-10T07:42:11Z

Just a note. like this nonresponse (and needed to re-touch) behavior occurred via vanilla web inspector (no appium env) on my local. I'll check again with newer host Safari version first.

KazuCocoa · 2024-07-11T06:48:22Z

Hm, I haven't seen this behavior with iOS 18 beta so far on my local.

KazuCocoa · 2024-07-11T07:08:13Z

Potentially this is only for iOS 17 env.

Similar disconnection occurred in await this.remote.navToUrl as well on iOS 17 so iOS 17 Safari could be not so stable for web inspector usage...? iOS 18 beta seems stabler for now.

si-net · 2024-08-21T11:15:39Z

@KazuCocoa We observed that this issue is isolated to iOS versions 17.02-17.05. Unfortunately there is nothing mentioned in the official release notes about this.

We were able to solve the problem by killing Safari and then launching it again, before attempting to connect to the remote debugger.

si-net · 2024-09-18T07:30:16Z

Here is the official bug fix for safari: https://developer.apple.com/documentation/safari-release-notes/safari-17_6-release-notes#Web-Inspector So this problem is solved for iOS 17.6 +

KazuCocoa · 2024-09-19T02:03:49Z

I'm not sure the line is for this issue, but if so, that's great news

KazuCocoa · 2024-10-08T05:09:04Z

Close this PR for now since maybe iOS 17.6 no longer has this issue (hopefully)

-> https://appium.github.io/appium-xcuitest-driver/latest/guides/troubleshooting/#frequent-disconnecting-from-remote-debugger-error-in-ios-17

KazuCocoa added 3 commits February 27, 2024 01:28

retry with reconnection

05432f9

recovery with reconnection

398744a

add webviewAtomWaitTimeout

26702b8

KazuCocoa changed the title ~~fix: add retry once with reconnection to the remote debugger for no response condtion~~ feat: add webviewAtomWaitTimeout and retry once with reconnection to the remote debugger for no response condtion Feb 28, 2024

fix lint

9bac2a5

KazuCocoa marked this pull request as ready for review February 28, 2024 09:53

KazuCocoa requested review from mykola-mokhnach and jlipps February 28, 2024 09:54

KazuCocoa added 2 commits February 28, 2024 01:57

>0

77d985e

correct docs

050c5fa

KazuCocoa changed the title ~~feat: add webviewAtomWaitTimeout and retry once with reconnection to the remote debugger for no response condtion~~ feat: add webviewAtomWaitTimeout and retry once with reconnection to the remote debugger to reduce no response condtion error Feb 28, 2024

KazuCocoa marked this pull request as draft February 28, 2024 17:23

KazuCocoa mentioned this pull request Feb 28, 2024

feat: add webviewAtomWaitTimeout to control timeout for the atom execution #2335

Merged

Merge branch 'master' into webview-retry-with-reconnect

10723c2

KazuCocoa changed the title ~~feat: add webviewAtomWaitTimeout and retry once with reconnection to the remote debugger to reduce no response condtion error~~ feat: add retry once with reconnection to the remote debugger to reduce no response condtion error Feb 29, 2024

KazuCocoa added 4 commits March 7, 2024 09:58

Merge branch 'master' into webview-retry-with-reconnect

48f0d58

Merge branch 'master' into webview-retry-with-reconnect

c64d0bd

Merge branch 'master' into webview-retry-with-reconnect

094a1a4

Merge branch 'master' into webview-retry-with-reconnect

89300ca

Merge branch 'master' into webview-retry-with-reconnect

6e091b8

KazuCocoa added 5 commits July 11, 2024 00:48

Update web.js

9e300a0

add ios 17

9bb2616

tweak the logic

97858d4

add FIXME

920b28f

Merge branch 'master' into webview-retry-with-reconnect

44ec815

KazuCocoa added 5 commits July 14, 2024 22:06

simplify a bit

04167f1

Update web.js

50cda10

Merge branch 'master' into webview-retry-with-reconnect

6958829

Merge branch 'master' into webview-retry-with-reconnect

e8ba758

Merge branch 'master' into webview-retry-with-reconnect

6c62f08

KazuCocoa added 2 commits August 22, 2024 15:43

Merge branch 'master' into webview-retry-with-reconnect

9db7b75

Merge branch 'master' into webview-retry-with-reconnect

87b9284

KazuCocoa mentioned this pull request Oct 6, 2024

docs: add remote debugger disconnection in troubleshooting #2476

Merged

Merge branch 'master' into webview-retry-with-reconnect

de5173e

KazuCocoa closed this Oct 8, 2024

KazuCocoa deleted the webview-retry-with-reconnect branch October 8, 2024 05:09

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat: add retry once with reconnection to the remote debugger to reduce no response condtion error #2334

feat: add retry once with reconnection to the remote debugger to reduce no response condtion error #2334

KazuCocoa commented Feb 28, 2024 •

edited

Loading

mykola-mokhnach commented Feb 28, 2024

KazuCocoa commented Feb 28, 2024 •

edited

Loading

KazuCocoa commented Jul 10, 2024

KazuCocoa commented Jul 11, 2024 •

edited

Loading

KazuCocoa commented Jul 11, 2024 •

edited

Loading

si-net commented Aug 21, 2024 •

edited

Loading

si-net commented Sep 18, 2024

KazuCocoa commented Sep 19, 2024

KazuCocoa commented Oct 8, 2024

feat: add retry once with reconnection to the remote debugger to reduce no response condtion error #2334

feat: add retry once with reconnection to the remote debugger to reduce no response condtion error #2334

Conversation

KazuCocoa commented Feb 28, 2024 • edited Loading

mykola-mokhnach commented Feb 28, 2024

KazuCocoa commented Feb 28, 2024 • edited Loading

KazuCocoa commented Jul 10, 2024

KazuCocoa commented Jul 11, 2024 • edited Loading

KazuCocoa commented Jul 11, 2024 • edited Loading

si-net commented Aug 21, 2024 • edited Loading

si-net commented Sep 18, 2024

KazuCocoa commented Sep 19, 2024

KazuCocoa commented Oct 8, 2024

KazuCocoa commented Feb 28, 2024 •

edited

Loading

KazuCocoa commented Feb 28, 2024 •

edited

Loading

KazuCocoa commented Jul 11, 2024 •

edited

Loading

KazuCocoa commented Jul 11, 2024 •

edited

Loading

si-net commented Aug 21, 2024 •

edited

Loading