appium / appium-mac2-driver

Next-gen Appium macOS driver, backed by Apple XCTest
Apache License 2.0
115 stars 24 forks source link

NoSuchElementError encountered in CI environment but working on local machine #282

Open MagdelineNg opened 4 months ago

MagdelineNg commented 4 months ago

Is there a reason why the Mac2 driver may throw NoSuchElementError: unable to find an element using 'xpath', value '//XCUIElementTypeButton[@elementType="9" and @identifier="_NS:291"]' in the CI environment (specifically, running on an ECS VM with GUI in Jenkins), but the driver able to locate the element using the same XPath when I run the script locally on my Mac?

The Jenkins node is able to locate certain Xpaths but not others as seen in logs where some status codes are 200 while others are 404. This is the environment I am running Mac2 driver on:

+ appium -v
Installed appium version is 2.5.1

[Pipeline] sh xcode-select -p
xcode-select is pointing to XCode.app found at /Applications/Xcode.app/Contents/Developer

[Pipeline] sh xcodebuild -version
xcodebuild version is Xcode 14.1
Build version 14B47b

[Pipeline] sh /bin/bash -l -c 'source scripts_dependencies_venv/bin/activate && (appium driver install mac2 || (deactivate && exit 1)) && deactivate'
Error: ✖ A driver named "mac2" is already installed. Did you mean to update? Run "appium driver update". See installed drivers with "appium driver list --installed".

[Pipeline] sh appium --relaxed-security --log appiumLogs.log --port 4723
[Appium] Welcome to Appium v2.5.1
[Appium] Non-default server args:
[Appium] { relaxedSecurityEnabled: true }
[Appium] The autodetected Appium home path: /Users/IDSDK/.appium
[Appium] Attempting to load driver mac2...
[Appium] Requiring driver at /Users/IDSDK/.appium/node_modules/appium-mac2-driver/build/index.js
[Appium] Mac2Driver has been successfully loaded in 0.063s
[Appium] Appium REST http interface listener started on http://0.0.0.0:4723/
[Appium] You can provide the following URLs in your client code to connect to this server:
[Appium]  http://127.0.0.1:4723/ (only accessible from the same host)
[Appium]  http://10.50.91.97:4723/
[Appium] Available drivers:
[Appium]   - mac2@1.11.0 (automationName 'Mac2')
[Appium] No plugins have been installed. Use the "appium plugin" command to install the one(s) you want to use.

Here are the Appium logs on the VM:

2024-02-26 10:41:39:611 [HTTP] --> POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element
2024-02-26 10:41:39:611 [HTTP] {"using":"xpath","value":"//XCUIElementTypePopUpButton[@elementType=\"14\" and @identifier=\"default-web-browser\"]"}
2024-02-26 10:41:39:612 [Mac2Driver@cac0 (20f48bdb)] Calling AppiumDriver.findElement() with args: ["xpath","//XCUIElementTypePopUpButton[@elementType=\"14\" and @identifier=\"default-web-browser\"]","20f48bdb-1d76-4637-acf9-cce7dd9b832e"]
2024-02-26 10:41:39:612 [Mac2Driver@cac0 (20f48bdb)] Valid locator strategies for this request: id, name, accessibility id, xpath, class name, -ios predicate string, predicate string, -ios class chain, class chain
2024-02-26 10:41:39:612 [WD Proxy] Matched '/element' to command name 'findElement'
2024-02-26 10:41:39:612 [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:10101/session/BEE743B2-0B98-40B1-AD75-54DF4EB41AF6/element] with body: {"using":"xpath","value":"//XCUIElementTypePopUpButton[@elementType=\"14\" and @identifier=\"default-web-browser\"]"}
2024-02-26 10:41:39:614 [WebDriverAgentMac] [xcodebuild] t =     9.70s Find the Application 'com.apple.systempreferences'
2024-02-26 10:41:39:913 [WebDriverAgentMac] [xcodebuild] t =    10.00s Get all elements bound by accessibility element for: Elements matching predicate 'BLOCKPREDICATE(0x600003aa0f30)'
2024-02-26 10:41:39:913 [WebDriverAgentMac] [xcodebuild] t =    10.00s     Requesting snapshot of accessibility hierarchy for app with pid 17124
2024-02-26 10:41:40:120 [WebDriverAgentMac] [xcodebuild] t =    10.21s     Find: Descendants matching type Any
2024-02-26 10:41:40:122 [WebDriverAgentMac] [xcodebuild] t =    10.21s     Find: Elements matching predicate 'BLOCKPREDICATE(0x600003aa0f30)'
2024-02-26 10:41:40:135 [WD Proxy] Got response with status 200: {"value":{"ELEMENT":"8472E0F9-B45F-4ACE-8F66-987E9214D63B","element-6066-11e4-a52e-4f735466cecf":"8472E0F9-B45F-4ACE-8F66-987E9214D63B"},"sessionId":"BEE743B2-0B98-40B1-AD75-54DF4EB41AF6"}
2024-02-26 10:41:40:135 [Mac2Driver@cac0 (20f48bdb)] Responding to client with driver.findElement() result: {"element-6066-11e4-a52e-4f735466cecf":"8472E0F9-B45F-4ACE-8F66-987E9214D63B","ELEMENT":"8472E0F9-B45F-4ACE-8F66-987E9214D63B"}
2024-02-26 10:41:40:136 [HTTP] <-- POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element 200 524 ms - 137
2024-02-26 10:41:40:136 [HTTP] 
2024-02-26 10:41:40:137 [HTTP] --> POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element/8472E0F9-B45F-4ACE-8F66-987E9214D63B/click
2024-02-26 10:41:40:137 [HTTP] {}
2024-02-26 10:41:40:137 [Mac2Driver@cac0 (20f48bdb)] Driver proxy active, passing request on via HTTP proxy
2024-02-26 10:41:40:137 [WD Proxy] Matched '/session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element/8472E0F9-B45F-4ACE-8F66-987E9214D63B/click' to command name 'click'
2024-02-26 10:41:40:138 [WD Proxy] Proxying [POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element/8472E0F9-B45F-4ACE-8F66-987E9214D63B/click] to [POST http://127.0.0.1:10101/session/BEE743B2-0B98-40B1-AD75-54DF4EB41AF6/element/8472E0F9-B45F-4ACE-8F66-987E9214D63B/click] with body: {}
2024-02-26 10:41:40:139 [WebDriverAgentMac] [xcodebuild] t =    10.23s Find the "default-web-browser" PopUpButton
2024-02-26 10:41:40:139 [WebDriverAgentMac] [xcodebuild] t =    10.23s     Requesting snapshot of accessibility hierarchy for app with pid 17124
2024-02-26 10:41:40:330 [WebDriverAgentMac] [xcodebuild] t =    10.42s     Find: Descendants matching type Any
2024-02-26 10:41:40:333 [WebDriverAgentMac] [xcodebuild] t =    10.42s     Find: Elements matching predicate 'BLOCKPREDICATE(0x600003aa0f30)'
2024-02-26 10:41:40:336 [WebDriverAgentMac] [xcodebuild] t =    10.43s     Find: Identity Binding
2024-02-26 10:41:40:345 [WebDriverAgentMac] [xcodebuild] t =    10.44s Click "default-web-browser" PopUpButton
2024-02-26 10:41:40:345 [WebDriverAgentMac] [xcodebuild] t =    10.44s     Wait for com.apple.systempreferences to idle
2024-02-26 10:41:40:346 [WebDriverAgentMac] [xcodebuild] t =    10.44s     Find the "default-web-browser" PopUpButton
2024-02-26 10:41:40:347 [WebDriverAgentMac] [xcodebuild] t =    10.44s         Requesting snapshot of accessibility hierarchy for app with pid 17124
2024-02-26 10:41:40:540 [WebDriverAgentMac] [xcodebuild] t =    10.63s         Find: Descendants matching type Any
2024-02-26 10:41:40:543 [WebDriverAgentMac] [xcodebuild] t =    10.63s         Find: Elements matching predicate 'BLOCKPREDICATE(0x600003aa0f30)'
2024-02-26 10:41:40:546 [WebDriverAgentMac] [xcodebuild] t =    10.64s         Find: Identity Binding
2024-02-26 10:41:40:552 [WebDriverAgentMac] [xcodebuild] t =    10.64s     Check for interrupting elements affecting "default-web-browser" PopUpButton
2024-02-26 10:41:40:557 [WebDriverAgentMac] [xcodebuild] t =    10.65s     Synthesize event
2024-02-26 10:41:41:116 [WebDriverAgentMac] [xcodebuild] t =    11.21s         Scroll element to visible
2024-02-26 10:41:41:117 [WebDriverAgentMac] [xcodebuild] t =    11.21s             Scroll ScrollView by dx: -188.00, dy: -592.00
2024-02-26 10:41:41:117 [WebDriverAgentMac] [xcodebuild] t =    11.21s                 Wait for com.apple.systempreferences to idle
2024-02-26 10:41:41:119 [WebDriverAgentMac] [xcodebuild] t =    11.21s                 Find the ScrollView
2024-02-26 10:41:41:279 [WebDriverAgentMac] [xcodebuild] t =    11.37s                 Check for interrupting elements affecting ScrollView
2024-02-26 10:41:41:295 [WebDriverAgentMac] [xcodebuild] t =    11.39s                 Found 1 interrupting element:
2024-02-26 10:41:41:295 [WebDriverAgentMac] [xcodebuild] t =    11.39s                         Dialog at {{1251.0, 748.0}, {260.0, 280.0}} from Application 'com.apple.UserNotificationCenter'
2024-02-26 10:41:41:296 [WebDriverAgentMac] [xcodebuild] t =    11.39s                 Invoking UI interruption monitors for Dialog at {{1251.0, 748.0}, {260.0, 280.0}} from Application 'com.apple.UserNotificationCenter'
2024-02-26 10:41:41:296 [WebDriverAgentMac] [xcodebuild] t =    11.39s                         Checking for user permission dialogs...
2024-02-26 10:41:41:296 [WebDriverAgentMac] [xcodebuild] t =    11.39s                         Checking existence of `StaticText`
2024-02-26 10:41:41:300 [WebDriverAgentMac] [xcodebuild] t =    11.39s                         Checking for Bluetooth Setup Assistant...
2024-02-26 10:41:41:300 [WebDriverAgentMac] [xcodebuild] t =    11.39s                         Find the Dialog at {{1251.0, 748.0}, {260.0, 280.0}}
2024-02-26 10:41:41:304 [WebDriverAgentMac] [xcodebuild] t =    11.39s                         No monitors handled UI interruption, checking to see if element still exists...
2024-02-26 10:41:41:306 [WebDriverAgentMac] [xcodebuild] t =    11.40s                         Checking existence of `"alert" Dialog`
2024-02-26 10:41:41:309 [WebDriverAgentMac] [xcodebuild] t =    11.40s                     Did not handle the interruption, but will attempt to continue…
2024-02-26 10:41:41:310 [WebDriverAgentMac] [xcodebuild] t =    11.40s                 Synthesize event
2024-02-26 10:41:41:551 [WebDriverAgentMac] [xcodebuild] t =    11.64s                 Wait for com.apple.systempreferences to idle
2024-02-26 10:41:41:553 [WebDriverAgentMac] [xcodebuild] t =    11.64s         Find the "default-web-browser" PopUpButton
2024-02-26 10:41:41:554 [WebDriverAgentMac] [xcodebuild] t =    11.64s             Requesting snapshot of accessibility hierarchy for app with pid 17124
2024-02-26 10:41:41:789 [WebDriverAgentMac] [xcodebuild] t =    11.88s             Find: Descendants matching type Any
2024-02-26 10:41:41:791 [WebDriverAgentMac] [xcodebuild] t =    11.88s             Find: Elements matching predicate 'BLOCKPREDICATE(0x600003aa0f30)'
2024-02-26 10:41:41:794 [WebDriverAgentMac] [xcodebuild] t =    11.88s             Find: Identity Binding
2024-02-26 10:41:42:134 [WebDriverAgentMac] [xcodebuild] t =    12.22s     Wait for com.apple.systempreferences to idle
2024-02-26 10:41:42:136 [WD Proxy] Got response with status 200: {"value":null,"sessionId":"BEE743B2-0B98-40B1-AD75-54DF4EB41AF6"}
2024-02-26 10:41:42:136 [WD Proxy] Replacing sessionId BEE743B2-0B98-40B1-AD75-54DF4EB41AF6 with 20f48bdb-1d76-4637-acf9-cce7dd9b832e
2024-02-26 10:41:42:136 [HTTP] <-- POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element/8472E0F9-B45F-4ACE-8F66-987E9214D63B/click 200 1999 ms - 65
2024-02-26 10:41:42:136 [HTTP] 
2024-02-26 10:41:42:137 [HTTP] --> POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element
2024-02-26 10:41:42:138 [HTTP] {"using":"xpath","value":"//XCUIElementTypeMenuItem[@elementType=\"54\" and @identifier=\"menuAction:\" and @title=\"Google Chrome\"]"}
2024-02-26 10:41:42:138 [Mac2Driver@cac0 (20f48bdb)] Calling AppiumDriver.findElement() with args: ["xpath","//XCUIElementTypeMenuItem[@elementType=\"54\" and @identifier=\"menuAction:\" and @title=\"Google Chrome\"]","20f48bdb-1d76-4637-acf9-cce7dd9b832e"]
2024-02-26 10:41:42:138 [Mac2Driver@cac0 (20f48bdb)] Valid locator strategies for this request: id, name, accessibility id, xpath, class name, -ios predicate string, predicate string, -ios class chain, class chain
2024-02-26 10:41:42:138 [WD Proxy] Matched '/element' to command name 'findElement'
2024-02-26 10:41:42:138 [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:10101/session/BEE743B2-0B98-40B1-AD75-54DF4EB41AF6/element] with body: {"using":"xpath","value":"//XCUIElementTypeMenuItem[@elementType=\"54\" and @identifier=\"menuAction:\" and @title=\"Google Chrome\"]"}
2024-02-26 10:41:42:140 [WebDriverAgentMac] [xcodebuild] t =    12.23s Find the Application 'com.apple.systempreferences'
2024-02-26 10:41:42:460 [WebDriverAgentMac] [xcodebuild] t =    12.55s Get all elements bound by accessibility element for: Elements matching predicate 'BLOCKPREDICATE(0x600003ab88d0)'
2024-02-26 10:41:42:460 [WebDriverAgentMac] [xcodebuild] t =    12.55s     Requesting snapshot of accessibility hierarchy for app with pid 17124
2024-02-26 10:41:42:659 [WebDriverAgentMac] [xcodebuild] t =    12.75s     Find: Descendants matching type Any
2024-02-26 10:41:42:662 [WebDriverAgentMac] [xcodebuild] t =    12.75s     Find: Elements matching predicate 'BLOCKPREDICATE(0x600003ab88d0)'
2024-02-26 10:41:42:674 [WD Proxy] Got response with status 200: {"value":{"ELEMENT":"7D91ADA5-286C-4680-AA21-ABD7B3305BAB","element-6066-11e4-a52e-4f735466cecf":"7D91ADA5-286C-4680-AA21-ABD7B3305BAB"},"sessionId":"BEE743B2-0B98-40B1-AD75-54DF4EB41AF6"}
2024-02-26 10:41:42:674 [Mac2Driver@cac0 (20f48bdb)] Responding to client with driver.findElement() result: {"element-6066-11e4-a52e-4f735466cecf":"7D91ADA5-286C-4680-AA21-ABD7B3305BAB","ELEMENT":"7D91ADA5-286C-4680-AA21-ABD7B3305BAB"}
2024-02-26 10:41:42:675 [HTTP] <-- POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element 200 537 ms - 137
2024-02-26 10:41:42:675 [HTTP] 
2024-02-26 10:41:42:676 [HTTP] --> POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element
2024-02-26 10:41:42:676 [HTTP] {"using":"xpath","value":"//XCUIElementTypeMenuItem[@elementType=\"54\" and @identifier=\"menuAction:\" and @title=\"Google Chrome\"]"}
2024-02-26 10:41:42:676 [Mac2Driver@cac0 (20f48bdb)] Calling AppiumDriver.findElement() with args: ["xpath","//XCUIElementTypeMenuItem[@elementType=\"54\" and @identifier=\"menuAction:\" and @title=\"Google Chrome\"]","20f48bdb-1d76-4637-acf9-cce7dd9b832e"]
2024-02-26 10:41:42:676 [Mac2Driver@cac0 (20f48bdb)] Valid locator strategies for this request: id, name, accessibility id, xpath, class name, -ios predicate string, predicate string, -ios class chain, class chain
2024-02-26 10:41:42:677 [WD Proxy] Matched '/element' to command name 'findElement'
2024-02-26 10:41:42:677 [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:10101/session/BEE743B2-0B98-40B1-AD75-54DF4EB41AF6/element] with body: {"using":"xpath","value":"//XCUIElementTypeMenuItem[@elementType=\"54\" and @identifier=\"menuAction:\" and @title=\"Google Chrome\"]"}
2024-02-26 10:41:42:678 [WebDriverAgentMac] [xcodebuild] t =    12.77s Find the Application 'com.apple.systempreferences'
2024-02-26 10:41:42:948 [WebDriverAgentMac] [xcodebuild] t =    13.04s Get all elements bound by accessibility element for: Elements matching predicate 'BLOCKPREDICATE(0x600003b55530)'
2024-02-26 10:41:42:949 [WebDriverAgentMac] [xcodebuild] t =    13.04s     Requesting snapshot of accessibility hierarchy for app with pid 17124
2024-02-26 10:41:43:145 [WebDriverAgentMac] [xcodebuild] t =    13.24s     Find: Descendants matching type Any
2024-02-26 10:41:43:148 [WebDriverAgentMac] [xcodebuild] t =    13.24s     Find: Elements matching predicate 'BLOCKPREDICATE(0x600003b55530)'
2024-02-26 10:41:43:160 [WD Proxy] Got response with status 200: {"value":{"ELEMENT":"8BB85FB7-FBAF-4EFC-BAFD-8E724FC14B18","element-6066-11e4-a52e-4f735466cecf":"8BB85FB7-FBAF-4EFC-BAFD-8E724FC14B18"},"sessionId":"BEE743B2-0B98-40B1-AD75-54DF4EB41AF6"}
2024-02-26 10:41:43:160 [Mac2Driver@cac0 (20f48bdb)] Responding to client with driver.findElement() result: {"element-6066-11e4-a52e-4f735466cecf":"8BB85FB7-FBAF-4EFC-BAFD-8E724FC14B18","ELEMENT":"8BB85FB7-FBAF-4EFC-BAFD-8E724FC14B18"}
2024-02-26 10:41:43:161 [HTTP] <-- POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element 200 485 ms - 137
2024-02-26 10:41:43:161 [HTTP] 
2024-02-26 10:41:43:162 [HTTP] --> POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element/8BB85FB7-FBAF-4EFC-BAFD-8E724FC14B18/click
2024-02-26 10:41:43:162 [HTTP] {}
2024-02-26 10:41:43:162 [Mac2Driver@cac0 (20f48bdb)] Driver proxy active, passing request on via HTTP proxy
2024-02-26 10:41:43:162 [WD Proxy] Matched '/session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element/8BB85FB7-FBAF-4EFC-BAFD-8E724FC14B18/click' to command name 'click'
2024-02-26 10:41:43:163 [WD Proxy] Proxying [POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element/8BB85FB7-FBAF-4EFC-BAFD-8E724FC14B18/click] to [POST http://127.0.0.1:10101/session/BEE743B2-0B98-40B1-AD75-54DF4EB41AF6/element/8BB85FB7-FBAF-4EFC-BAFD-8E724FC14B18/click] with body: {}
2024-02-26 10:41:43:164 [WebDriverAgentMac] [xcodebuild] t =    13.25s Find the "menuAction:" MenuItem
2024-02-26 10:41:43:164 [WebDriverAgentMac] [xcodebuild] t =    13.25s     Requesting snapshot of accessibility hierarchy for app with pid 17124
2024-02-26 10:41:43:367 [WebDriverAgentMac] [xcodebuild] t =    13.46s     Find: Descendants matching type Any
2024-02-26 10:41:43:370 [WebDriverAgentMac] [xcodebuild] t =    13.46s     Find: Elements matching predicate 'BLOCKPREDICATE(0x600003b55530)'
2024-02-26 10:41:43:373 [WebDriverAgentMac] [xcodebuild] t =    13.46s     Find: Identity Binding
2024-02-26 10:41:43:382 [WebDriverAgentMac] [xcodebuild] t =    13.47s Click "menuAction:" MenuItem
2024-02-26 10:41:43:382 [WebDriverAgentMac] [xcodebuild] t =    13.47s     Wait for com.apple.systempreferences to idle
2024-02-26 10:41:43:384 [WebDriverAgentMac] [xcodebuild] t =    13.47s     Find the "menuAction:" MenuItem
2024-02-26 10:41:43:384 [WebDriverAgentMac] [xcodebuild] t =    13.47s         Requesting snapshot of accessibility hierarchy for app with pid 17124
2024-02-26 10:41:43:586 [WebDriverAgentMac] [xcodebuild] t =    13.68s         Find: Descendants matching type Any
2024-02-26 10:41:43:589 [WebDriverAgentMac] [xcodebuild] t =    13.68s         Find: Elements matching predicate 'BLOCKPREDICATE(0x600003b55530)'
2024-02-26 10:41:43:591 [WebDriverAgentMac] [xcodebuild] t =    13.68s         Find: Identity Binding
2024-02-26 10:41:43:598 [WebDriverAgentMac] [xcodebuild] t =    13.69s     Check for interrupting elements affecting "menuAction:" MenuItem
2024-02-26 10:41:43:599 [WebDriverAgentMac] [xcodebuild] t =    13.69s     Synthesize event
2024-02-26 10:41:43:599 [WebDriverAgentMac] [xcodebuild] t =    13.69s         Checking existence of `"menuAction:" MenuItem`
2024-02-26 10:41:43:753 [WebDriverAgentMac] [xcodebuild] t =    13.84s         Hover menu item 'Google Chrome'
2024-02-26 10:41:43:753 [WebDriverAgentMac] [xcodebuild] t =    13.84s             Wait for com.apple.systempreferences to idle
2024-02-26 10:41:43:754 [WebDriverAgentMac] [xcodebuild] t =    13.85s             Find the "menuAction:" MenuItem
2024-02-26 10:41:43:900 [WebDriverAgentMac] [xcodebuild] t =    13.99s             Check for interrupting elements affecting "menuAction:" MenuItem
2024-02-26 10:41:43:902 [WebDriverAgentMac] [xcodebuild] t =    13.99s             Synthesize event
2024-02-26 10:41:44:116 [WebDriverAgentMac] [xcodebuild] t =    14.21s             Wait for com.apple.systempreferences to idle
2024-02-26 10:41:44:118 [WebDriverAgentMac] [xcodebuild] t =    14.21s         Find the "menuAction:" MenuItem
2024-02-26 10:41:44:119 [WebDriverAgentMac] [xcodebuild] t =    14.21s             Requesting snapshot of accessibility hierarchy for app with pid 17124
2024-02-26 10:41:44:325 [WebDriverAgentMac] [xcodebuild] t =    14.42s             Find: Descendants matching type Any
2024-02-26 10:41:44:328 [WebDriverAgentMac] [xcodebuild] t =    14.42s             Find: Elements matching predicate 'BLOCKPREDICATE(0x600003b55530)'
2024-02-26 10:41:44:331 [WebDriverAgentMac] [xcodebuild] t =    14.42s             Find: Identity Binding
2024-02-26 10:41:45:001 [WebDriverAgentMac] [xcodebuild] t =    15.09s     Wait for com.apple.systempreferences to idle
2024-02-26 10:41:45:003 [WD Proxy] Got response with status 200: {"value":null,"sessionId":"BEE743B2-0B98-40B1-AD75-54DF4EB41AF6"}
2024-02-26 10:41:45:004 [WD Proxy] Replacing sessionId BEE743B2-0B98-40B1-AD75-54DF4EB41AF6 with 20f48bdb-1d76-4637-acf9-cce7dd9b832e
2024-02-26 10:41:45:004 [HTTP] <-- POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element/8BB85FB7-FBAF-4EFC-BAFD-8E724FC14B18/click 200 1842 ms - 65
2024-02-26 10:41:45:004 [HTTP] 
2024-02-26 10:41:46:211 [HTTP] --> POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/execute/sync
2024-02-26 10:41:46:212 [HTTP] {"script":"macos: activateApp","args":[{"path":"/Volumes/jenkins/workspace/PRNum/builds/scripts/ui_automation_test/ui_automation_test_pkgs/1.11.10.110/ubx64arm64/Release/TestHarness/TestApp.app"}]}
2024-02-26 10:41:46:212 [Mac2Driver@cac0 (20f48bdb)] Calling AppiumDriver.execute() with args: ["macos: activateApp",[{"path":"/Volumes/jenkins/workspace/PRNum/builds/scripts/ui_automation_test/ui_automation_test_pkgs/1.11.10.110/ubx64arm64/Release/TestHarness/TestApp.app"}],"20f48bdb-1d76-4637-acf9-cce7dd9b832e"]
2024-02-26 10:41:46:212 [Mac2Driver] Executing extension command 'macos: activateApp'
2024-02-26 10:41:46:213 [WD Proxy] Proxying [POST /wda/apps/activate] to [POST http://127.0.0.1:10101/session/BEE743B2-0B98-40B1-AD75-54DF4EB41AF6/wda/apps/activate] with body: {"path":"/Volumes/jenkins/workspace/PRNum/builds/scripts/ui_automation_test/ui_automation_test_pkgs/1.11.10.110/ubx64arm64/Release/TestHarness/TestApp.app"}
2024-02-26 10:41:46:218 [WebDriverAgentMac] [xcodebuild] t =    16.31s Open com.company.TestApp
2024-02-26 10:41:46:219 [WebDriverAgentMac] [xcodebuild] t =    16.31s     Launch com.company.TestApp
2024-02-26 10:41:46:367 [WebDriverAgentMac] [xcodebuild] t =    16.46s         Wait for accessibility to load
2024-02-26 10:41:46:800 [WebDriverAgentMac] [xcodebuild] t =    16.89s         Setting up automation session
2024-02-26 10:41:46:809 [WebDriverAgentMac] [xcodebuild] t =    16.90s         Wait for com.company.TestApp to idle
2024-02-26 10:41:46:812 [WD Proxy] Got response with status 200: {"value":null,"sessionId":"BEE743B2-0B98-40B1-AD75-54DF4EB41AF6"}
2024-02-26 10:41:46:812 [Mac2Driver@cac0 (20f48bdb)] Responding to client with driver.execute() result: null
2024-02-26 10:41:46:812 [HTTP] <-- POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/execute/sync 200 601 ms - 14
2024-02-26 10:41:46:813 [HTTP] 
2024-02-26 10:41:46:814 [HTTP] --> POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/execute/sync
2024-02-26 10:41:46:814 [HTTP] {"script":"macos: activateApp","args":[{"path":"/Volumes/jenkins/workspace/PRNum/builds/scripts/ui_automation_test/ui_automation_test_pkgs/1.11.10.110/ubx64arm64/Release/TestHarness/TestApp2.app"}]}
2024-02-26 10:41:46:815 [Mac2Driver@cac0 (20f48bdb)] Calling AppiumDriver.execute() with args: ["macos: activateApp",[{"path":"/Volumes/jenkins/workspace/PRNum/builds/scripts/ui_automation_test/ui_automation_test_pkgs/1.11.10.110/ubx64arm64/Release/TestHarness/TestApp2.app"}],"20f48bdb-1d76-4637-acf9-cce7dd9b832e"]
2024-02-26 10:41:46:815 [Mac2Driver] Executing extension command 'macos: activateApp'
2024-02-26 10:41:46:816 [WD Proxy] Proxying [POST /wda/apps/activate] to [POST http://127.0.0.1:10101/session/BEE743B2-0B98-40B1-AD75-54DF4EB41AF6/wda/apps/activate] with body: {"path":"/Volumes/jenkins/workspace/PRNum/builds/scripts/ui_automation_test/ui_automation_test_pkgs/1.11.10.110/ubx64arm64/Release/TestHarness/TestApp2.app"}
2024-02-26 10:41:46:821 [WebDriverAgentMac] [xcodebuild] t =    16.91s Open com.company.AdskIdentityManager
2024-02-26 10:41:46:822 [WebDriverAgentMac] [xcodebuild] t =    16.91s     Launch com.company.AdskIdentityManager
2024-02-26 10:41:47:180 [WebDriverAgentMac] [xcodebuild] t =    17.27s         Wait for accessibility to load
2024-02-26 10:41:47:181 [WebDriverAgentMac] [xcodebuild] t =    17.27s         Setting up automation session
2024-02-26 10:41:47:187 [WebDriverAgentMac] [xcodebuild] t =    17.28s         Wait for com.company.AdskIdentityManager to idle
2024-02-26 10:41:47:189 [WD Proxy] Got response with status 200: {"value":null,"sessionId":"BEE743B2-0B98-40B1-AD75-54DF4EB41AF6"}
2024-02-26 10:41:47:189 [Mac2Driver@cac0 (20f48bdb)] Responding to client with driver.execute() result: null
2024-02-26 10:41:47:189 [HTTP] <-- POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/execute/sync 200 375 ms - 14
2024-02-26 10:41:47:189 [HTTP] 
2024-02-26 10:41:47:191 [HTTP] --> POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/execute/sync
2024-02-26 10:41:47:191 [HTTP] {"script":"macos: activateApp","args":[{"path":"/Volumes/jenkins/workspace/PRNum/builds/scripts/ui_automation_test/ui_automation_test_pkgs/1.11.10.110/ubx64arm64/Release/TestHarness/TestApp.app"}]}
2024-02-26 10:41:47:192 [Mac2Driver@cac0 (20f48bdb)] Calling AppiumDriver.execute() with args: ["macos: activateApp",[{"path":"/Volumes/jenkins/workspace/PRNum/builds/scripts/ui_automation_test/ui_automation_test_pkgs/1.11.10.110/ubx64arm64/Release/TestHarness/TestApp.app"}],"20f48bdb-1d76-4637-acf9-cce7dd9b832e"]
2024-02-26 10:41:47:192 [Mac2Driver] Executing extension command 'macos: activateApp'
2024-02-26 10:41:47:193 [WD Proxy] Proxying [POST /wda/apps/activate] to [POST http://127.0.0.1:10101/session/BEE743B2-0B98-40B1-AD75-54DF4EB41AF6/wda/apps/activate] with body: {"path":"/Volumes/jenkins/workspace/PRNum/builds/scripts/ui_automation_test/ui_automation_test_pkgs/1.11.10.110/ubx64arm64/Release/TestHarness/TestApp.app"}
2024-02-26 10:41:47:195 [WebDriverAgentMac] [xcodebuild] t =    17.29s Open com.company.TestApp
2024-02-26 10:41:47:196 [WebDriverAgentMac] [xcodebuild] t =    17.29s     Activate com.company.TestApp
2024-02-26 10:41:47:199 [WebDriverAgentMac] [xcodebuild] t =    17.29s         Wait for com.company.TestApp to idle
2024-02-26 10:41:47:200 [WD Proxy] Got response with status 200: {"value":null,"sessionId":"BEE743B2-0B98-40B1-AD75-54DF4EB41AF6"}
2024-02-26 10:41:47:201 [Mac2Driver@cac0 (20f48bdb)] Responding to client with driver.execute() result: null
2024-02-26 10:41:47:201 [HTTP] <-- POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/execute/sync 200 11 ms - 14
2024-02-26 10:41:47:201 [HTTP] 
2024-02-26 10:41:47:202 [HTTP] --> POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element
2024-02-26 10:41:47:203 [HTTP] {"using":"xpath","value":"//XCUIElementTypeButton[@elementType=\"9\" and @identifier=\"_NS:291\"]"}
2024-02-26 10:41:47:203 [Mac2Driver@cac0 (20f48bdb)] Calling AppiumDriver.findElement() with args: ["xpath","//XCUIElementTypeButton[@elementType=\"9\" and @identifier=\"_NS:291\"]","20f48bdb-1d76-4637-acf9-cce7dd9b832e"]
2024-02-26 10:41:47:203 [Mac2Driver@cac0 (20f48bdb)] Valid locator strategies for this request: id, name, accessibility id, xpath, class name, -ios predicate string, predicate string, -ios class chain, class chain
2024-02-26 10:41:47:204 [WD Proxy] Matched '/element' to command name 'findElement'
2024-02-26 10:41:47:204 [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:10101/session/BEE743B2-0B98-40B1-AD75-54DF4EB41AF6/element] with body: {"using":"xpath","value":"//XCUIElementTypeButton[@elementType=\"9\" and @identifier=\"_NS:291\"]"}
2024-02-26 10:41:47:205 [WebDriverAgentMac] [xcodebuild] t =    17.30s Find the Application 'com.company.TestApp'
2024-02-26 10:41:47:562 [WD Proxy] Got response with status 404: {"value":{"error":"no such element","message":"unable to find an element using 'xpath', value '//XCUIElementTypeButton[@elementType=\"9\" and @identifier=\"_NS:291\"]'","traceback":"(\n\t0   WebDriverAgentLib                   0x000000010bb38a92 FBNoSuchElementErrorResponseForRequest + 290\n\t1   WebDriverAgentLib                   0x000000010bb3881a +[FBFindElementCommands handleFindElement:] + 426\n\t2   WebDriverAgentLib                   0x000000010bb7f21c -[FBRoute_TargetAction mountRequest:intoResponse:] + 172\n\t3   WebDriverAgentLib                   0x000000010bb780c8 __37-[FBWebServer registerRouteHandlers:]_block_invoke + 776\n\t4   WebDriverAgentLib                   0x000000010bb717bd -[RoutingHTTPServer handleRoute:withRequest:response:] + 189\n\t5   WebDriverAgentLib                   0x000000010bb72501 __72-[RoutingHTTPServer routeMethod:withPath:parameters:request:connection:]_block_invoke + 65\n\t6   libdispatch.dylib                   0x00007ff814ce5a44 _dispatch_client_callout + 8\n\t7 ...
2024-02-26 10:41:47:563 [W3C] Matched W3C error code 'no such element' to NoSuchElementError
2024-02-26 10:41:47:563 [Mac2Driver@cac0 (20f48bdb)] Encountered internal error running command: NoSuchElementError: unable to find an element using 'xpath', value '//XCUIElementTypeButton[@elementType="9" and @identifier="_NS:291"]'
2024-02-26 10:41:47:563 [Mac2Driver@cac0 (20f48bdb)]     at errorFromW3CJsonCode (/Volumes/jenkins/jenkins_agent_config/tools/jenkins.plugins.nodejs.tools.NodeJSInstallation/node/lib/node_modules/appium/node_modules/@appium/base-driver/lib/protocol/errors.js:1085:25)
2024-02-26 10:41:47:563 [Mac2Driver@cac0 (20f48bdb)]     at ProxyRequestError.getActualError (/Volumes/jenkins/jenkins_agent_config/tools/jenkins.plugins.nodejs.tools.NodeJSInstallation/node/lib/node_modules/appium/node_modules/@appium/base-driver/lib/protocol/errors.js:954:14)
2024-02-26 10:41:47:563 [Mac2Driver@cac0 (20f48bdb)]     at WDAMacProxy.command (/Volumes/jenkins/jenkins_agent_config/tools/jenkins.plugins.nodejs.tools.NodeJSInstallation/node/lib/node_modules/appium/node_modules/@appium/base-driver/lib/jsonwp-proxy/proxy.js:353:19)
2024-02-26 10:41:47:563 [Mac2Driver@cac0 (20f48bdb)]     at processTicksAndRejections (node:internal/process/task_queues:95:5)
2024-02-26 10:41:47:563 [Mac2Driver@cac0 (20f48bdb)]     at Mac2Driver.findElOrEls (/Users/TestApp/.appium/node_modules/appium-mac2-driver/lib/commands/find.js:17:10)
2024-02-26 10:41:47:564 [Mac2Driver@cac0 (20f48bdb)]     at Mac2Driver.findElOrElsWithProcessing (/Volumes/jenkins/jenkins_agent_config/tools/jenkins.plugins.nodejs.tools.NodeJSInstallation/node/lib/node_modules/appium/node_modules/@appium/base-driver/lib/basedriver/commands/find.ts:60:12)
2024-02-26 10:41:47:564 [Mac2Driver@cac0 (20f48bdb)]     at Mac2Driver.findElement (/Volumes/jenkins/jenkins_agent_config/tools/jenkins.plugins.nodejs.tools.NodeJSInstallation/node/lib/node_modules/appium/node_modules/@appium/base-driver/lib/basedriver/commands/find.ts:75:12)
2024-02-26 10:41:47:564 [HTTP] <-- POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element 404 361 ms - 1638
2024-02-26 10:41:47:564 [HTTP] 
2024-02-26 10:41:47:666 [HTTP] --> POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element
2024-02-26 10:41:47:666 [HTTP] {"using":"xpath","value":"//XCUIElementTypeButton[@elementType=\"9\" and @identifier=\"_NS:291\"]"}
2024-02-26 10:41:47:666 [Mac2Driver@cac0 (20f48bdb)] Calling AppiumDriver.findElement() with args: ["xpath","//XCUIElementTypeButton[@elementType=\"9\" and @identifier=\"_NS:291\"]","20f48bdb-1d76-4637-acf9-cce7dd9b832e"]
2024-02-26 10:41:47:666 [Mac2Driver@cac0 (20f48bdb)] Valid locator strategies for this request: id, name, accessibility id, xpath, class name, -ios predicate string, predicate string, -ios class chain, class chain
2024-02-26 10:41:47:667 [WD Proxy] Matched '/element' to command name 'findElement'
2024-02-26 10:41:47:667 [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:10101/session/BEE743B2-0B98-40B1-AD75-54DF4EB41AF6/element] with body: {"using":"xpath","value":"//XCUIElementTypeButton[@elementType=\"9\" and @identifier=\"_NS:291\"]"}
2024-02-26 10:41:47:669 [WebDriverAgentMac] [xcodebuild] t =    17.76s Find the Application 'com.company.TestApp'
2024-02-26 10:41:47:837 [WD Proxy] Got response with status 404: {"value":{"error":"no such element","message":"unable to find an element using 'xpath', value '//XCUIElementTypeButton[@elementType=\"9\" and @identifier=\"_NS:291\"]'","traceback":"(\n\t0   WebDriverAgentLib                   0x000000010bb38a92 FBNoSuchElementErrorResponseForRequest + 290\n\t1   WebDriverAgentLib                   0x000000010bb3881a +[FBFindElementCommands handleFindElement:] + 426\n\t2   WebDriverAgentLib                   0x000000010bb7f21c -[FBRoute_TargetAction mountRequest:intoResponse:] + 172\n\t3   WebDriverAgentLib                   0x000000010bb780c8 __37-[FBWebServer registerRouteHandlers:]_block_invoke + 776\n\t4   WebDriverAgentLib                   0x000000010bb717bd -[RoutingHTTPServer handleRoute:withRequest:response:] + 189\n\t5   WebDriverAgentLib                   0x000000010bb72501 __72-[RoutingHTTPServer routeMethod:withPath:parameters:request:connection:]_block_invoke + 65\n\t6   libdispatch.dylib                   0x00007ff814ce5a44 _dispatch_client_callout + 8\n\t7 ...
2024-02-26 10:41:47:837 [W3C] Matched W3C error code 'no such element' to NoSuchElementError
2024-02-26 10:41:47:837 [Mac2Driver@cac0 (20f48bdb)] Encountered internal error running command: NoSuchElementError: unable to find an element using 'xpath', value '//XCUIElementTypeButton[@elementType="9" and @identifier="_NS:291"]'
2024-02-26 10:41:47:838 [Mac2Driver@cac0 (20f48bdb)]     at errorFromW3CJsonCode (/Volumes/jenkins/jenkins_agent_config/tools/jenkins.plugins.nodejs.tools.NodeJSInstallation/node/lib/node_modules/appium/node_modules/@appium/base-driver/lib/protocol/errors.js:1085:25)
2024-02-26 10:41:47:838 [Mac2Driver@cac0 (20f48bdb)]     at ProxyRequestError.getActualError (/Volumes/jenkins/jenkins_agent_config/tools/jenkins.plugins.nodejs.tools.NodeJSInstallation/node/lib/node_modules/appium/node_modules/@appium/base-driver/lib/protocol/errors.js:954:14)
2024-02-26 10:41:47:838 [Mac2Driver@cac0 (20f48bdb)]     at WDAMacProxy.command (/Volumes/jenkins/jenkins_agent_config/tools/jenkins.plugins.nodejs.tools.NodeJSInstallation/node/lib/node_modules/appium/node_modules/@appium/base-driver/lib/jsonwp-proxy/proxy.js:353:19)
2024-02-26 10:41:47:838 [Mac2Driver@cac0 (20f48bdb)]     at processTicksAndRejections (node:internal/process/task_queues:95:5)
2024-02-26 10:41:47:838 [Mac2Driver@cac0 (20f48bdb)]     at Mac2Driver.findElOrEls (/Users/TestApp/.appium/node_modules/appium-mac2-driver/lib/commands/find.js:17:10)
2024-02-26 10:41:47:838 [Mac2Driver@cac0 (20f48bdb)]     at Mac2Driver.findElOrElsWithProcessing (/Volumes/jenkins/jenkins_agent_config/tools/jenkins.plugins.nodejs.tools.NodeJSInstallation/node/lib/node_modules/appium/node_modules/@appium/base-driver/lib/basedriver/commands/find.ts:60:12)
2024-02-26 10:41:47:838 [Mac2Driver@cac0 (20f48bdb)]     at Mac2Driver.findElement (/Volumes/jenkins/jenkins_agent_config/tools/jenkins.plugins.nodejs.tools.NodeJSInstallation/node/lib/node_modules/appium/node_modules/@appium/base-driver/lib/basedriver/commands/find.ts:75:12)
2024-02-26 10:41:47:838 [HTTP] <-- POST /session/20f48bdb-1d76-4637-acf9-cce7dd9b832e/element 404 172 ms - 1638
2024-02-26 10:41:47:838 [HTTP] 
MagdelineNg commented 4 months ago

I realised that the Identifier attribute used in Xpath for the element has changed when I print the page source of the app in the Jenkins VM environment. Is the XC Identifier attribute not unique and changes across different machines?

I tested xpath with a title attribute for the element which does not change across environments, but am still the driver is not able to find the element even though the xpath of the element is valid and found in driver.page_source

I can see this printed in the logs on the VM: -------------------------------- live log call --------------------------------- WARNING urllib3.connectionpool:connectionpool.py:874 Retrying (Retry(total=2, connect=None, read=None, redirect=None, status=None)) after connection broken by 'NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7fc6d1521160>: Failed to establish a new connection: [Errno 61] Connection refused')': /session/1f324abc509025d06118a66eeded1c6f WARNING urllib3.connectionpool:connectionpool.py:874 Retrying (Retry(total=1, connect=None, read=None, redirect=None, status=None)) after connection broken by 'NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7fc6d1521490>: Failed to establish a new connection: [Errno 61] Connection refused')': /session/1f324abc509025d06118a66eeded1c6f WARNING urllib3.connectionpool:connectionpool.py:874 Retrying (Retry(total=0, connect=None, read=None, redirect=None, status=None)) after connection broken by 'NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7fc6d1521e80>: Failed to establish a new connection: [Errno 61] Connection refused')': /session/1f324abc509025d06118a66eeded1c6f

MagdelineNg commented 4 months ago

Hi, after more debugging by remote desktop into the Jenkins VM, I realised the Appium logs is getting stuck at this line:

[WebDriverAgentMac] [xcodebuild] t = 414.4s Find the Application 'com.company.TestApp

I logged errors from my python script, and received this:

Stacktrace:

UnknownError: An unknown server-side error occurred while processing the command. Original error: Failed to determine bundle identifier for '/Volumes/jenkins/workspace/CPIDSDK-4800/builds/scripts/ui_automation_test_pkgs/IDSDK/1.11.10.111/ubx64arm64/Release/TestHarness/TestApp.app'. The application may be damaged or incomplete.

    at errorFromW3CJsonCode (/usr/local/lib/node_modules/appium/node_modules/@appium/base-driver/lib/protocol/errors.js:1085:25)

    at ProxyRequestError.getActualError (/usr/local/lib/node_modules/appium/node_modules/@appium/base-driver/lib/protocol/errors.js:954:14)

    at WDAMacProxy.command (/usr/local/lib/node_modules/appium/node_modules/@appium/base-driver/lib/jsonwp-proxy/proxy.js:353:19)

    at processTicksAndRejections (node:internal/process/task_queues:95:5)

    at Mac2Driver.macosActivateApp (/Users/IDSDK/.appium/node_modules/appium-mac2-driver/lib/commands/app-management.js:49:10)

    at Mac2Driver.executeMacosCommand (/Users/IDSDK/.appium/node_modules/appium-mac2-driver/lib/commands/execute.js:54:10)

    at Mac2Driver.execute (/Users/IDSDK/.appium/node_modules/appium-mac2-driver/lib/commands/execute.js:44:12)

Any idea why the application is identified as damaged or incomplete, even though Mac2 driver is able to launch it?

KazuCocoa commented 4 months ago

Maybe the system log has more info. The error might came from the XCTest framework's activate API call https://github.com/appium/appium-mac2-driver/blob/master/lib/commands/app-management.js#L49 https://github.com/appium/appium-mac2-driver/blob/e935c90e1e8918295cd3afbeb01e24e756e2fe38/WebDriverAgentMac/WebDriverAgentLib/Routing/FBSession.m#L112 https://developer.apple.com/documentation/xctest/xcuiapplication/2873317-activate