appium / appium-xcuitest-driver

Appium iOS driver, backed by Apple XCTest
https://appium.github.io/appium-xcuitest-driver/
Apache License 2.0
749 stars 419 forks source link

[XCUITest] Unable to launch WebDriverAgent because of xcodebuild failure: Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed? #1260

Closed bitcrumb closed 3 years ago

bitcrumb commented 3 years ago

Hi,

No matter what I try. I can't seem to get Appium to launch my app. It already fails at detecting xcodebuild so it seems:

Both in zsh & bash terminal I am able to locate the xcodebuild binary. I have Xcode & the commandline tools properly installed.

 ❯  ~  which xcodebuild
/usr/bin/xcodebuild
 ❯  ~  bash
bash-5.1$ which xcodebuild
/usr/bin/xcodebuild
bash-5.1$

This is the set of desired capabilities:

{
  "deviceName": "iPhone 11",
  "platformName": "iOS",
  "platformVersion": "14.3",
  "bundleId": "my.beautiful.app",
  "automationName": "XCUITest",
  "agentPath": "/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj",
  "bootstrapPath": "/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent",
  "showXcodeLog": true,
  "showIOSLog": true
}

Here's the full output from Appium Desktop. Anyone knows what might be happening?

[info] [Appium] Welcome to Appium v1.19.1
[info] [Appium] Non-default server args:
[info] [Appium]   relaxedSecurityEnabled: true
[info] [Appium]   allowInsecure: {
[info] [Appium]   }
[info] [Appium]   denyInsecure: {
[info] [Appium]   }
[info] [Appium] Appium REST http interface listener started on 0.0.0.0:4723[info] [HTTP] --> POST /wd/hub/session
[info] [HTTP] {"desiredCapabilities":{"agentPath":"/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj","automationName":"XCUITest","bootstrapPath":"/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragentWebDriverAgent","bundleId":"my.beautiful.app","deviceName":"iPhone 11","platformName":"iOS","platformVersion":"14.3","showIOSLog":true,"showXcodeLog":true,"newCommandTimeout":0,"connectHardwareKeyboard":true}}
[debug] [MJSONWP] Calling AppiumDriver.createSession() with args: [{"agentPath":"/Applications/Appium.app/Contents/Resources/app/node_modules/amoppium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj","automationName":"XCUITest","bootstrapPath":"/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragentWebDriverAgent","bundleId":"my.beautiful.app","deviceName":"iPhone 11","platformName":"iOS","platformVersion":"14.3","showIOSLog":true,"showXcodeLog":true,"newCommandTimeout":0,"connectHardwareKeyboard":true},null,null]
[debug] [BaseDriver] Event 'newSessionRequested' logged at 1608274501192 (07:55:01 GMT+0100 (Central European Standard Time))
[info] [Appium] Appium v1.19.1 creating new XCUITestDriver (v3.31.1) session
[info] [Appium] Applying relaxed security to 'XCUITestDriver' as per server command line argument. All insecure features will be enabled unless explicitly disabled by --deny-insecure
[debug] [BaseDriver] Creating session with MJSONWP desired capabilities: {
[debug] [BaseDriver]   "agentPath": "/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj",
[debug] [BaseDriver]   "automationName": "XCUITest",
[debug] [BaseDriver]   "bootstrapPath": "/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragentWebDriverAgent",
[debug] [BaseDriver]   "bundleId": "my.beautiful.app",
[debug] [BaseDriver]   "deviceName": "iPhone 11",
[debug] [BaseDriver]   "platformName": "iOS",
[debug] [BaseDriver]   "platformVersion": "14.3",
[debug] [BaseDriver]   "showIOSLog": true,
[debug] [BaseDriver]   "showXcodeLog": true,
[debug] [BaseDriver]   "newCommandTimeout": 0,
[debug] [BaseDriver]   "connectHardwareKeyboard": true
[debug] [BaseDriver] }
[info] [BaseDriver] Session created with session id: 308fec8b-360b-472b-ac9e-bb1a9afce04c[debug] [XCUITest] Current user: 'lode'
[info] [XCUITest] iOS SDK Version set to '14.3'[info] [iOSSim] Constructing iOS simulator for Xcode version 12.3 with udid '653AF053-A8C2-4207-9296-61B47A96588E'
[info] [XCUITest] Determining device to run tests on: udid: '653AF053-A8C2-4207-9296-61B47A96588E', real device: false
[debug] [BaseDriver] Event 'xcodeDetailsRetrieved' logged at 1608274502652 (07:55:02 GMT+0100 (Central European Standard Time))
[debug] [BaseDriver] Event 'appConfigured' logged at 1608274502652 (07:55:02 GMT+0100 (Central European Standard Time))
[debug] [BaseDriver] Event 'resetStarted' logged at 1608274502652 (07:55:02 GMT+0100 (Central European Standard Time))[debug] [iOSSim] Cleaning app data files for '', 'my.beautiful.app'
[debug] [iOSSim] Checking whether simulator has been run before: yes
[debug] [iOSSim] Building bundle path map[debug] [iOSSim] Could not find app directories to delete. It is probably not installed
[debug] [BaseDriver] Event 'resetComplete' logged at 1608274503320 (07:55:03 GMT+0100 (Central European Standard Time))
[info] [WebDriverAgent] Using WDA path: '/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragentWebDriverAgent'
[info] [WebDriverAgent] Using WDA agent: '/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj'
[debug] [IOSSimulatorLog] Starting log capture for iOS Simulator with udid '653AF053-A8C2-4207-9296-61B47A96588E' using simctl[debug] [BaseDriver] Event 'logCaptureStarted' logged at 1608274504418 (07:55:04 GMT+0100 (Central European Standard Time))
[info] [XCUITest] Setting up simulator
[debug] [iOS] No reason to set locale
[debug] [iOS] No iOS / app preferences to set
[debug] [iOS] Setting did not need to be updated
[debug] [iOSSim] Setting preferences of 653AF053-A8C2-4207-9296-61B47A96588E Simulator to {"ConnectHardwareKeyboard":true}
[debug] [iOSSim] Setting common Simulator preferences to {"RotateWindowWhenSignaledByGuest":true,"ConnectHardwareKeyboard":true}
[debug] [iOSSim] Updated 653AF053-A8C2-4207-9296-61B47A96588E Simulator preferences at '/Users/lode/Library/Preferences/com.apple.iphonesimulator.plist' with {"DevicePreferences":{"653AF053-A8C2-4207-9296-61B47A96588E":{"ConnectHardwareKeyboard":true}},"RotateWindowWhenSignaledByGuest":true,"ConnectHardwareKeyboard":true}[debug] [iOSSim] Got Simulator UI client PID: 6856
[info] [iOSSim] Both Simulator with UDID '653AF053-A8C2-4207-9296-61B47A96588E' and the UI client are currently running
[debug] [BaseDriver] Event 'simStarted' logged at 1608274504699 (07:55:04 GMT+0100 (Central European Standard Time))[debug] [WebDriverAgent] No obsolete cached processes from previous WDA sessions listening on port 8100 have been found
[info] [DevCon Factory] Requesting connection for device 653AF053-A8C2-4207-9296-61B47A96588E on local port 8100
[debug] [DevCon Factory] Cached connections count: 0
[info] [DevCon Factory] Successfully requested the connection for 653AF053-A8C2-4207-9296-61B47A96588E:8100
[debug] [XCUITest] Starting WebDriverAgent initialization with the synchronization key 'XCUITestDriver'
[debug] [WD Proxy] Matched '/status' to command name 'getStatus'
[debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8100/status] with no body
[info] [WD Proxy] connect ECONNREFUSED 127.0.0.1:8100
[debug] [WebDriverAgent] WDA is not listening at 'http://127.0.0.1:8100/'
[debug] [WebDriverAgent] WDA is currently not running. There is nothing to cache
[debug] [XCUITest] Trying to start WebDriverAgent 2 times with 10000ms interval
[debug] [XCUITest] These values can be customized by changing wdaStartupRetries/wdaStartupRetryInterval capabilities
[debug] [BaseDriver] Event 'wdaStartAttempted' logged at 1608274504992 (07:55:04 GMT+0100 (Central European Standard Time))
[info] [WebDriverAgent] Launching WebDriverAgent on the device
[info] [WebDriverAgent] Fetching dependencies
[info] [WebDriverAgent] Dependencies up-to-date
[debug] [WebDriverAgent] Killing running processes 'xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E, 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner, xctest.*653AF053-A8C2-4207-9296-61B47A96588E' for the device 653AF053-A8C2-4207-9296-61B47A96588E...
[debug] [WebDriverAgent] 'pgrep -if xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if xctest.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] Beginning test with command 'xcodebuild build-for-testing test-without-building -project /Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -destination id=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET=14.3 GCC_TREAT_WARNINGS_AS_ERRORS=0 COMPILER_INDEX_STORE_ENABLE=NO' in directory '/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragentWebDriverAgent'
[debug] [WebDriverAgent] Output from xcodebuild will be logged. To change this, use 'showXcodeLog' desired capability
[error] [WebDriverAgent] Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed?[info] [WebDriverAgent] Dependencies up-to-date
[debug] [WebDriverAgent] Killing running processes 'xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E, 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner, xctest.*653AF053-A8C2-4207-9296-61B47A96588E' for the device 653AF053-A8C2-4207-9296-61B47A96588E...
[debug] [WebDriverAgent] 'pgrep -if xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if xctest.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] Beginning test with command 'xcodebuild build-for-testing test-without-building -project /Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -destination id=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET=14.3 GCC_TREAT_WARNINGS_AS_ERRORS=0 COMPILER_INDEX_STORE_ENABLE=NO' in directory '/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragentWebDriverAgent'
[debug] [WebDriverAgent] Output from xcodebuild will be logged. To change this, use 'showXcodeLog' desired capability
[error] [WebDriverAgent] Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed?
[debug] [BaseDriver] Event 'wdaStartFailed' logged at 1608274505184 (07:55:05 GMT+0100 (Central European Standard Time))
[debug] [XCUITest] Unable to launch WebDriverAgent because of xcodebuild failure: Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed?
[warn] [XCUITest] Quitting and uninstalling WebDriverAgent
[info] [WebDriverAgent] Shutting down sub-processes
[info] [WebDriverAgent] Shutting down 'xcodebuild' process (pid 'undefined')
[info] [WebDriverAgent] Sending 'SIGTERM'...[debug] [WebDriverAgent] xcodebuild process did not end in a timely fashion: 'Process didn't end after 1000ms (cmd: 'xcodebuild build-for-testing test-without-building -project /Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -destination id\=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET\=14.3 GCC_TREAT_WARNINGS_AS_ERRORS\=0 COMPILER_INDEX_STORE_ENABLE\=NO')'.
[info] [WebDriverAgent] Sending 'SIGKILL'...[debug] [WebDriverAgent] Parsed BUILD_DIR configuration value: '/Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-alwvnomvwrdtzoaxbbkniqrpcdpp/Build/Products'
[debug] [WebDriverAgent] Got derived data root: '/Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-alwvnomvwrdtzoaxbbkniqrpcdpp'[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.825 Df fontservicesd[36773:f528d] [com.apple.xpc.activity:Client] _xpc_activity_dispatch: beginning dispatch, activity name com.apple.fontservicesd.subscription-support, seqno 0
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.825 Df fontservicesd[36773:f528d] [com.apple.xpc.activity:Client] _xpc_activity_dispatch: com.apple.fontservicesd.subscription-support (0x7f895df05450): found an activity with matching seqno 0
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.826 Df fontservicesd[36773:f528d] [com.apple.xpc.activity:Client] _xpc_activity_dispatch: lower half, activity name com.apple.fontservicesd.subscription-support (0x7f895df05450), seqno from top half was 0
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.826 Df fontservicesd[36773:f528d] [com.apple.xpc.activity:Client] _xpc_activity_set_state: com.apple.fontservicesd.subscription-support (0x7f895df05450), 2
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.826 Df fontservicesd[36773:f528d] [com.apple.xpc.activity:Client] _xpc_activity_set_state: send new state to CTS: com.apple.fontservicesd.subscription-support (0x7f895df05450), 2
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.827 Df UserEventAgent[36726:f546a] [com.apple.xpc.activity:Activities] Running XPC Activity (PID 36773): com.apple.fontservicesd.subscription-support (0x7fccb340b850)
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.828 Df fontservicesd[36773:f528d] [com.apple.xpc.activity:Client] _xpc_activity_set_state_from_cts: com.apple.fontservicesd.subscription-support (0x7f895df05450), set activity state to 2
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.828 Df fontservicesd[36773:f528d] [com.apple.xpc.activity:Client] __XPC_ACTIVITY_CALLING_HANDLER__: com.apple.fontservicesd.subscription-support (0x7f895df05450), current state 2, pending state 0
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.828 Df fontservicesd[36773:f528d] [com.apple.xpc.activity:Client] __XPC_ACTIVITY_CALLING_HANDLER__ returned from handler: com.apple.fontservicesd.subscription-support (0x7f895df05450), current state 2, pending state 0
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.828 Df fontservicesd[36773:f528d] [com.apple.xpc.activity:Client] _xpc_activity_set_state: com.apple.fontservicesd.subscription-support (0x7f895df05450), 5
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.829 Df fontservicesd[36773:f528d] [com.apple.xpc.activity:Client] _xpc_activity_set_state: send new state to CTS: com.apple.fontservicesd.subscription-support (0x7f895df05450), 5
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.829 Df UserEventAgent[36726:f546a] [com.apple.xpc.activity:Activities] Completed XPC Activity: com.apple.fontservicesd.subscription-support (0x7fccb340b850)
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.832 Df UserEventAgent[36726:f546a] [com.apple.xpc.activity:Activities] Rescheduling XPC Activity: com.apple.fontservicesd.subscription-support (0x7fccb340b850)
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.833 Df fontservicesd[36773:f528d] [com.apple.xpc.activity:Client] _xpc_activity_set_state_from_cts: com.apple.fontservicesd.subscription-support (0x7f895df05450), set activity state to 1
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.876 Df mobileassetd[36797:f5282] [com.apple.mobileassetd:Notice] -[ControlManager handleClientConnection:on:]_block_invoke: assetType: com.apple.MobileAsset.Font6 client: fontservicesd, command: 1 (MA_QUERY_ASSET_TYPE)
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.876 Df mobileassetd[36797:f5282] [com.apple.mobileassetd:Notice] -[ControlManager handleClientConnection:on:]_block_invoke: fontservicesd issued query command for com.apple.MobileAsset.Font6
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.877 Df mobileassetd[36797:f5282] [com.apple.mobileassetd:Notice] -[ControlManager handleQueryRequest:clientName:connection:message:]: fontservicesd queried for: com.apple.MobileAsset.Font6 with returnType of: 1 (MAInstalledOnly) - may block on network sync
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.877 Df mobileassetd[36797:f5282] [com.apple.mobileassetd:Notice] -[ControlManager determineAssets:clientName:connection:downloadingTasks:message:resultTypes:queryArray:isForSpecificAsset:specificAssetId:specificAllowedDifferences:]: fontservicesd queried for: com.apple.MobileAsset.Font6 with returnType of: 1
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.878 Df mobileassetd[36797:f5282] [com.apple.mobileassetd:Notice] -[ControlManager determineAssets:clientName:connection:downloadingTasks:message:resultTypes:queryArray:isForSpecificAsset:specificAssetId:specificAllowedDifferences:]: fontservicesd unable to load repository for: com.apple.MobileAsset.Font6
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.878 Df mobileassetd[36797:f5282] [com.apple.mobileassetd:Notice] -[ControlManager loadCatalog:catalogAssets:assetIds:postedDate:lastFetchDate:catalogInfo:]: Could not load catalog for com.apple.MobileAsset.Font6
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.878 Df mobileassetd[36797:f5282] [com.apple.mobileassetd:Notice] -[ControlManager determineAssets:clientName:connection:downloadingTasks:message:resultTypes:queryArray:isForSpecificAsset:specificAssetId:specificAllowedDifferences:]: fontservicesd unable to load catalog for: com.apple.MobileAsset.Font6
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.878 Df mobileassetd[36797:f5282] [com.apple.mobileassetd:Notice] dataFillInstalled: preqs are nil for dataFilling
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.878 Df mobileassetd[36797:f5282] [com.apple.mobileassetd:Notice] dataFillInstalled: preqs are nil for dataFilling
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.879 Df fontservicesd[36773:f5484] [com.apple.mobileassetd:Notice] -[MAAssetQuery getResultsFromMessage:]: Got the query meta data reply for: com.apple.MobileAsset.Font6, response: 2
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:15.879 Df mobileassetd[36797:f5282] [com.apple.mobileassetd:Notice] -[ControlManager determineAssets:clientName:connection:downloadingTasks:message:resultTypes:queryArray:isForSpecificAsset:specificAssetId:specificAllowedDifferences:]: fontservicesd queried for: com.apple.MobileAsset.Font6 with returnTypes 1 (MAInstalledOnly) and found 0 assets with result 2 (MAQueryCatalogNotDownloaded) --> From 0 listed in the catalog and 0 local (0/0 downloaded, 0 preinstalled)--> Catalog info ((null)) --> Filtered for MAInstalledOnly to 0 in catalog (0 installed, 0 server-only, 0 preinstalled), 0 installedNotInCatalog, 0 installedWithOS, 0 requiredByOS; --> Merged to 0 assets[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:16.026 Df useractivityd[36868:f525a] [com.apple.useractivity:main] SIMULATOR: Received message from another simulator on port 8963, so dispatching.
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:16.029 Df useractivityd[36868:f525a] [com.apple.useractivity:main] SIMULATOR: Item 7A9299E8-6309-4762-9D5C-50D24B88A63D seems to be different from (null), so changing received item & updating lists.
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:16.029 Df useractivityd[36868:f525a] [com.apple.useractivity:main] SIMULATOR: Unable to find application to handle typeIdentifier :com.apple.TextEdit.editing for item 7A9299E8-6309-4762-9D5C-50D24B88A63D[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:23.580 Df useractivityd[36868:f525a] [com.apple.useractivity:main] SIMULATOR: Received message from another simulator on port 8963, so dispatching.
[info] [IOSSimulatorLog] [IOS_SYSLOG_ROW] 2020-12-18 07:55:23.581 Df useractivityd[36868:f552a] [com.apple.useractivity:main] SIMULATOR: Clearing current item, because it has been removed ( was 7A9299E8-6309-4762-9D5C-50D24B88A63D/UAUserActivityInfo:{ type = UserActivity; uuid = 7A9299E8-6309-4762-9D5C-50D24B88A63D; activityType = "com.apple.TextEdit.editing"; dynamicActivityType = "(null)"; teamID=; - userInfo = $4d50030581b94e53557365724163746976697479446f63756d656e7455524cc7.. 176 ..3536613234643039653935376235343935613734643536333433336138623432 -  -   opts=(null); when = 2020-12-18 06:55:16 +0000 } { type = UserActivity; uuid = 7A9299E8-6309-4762-9D5C-50D24B88A63D;  activityType = "com.apple.TextEdit.editing"; userInfo = $4d50030581b94e535573657241637469.. 176 ..35613734643536333433336138623432;   eligible=NO}).[debug] [BaseDriver] Event 'wdaStartAttempted' logged at 1608274526197 (07:55:26 GMT+0100 (Central European Standard Time))
[info] [XCUITest] Retrying WDA startup (2 of 2)
[info] [WebDriverAgent] Launching WebDriverAgent on the device
[info] [WebDriverAgent] Fetching dependencies
[info] [WebDriverAgent] Dependencies up-to-date
[debug] [WebDriverAgent] Killing running processes 'xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E, 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner, xctest.*653AF053-A8C2-4207-9296-61B47A96588E' for the device 653AF053-A8C2-4207-9296-61B47A96588E...
[debug] [WebDriverAgent] 'pgrep -if xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if xctest.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] Beginning test with command 'xcodebuild build-for-testing test-without-building -project /Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -derivedDataPath /Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-alwvnomvwrdtzoaxbbkniqrpcdpp -destination id=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET=14.3 GCC_TREAT_WARNINGS_AS_ERRORS=0 COMPILER_INDEX_STORE_ENABLE=NO' in directory '/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragentWebDriverAgent'
[debug] [WebDriverAgent] Output from xcodebuild will be logged. To change this, use 'showXcodeLog' desired capability
[error] [WebDriverAgent] Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed?
[info] [WebDriverAgent] Launching WebDriverAgent on the device
[info] [WebDriverAgent] Fetching dependencies
[info] [WebDriverAgent] Dependencies up-to-date
[debug] [WebDriverAgent] Killing running processes 'xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E, 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner, xctest.*653AF053-A8C2-4207-9296-61B47A96588E' for the device 653AF053-A8C2-4207-9296-61B47A96588E...[debug] [WebDriverAgent] 'pgrep -if xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if xctest.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] Beginning test with command 'xcodebuild build-for-testing test-without-building -project /Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -derivedDataPath /Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-alwvnomvwrdtzoaxbbkniqrpcdpp -destination id=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET=14.3 GCC_TREAT_WARNINGS_AS_ERRORS=0 COMPILER_INDEX_STORE_ENABLE=NO' in directory '/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragentWebDriverAgent'
[debug] [WebDriverAgent] Output from xcodebuild will be logged. To change this, use 'showXcodeLog' desired capability
[error] [WebDriverAgent] Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed?
[debug] [BaseDriver] Event 'wdaStartFailed' logged at 1608274526374 (07:55:26 GMT+0100 (Central European Standard Time))
[debug] [XCUITest] Unable to launch WebDriverAgent because of xcodebuild failure: Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed?
[warn] [XCUITest] Quitting and uninstalling WebDriverAgent
[info] [WebDriverAgent] Shutting down sub-processes
[info] [WebDriverAgent] Shutting down 'xcodebuild' process (pid 'undefined')
[info] [WebDriverAgent] Sending 'SIGTERM'...[debug] [WebDriverAgent] xcodebuild process did not end in a timely fashion: 'Process didn't end after 1000ms (cmd: 'xcodebuild build-for-testing test-without-building -project /Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -derivedDataPath /Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-alwvnomvwrdtzoaxbbkniqrpcdpp -destination id\=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET\=14.3 GCC_TREAT_WARNINGS_AS_ERRORS\=0 COMPILER_INDEX_STORE_ENABLE\=NO')'.
[info] [WebDriverAgent] Sending 'SIGKILL'...[error] [XCUITest] {}
[info] [DevCon Factory] Releasing connections for 653AF053-A8C2-4207-9296-61B47A96588E device on any port number
[info] [DevCon Factory] Found cached connections to release: ["653AF053-A8C2-4207-9296-61B47A96588E:8100"]
[debug] [DevCon Factory] Cached connections count: 0
[debug] [XCUITest] Not clearing log files. Use `clearSystemFiles` capability to turn on.
[debug] [IOSSimulatorLog] Stopping iOS log capture
[debug] [BaseDriver] Event 'newSessionStarted' logged at 1608274537432 (07:55:37 GMT+0100 (Central European Standard Time))
[debug] [MJSONWP] Encountered internal error running command: Error: Process didn't end after 10000ms (cmd: 'xcodebuild build-for-testing test-without-building -project /Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -derivedDataPath /Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-alwvnomvwrdtzoaxbbkniqrpcdpp -destination id\=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET\=14.3 GCC_TREAT_WARNINGS_AS_ERRORS\=0 COMPILER_INDEX_STORE_ENABLE\=NO')
[debug] [MJSONWP]     at Timeout._onTimeout (/Applications/Appium.app/Contents/Resources/app/node_modules/appium/node_modules/teen_process/lib/subprocess.js:231:16)
[debug] [MJSONWP]     at listOnTimeout (internal/timers.js:531:17)
[debug] [MJSONWP]     at processTimers (internal/timers.js:475:7)
[debug] [MJSONWP] Destroying socket connection
[info] [HTTP] <-- POST /wd/hub/session 500 36247 ms - 659
[info] [HTTP] 
mykola-mokhnach commented 3 years ago

https://github.com/appium/java-client/blob/master/docs/environment.md

bitcrumb commented 3 years ago

Thx for the fast reply!

I verified, the xcodebuild binary is in the PATH of the Appium process (as expected), see screenshot: Screenshot 2020-12-18 at 08 37 52

This is when launching Appium from the Dock.

bitcrumb commented 3 years ago

Also, I want to add that there is no difference in behavior when i start Appium from the command line like this: /Applications/Appium.app/Contents/MacOS/Appium

In that case the environment variables are indeed different (as expected), but the path to the xcodebuild binary is in the list: Screenshot 2020-12-18 at 08 45 02 I still get the same error though.

You'll see that I am using asdf for managing multiple runtime versions of tools like python, ruby, etc... But I want to stress that I already verified this had nothing to dot with it, by removing the node plugin from asdf & installing it via brew as per documentation. However, this was to no avail, since I got the same results.

bitcrumb commented 3 years ago

I might also add that I tried by installing both the latest stable and beta version. In both I observed the same behavior.

mykola-mokhnach commented 3 years ago

what is the output of xcode-select -p? Do you use DEVELOPER_DIR env variable?

bitcrumb commented 3 years ago

Shouldn't be anything out of the ordinary.

Screenshot 2020-12-18 at 08 53 17

bitcrumb commented 3 years ago

Can it have anything to do with some tooling I am missing?

I installed the following tools:

I didn't install any tools required for physical devices yet, since I wanted to test the setup against simulator first. Although I checked if installing idb and ios-deploy made a difference, it didn't.

I tried with capabilities (agentPath & bootstrapPath) that both pointed to the global npm appium node modules as well as pointing to the node_modules inside the appium desktop bundle, no difference.

I assume I don't need the global npm appium if I have appium desktop installed, so I also checked if removing the global appium npm package made a difference, it didn't.

I also created a node script:

const wd = require('wd');

let driver = wd.promiseChainRemote({
  host: '127.0.0.1',
  port: 4723,
});

let desiredCaps = {
  platformName: 'iOS',
  platformVersion: '14.2',
  deviceName: 'iPhone 11',
  bundleId: 'mobi.inthepocket.xxx.xxx.debug',
  automationName: 'XCUITest',
  agentPath:
    '/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj',
  bootstrapPath:
    '/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent',
  showXcodeLog: true,
  useNewWDA: true,
};

driver.init(desiredCaps);
console.log(driver);

If I run that script, the output is similar:

[Appium] Welcome to Appium v1.19.1
[Appium] Appium REST http interface listener started on 0.0.0.0:4723
[HTTP] --> POST /wd/hub/session
[HTTP] {"desiredCapabilities":{"deviceName":"iPhone 11","platformName":"iOS","platformVersion":"14.3","bundleId":"mobi.inthepocket.xxx.xxx.debug","automationName":"XCUITest","agentPath":"/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj","bootstrapPath":"/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent","showXcodeLog":true}}
[debug] [MJSONWP] Calling AppiumDriver.createSession() with args: [{"deviceName":"iPhone 11","platformName":"iOS","platformVersion":"14.3","bundleId":"mobi.inthepocket.xxx.xxx.debug","automationName":"XCUITest","agentPath":"/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj","bootstrapPath":"/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent","showXcodeLog":true},null,null]
[debug] [BaseDriver] Event 'newSessionRequested' logged at 1608278701465 (09:05:01 GMT+0100 (Central European Standard Time))
[Appium] Appium v1.19.1 creating new XCUITestDriver (v3.31.1) session
[debug] [BaseDriver] Creating session with MJSONWP desired capabilities: {
[debug] [BaseDriver]   "deviceName": "iPhone 11",
[debug] [BaseDriver]   "platformName": "iOS",
[debug] [BaseDriver]   "platformVersion": "14.3",
[debug] [BaseDriver]   "bundleId": "mobi.inthepocket.xxx.xxx.debug",
[debug] [BaseDriver]   "automationName": "XCUITest",
[debug] [BaseDriver]   "agentPath": "/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj",
[debug] [BaseDriver]   "bootstrapPath": "/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent",
[debug] [BaseDriver]   "showXcodeLog": true
[debug] [BaseDriver] }
[BaseDriver] Session created with session id: 05fbdc95-8fdf-4de6-a3a4-40e39ce0cfce
[debug] [XCUITest] Current user: 'lode'
[XCUITest] iOS SDK Version set to '14.3'
[iOSSim] Constructing iOS simulator for Xcode version 12.3 with udid '653AF053-A8C2-4207-9296-61B47A96588E'
[XCUITest] Determining device to run tests on: udid: '653AF053-A8C2-4207-9296-61B47A96588E', real device: false
[debug] [BaseDriver] Event 'xcodeDetailsRetrieved' logged at 1608278702437 (09:05:02 GMT+0100 (Central European Standard Time))
[debug] [BaseDriver] Event 'appConfigured' logged at 1608278702437 (09:05:02 GMT+0100 (Central European Standard Time))
[debug] [BaseDriver] Event 'resetStarted' logged at 1608278702438 (09:05:02 GMT+0100 (Central European Standard Time))
[debug] [iOSSim] Cleaning app data files for '', 'mobi.inthepocket.xxx.xxx.debug'
[debug] [iOSSim] Checking whether simulator has been run before: yes
[debug] [iOSSim] Building bundle path map
[debug] [Support] Plist file '/Users/lode/Library/Developer/CoreSimulator/Devices/653AF053-A8C2-4207-9296-61B47A96588E/data/Containers/Data/Application/7CDB6446-B248-4910-974C-B7C04DB00A50/.com.apple.mobile_container_manager.metadata.plist' does not exist. Returning an empty plist.
[debug] [iOSSim] Could not find app directories to delete. It is probably not installed
[debug] [BaseDriver] Event 'resetComplete' logged at 1608278703023 (09:05:03 GMT+0100 (Central European Standard Time))
[WebDriverAgent] Using WDA path: '/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent'
[WebDriverAgent] Using WDA agent: '/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj'
[debug] [IOSSimulatorLog] Starting log capture for iOS Simulator with udid '653AF053-A8C2-4207-9296-61B47A96588E' using simctl
[debug] [BaseDriver] Event 'logCaptureStarted' logged at 1608278703866 (09:05:03 GMT+0100 (Central European Standard Time))
[XCUITest] Setting up simulator
[debug] [iOS] No reason to set locale
[debug] [iOS] No iOS / app preferences to set
[debug] [iOS] Setting did not need to be updated
[debug] [iOSSim] Setting preferences of 653AF053-A8C2-4207-9296-61B47A96588E Simulator to {"ConnectHardwareKeyboard":false}
[debug] [iOSSim] Setting common Simulator preferences to {"RotateWindowWhenSignaledByGuest":true,"ConnectHardwareKeyboard":false}
[debug] [iOSSim] Updated 653AF053-A8C2-4207-9296-61B47A96588E Simulator preferences at '/Users/lode/Library/Preferences/com.apple.iphonesimulator.plist' with {"DevicePreferences":{"653AF053-A8C2-4207-9296-61B47A96588E":{"ConnectHardwareKeyboard":false}},"RotateWindowWhenSignaledByGuest":true,"ConnectHardwareKeyboard":false}
[debug] [iOSSim] Got Simulator UI client PID: 6856
[iOSSim] Both Simulator with UDID '653AF053-A8C2-4207-9296-61B47A96588E' and the UI client are currently running
[debug] [BaseDriver] Event 'simStarted' logged at 1608278704068 (09:05:04 GMT+0100 (Central European Standard Time))
[debug] [WebDriverAgent] No obsolete cached processes from previous WDA sessions listening on port 8100 have been found
[DevCon Factory] Requesting connection for device 653AF053-A8C2-4207-9296-61B47A96588E on local port 8100
[debug] [DevCon Factory] Cached connections count: 0
[DevCon Factory] Successfully requested the connection for 653AF053-A8C2-4207-9296-61B47A96588E:8100
[debug] [XCUITest] Starting WebDriverAgent initialization with the synchronization key 'XCUITestDriver'
[debug] [WD Proxy] Matched '/status' to command name 'getStatus'
[debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8100/status] with no body
[WD Proxy] connect ECONNREFUSED 127.0.0.1:8100
[debug] [WebDriverAgent] WDA is not listening at 'http://127.0.0.1:8100/'
[debug] [WebDriverAgent] WDA is currently not running. There is nothing to cache
[debug] [XCUITest] Trying to start WebDriverAgent 2 times with 10000ms interval
[debug] [XCUITest] These values can be customized by changing wdaStartupRetries/wdaStartupRetryInterval capabilities
[debug] [BaseDriver] Event 'wdaStartAttempted' logged at 1608278704368 (09:05:04 GMT+0100 (Central European Standard Time))
[WebDriverAgent] Launching WebDriverAgent on the device
[WebDriverAgent] Fetching dependencies
[WebDriverAgent] Installing/updating dependencies for platforms 'iOS', 'tvOS'
[debug] [WebDriverAgent] Applying Carthage build workaround to exclude Apple Silicon binaries. See https://github.com/Carthage/Carthage/issues/3019 for more details
[debug] [WebDriverAgent] *** Checking out YYCache at "1.1.2"
[debug] [WebDriverAgent] *** Checking out CocoaAsyncSocket at "72e0fa9e62d56e5bbb3f67e9cfd5aa85841735bc"
[debug] [WebDriverAgent] Parsed BUILD_DIR configuration value: '/Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-fqmfzflyhkoaixezaqynknzkzoco/Build/Products'
[debug] [WebDriverAgent] Got derived data root: '/Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-fqmfzflyhkoaixezaqynknzkzoco'
[debug] [WebDriverAgent] *** xcodebuild output can be found in /var/folders/mr/3r3vzkhj0wv50cqcwjybkznm0000gp/T/carthage-xcodebuild.BTw4Zx.log
[debug] [WebDriverAgent] *** Building scheme "tvOS Framework" in CocoaAsyncSocket.xcodeproj
[debug] [WebDriverAgent] *** Building scheme "iOS Framework" in CocoaAsyncSocket.xcodeproj
[debug] [WebDriverAgent] *** Building scheme "YYCache iOS" in YYCache.xcodeproj
[debug] [WebDriverAgent] *** Building scheme "YYCache tvOS" in YYCache.xcodeproj
[debug] [WebDriverAgent] Finished fetching dependencies
[debug] [WebDriverAgent] Cleaning the project scheme 'WebDriverAgentLib' to make sure there are no leftovers from previous installs
[debug] [WebDriverAgent] Cleaning the project scheme 'WebDriverAgentRunner' to make sure there are no leftovers from previous installs
[debug] [WebDriverAgent] Killing running processes 'xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E, 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner, xctest.*653AF053-A8C2-4207-9296-61B47A96588E' for the device 653AF053-A8C2-4207-9296-61B47A96588E...
[debug] [WebDriverAgent] 'pgrep -if xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if xctest.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] Beginning test with command 'xcodebuild build-for-testing test-without-building -project /Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -derivedDataPath /Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-fqmfzflyhkoaixezaqynknzkzoco -destination id=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET=14.3 GCC_TREAT_WARNINGS_AS_ERRORS=0 COMPILER_INDEX_STORE_ENABLE=NO' in directory '/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent'
[debug] [WebDriverAgent] Output from xcodebuild will be logged. To change this, use 'showXcodeLog' desired capability
[WebDriverAgent] Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed?
[WebDriverAgent] Launching WebDriverAgent on the device
[WebDriverAgent] Fetching dependencies
[WebDriverAgent] Dependencies up-to-date
[debug] [WebDriverAgent] Killing running processes 'xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E, 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner, xctest.*653AF053-A8C2-4207-9296-61B47A96588E' for the device 653AF053-A8C2-4207-9296-61B47A96588E...
[debug] [WebDriverAgent] 'pgrep -if xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if xctest.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] Beginning test with command 'xcodebuild build-for-testing test-without-building -project /Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -derivedDataPath /Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-fqmfzflyhkoaixezaqynknzkzoco -destination id=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET=14.3 GCC_TREAT_WARNINGS_AS_ERRORS=0 COMPILER_INDEX_STORE_ENABLE=NO' in directory '/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent'
[debug] [WebDriverAgent] Output from xcodebuild will be logged. To change this, use 'showXcodeLog' desired capability
[WebDriverAgent] Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed?
[debug] [BaseDriver] Event 'wdaStartFailed' logged at 1608278832451 (09:07:12 GMT+0100 (Central European Standard Time))
[debug] [XCUITest] Unable to launch WebDriverAgent because of xcodebuild failure: Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed?
[XCUITest] Quitting and uninstalling WebDriverAgent
[WebDriverAgent] Shutting down sub-processes
[WebDriverAgent] Shutting down 'xcodebuild' process (pid 'undefined')
[WebDriverAgent] Sending 'SIGTERM'...
[debug] [WebDriverAgent] xcodebuild process did not end in a timely fashion: 'Process didn't end after 1000ms (cmd: 'xcodebuild build-for-testing test-without-building -project /Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -derivedDataPath /Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-fqmfzflyhkoaixezaqynknzkzoco -destination id\=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET\=14.3 GCC_TREAT_WARNINGS_AS_ERRORS\=0 COMPILER_INDEX_STORE_ENABLE\=NO')'.
[WebDriverAgent] Sending 'SIGKILL'...
[debug] [BaseDriver] Event 'wdaStartAttempted' logged at 1608278853464 (09:07:33 GMT+0100 (Central European Standard Time))
[XCUITest] Retrying WDA startup (2 of 2)
[WebDriverAgent] Launching WebDriverAgent on the device
[WebDriverAgent] Fetching dependencies
[WebDriverAgent] Dependencies up-to-date
[debug] [WebDriverAgent] Killing running processes 'xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E, 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner, xctest.*653AF053-A8C2-4207-9296-61B47A96588E' for the device 653AF053-A8C2-4207-9296-61B47A96588E...
[debug] [WebDriverAgent] 'pgrep -if xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if xctest.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] Beginning test with command 'xcodebuild build-for-testing test-without-building -project /Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -derivedDataPath /Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-fqmfzflyhkoaixezaqynknzkzoco -destination id=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET=14.3 GCC_TREAT_WARNINGS_AS_ERRORS=0 COMPILER_INDEX_STORE_ENABLE=NO' in directory '/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent'
[debug] [WebDriverAgent] Output from xcodebuild will be logged. To change this, use 'showXcodeLog' desired capability
[WebDriverAgent] Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed?
[WebDriverAgent] Launching WebDriverAgent on the device
[WebDriverAgent] Fetching dependencies
[WebDriverAgent] Dependencies up-to-date
[debug] [WebDriverAgent] Killing running processes 'xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E, 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner, xctest.*653AF053-A8C2-4207-9296-61B47A96588E' for the device 653AF053-A8C2-4207-9296-61B47A96588E...
[debug] [WebDriverAgent] 'pgrep -if xcodebuild.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if 653AF053-A8C2-4207-9296-61B47A96588E.*XCTRunner' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] 'pgrep -if xctest.*653AF053-A8C2-4207-9296-61B47A96588E' didn't detect any matching processes. Return code: 1
[debug] [WebDriverAgent] Beginning test with command 'xcodebuild build-for-testing test-without-building -project /Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -derivedDataPath /Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-fqmfzflyhkoaixezaqynknzkzoco -destination id=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET=14.3 GCC_TREAT_WARNINGS_AS_ERRORS=0 COMPILER_INDEX_STORE_ENABLE=NO' in directory '/Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent'
[debug] [WebDriverAgent] Output from xcodebuild will be logged. To change this, use 'showXcodeLog' desired capability
[WebDriverAgent] Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed?
[debug] [BaseDriver] Event 'wdaStartFailed' logged at 1608278853623 (09:07:33 GMT+0100 (Central European Standard Time))
[debug] [XCUITest] Unable to launch WebDriverAgent because of xcodebuild failure: Unable to start WebDriverAgent: Error: Command 'xcodebuild' not found. Is it installed?
[XCUITest] Quitting and uninstalling WebDriverAgent
[WebDriverAgent] Shutting down sub-processes
[WebDriverAgent] Shutting down 'xcodebuild' process (pid 'undefined')
[WebDriverAgent] Sending 'SIGTERM'...
[debug] [WebDriverAgent] xcodebuild process did not end in a timely fashion: 'Process didn't end after 1000ms (cmd: 'xcodebuild build-for-testing test-without-building -project /Users/lode/.asdf/installs/nodejs/12.20.0/.npm/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -derivedDataPath /Users/lode/Library/Developer/Xcode/DerivedData/WebDriverAgent-fqmfzflyhkoaixezaqynknzkzoco -destination id\=653AF053-A8C2-4207-9296-61B47A96588E IPHONEOS_DEPLOYMENT_TARGET\=14.3 GCC_TREAT_WARNINGS_AS_ERRORS\=0 COMPILER_INDEX_STORE_ENABLE\=NO')'.
[WebDriverAgent] Sending 'SIGKILL'...
mykola-mokhnach commented 3 years ago

Such error message is printed when the standard Node spawn call returns ENOENT error: https://github.com/appium/node-teen_process/blob/5d8c1d68d211215da8d12905f669d9d93ab769a8/lib/subprocess.js#L149

I'm not quite sure what exactly causes the error in your case, but I would start with writing a simple Node script, that calls xcodebuild using spawn to figure out what the cause could be.

mykola-mokhnach commented 3 years ago

Something that Google shows: https://stackoverflow.com/questions/27688804/how-do-i-debug-error-spawn-enoent-on-node-js

bitcrumb commented 3 years ago

I recall seeing that spawn error message with the ENOENT code as well idd, thanks for the pointer, most helpful!

Note: seems that I am not alone with this error, a colleague of mine experienced the same error in september already.

And thank you for your time! 🙏🏻

bitcrumb commented 3 years ago

It seems like the xcodebuild binary can be properly resolved when creating a local node script:

Screenshot 2020-12-18 at 09 51 14

Is Appium desktop potentially using a different node version?

mykola-mokhnach commented 3 years ago

In the SO atricle above it is stated that spawn may throw this error also ifcwd value is wrong/does not exist. Please make sure your bootstrapPath is a valid one

bitcrumb commented 3 years ago

🤦🏻 That's it. The bootstrapPath points to a directory that doesn't exist. The /WebDriverAgent at the end is wrong. Must be a copy/paste error from our internal Wiki which still had old paths in the example code. And to top it off, I kept changing only the first bit of the path when trying out different paths. Ugh.

The error message totally threw me off & had me looking in all the wrong directions.

Thanks for pointing that out! Really appreciate your help ❤️

mykola-mokhnach commented 3 years ago

I hope the error message will be more helpful after https://github.com/appium/node-teen_process/pull/55 is merged