diff --git a/lib/webdriveragent.js b/lib/webdriveragent.js index 4e0c0b876..5e262f396 100644 --- a/lib/webdriveragent.js +++ b/lib/webdriveragent.js @@ -4,7 +4,7 @@ import url from 'url'; import B from 'bluebird'; import { JWProxy } from '@appium/base-driver'; import { fs, util, plist, mkdirp } from '@appium/support'; -import log from './logger'; +import defaultLogger from './logger'; import { NoSessionProxy } from './no-session-proxy'; import { getWDAUpgradeTimestamp, resetTestProcesses, getPIDsListeningOnPort @@ -24,10 +24,11 @@ const WDA_CF_BUNDLE_NAME = 'WebDriverAgentRunner-Runner'; const SHARED_RESOURCES_GUARD = new AsyncLock(); class WebDriverAgent { - constructor (xcodeVersion, args = {}) { + constructor (xcodeVersion, args = {}, log = null) { this.xcodeVersion = xcodeVersion; this.args = _.clone(args); + this.log = log ?? defaultLogger; this.device = args.device; this.platformVersion = args.platformVersion; @@ -83,18 +84,18 @@ class WebDriverAgent { allowProvisioningDeviceRegistration: args.allowProvisioningDeviceRegistration, resultBundlePath: args.resultBundlePath, resultBundleVersion: args.resultBundleVersion, - }); + }, this.log); } setWDAPaths (bootstrapPath, agentPath) { // allow the user to specify a place for WDA. This is undocumented and // only here for the purposes of testing development of WDA this.bootstrapPath = bootstrapPath || BOOTSTRAP_PATH; - log.info(`Using WDA path: '${this.bootstrapPath}'`); + this.log.info(`Using WDA path: '${this.bootstrapPath}'`); // for backward compatibility we need to be able to specify agentPath too this.agentPath = agentPath || path.resolve(this.bootstrapPath, 'WebDriverAgent.xcodeproj'); - log.info(`Using WDA agent: '${this.agentPath}'`); + this.log.info(`Using WDA agent: '${this.agentPath}'`); } async cleanupObsoleteProcesses () { @@ -103,17 +104,17 @@ class WebDriverAgent { !cmdLine.toLowerCase().includes(this.device.udid.toLowerCase())); if (_.isEmpty(obsoletePids)) { - log.debug(`No obsolete cached processes from previous WDA sessions ` + + this.log.debug(`No obsolete cached processes from previous WDA sessions ` + `listening on port ${this.url.port} have been found`); return; } - log.info(`Detected ${obsoletePids.length} obsolete cached process${obsoletePids.length === 1 ? '' : 'es'} ` + + this.log.info(`Detected ${obsoletePids.length} obsolete cached process${obsoletePids.length === 1 ? '' : 'es'} ` + `from previous WDA sessions. Cleaning them up`); try { await exec('kill', obsoletePids); } catch (e) { - log.warn(`Failed to kill obsolete cached process${obsoletePids.length === 1 ? '' : 'es'} '${obsoletePids}'. ` + + this.log.warn(`Failed to kill obsolete cached process${obsoletePids.length === 1 ? '' : 'es'} '${obsoletePids}'. ` + `Original error: ${e.message}`); } } @@ -166,7 +167,7 @@ class WebDriverAgent { try { return await noSessionProxy.command('/status', 'GET'); } catch (err) { - log.debug(`WDA is not listening at '${this.url.href}'`); + this.log.debug(`WDA is not listening at '${this.url.href}'`); return null; } } @@ -180,17 +181,17 @@ class WebDriverAgent { try { const bundleIds = await this.device.getUserInstalledBundleIdsByBundleName(WDA_CF_BUNDLE_NAME); if (_.isEmpty(bundleIds)) { - log.debug('No WDAs on the device.'); + this.log.debug('No WDAs on the device.'); return; } - log.debug(`Uninstalling WDAs: '${bundleIds}'`); + this.log.debug(`Uninstalling WDAs: '${bundleIds}'`); for (const bundleId of bundleIds) { await this.device.removeApp(bundleId); } } catch (e) { - log.debug(e); - log.warn(`WebDriverAgent uninstall failed. Perhaps, it is already uninstalled? ` + + this.log.debug(e); + this.log.warn(`WebDriverAgent uninstall failed. Perhaps, it is already uninstalled? ` + `Original error: ${e.message}`); } } @@ -198,13 +199,13 @@ class WebDriverAgent { async _cleanupProjectIfFresh () { const homeFolder = process.env.HOME; if (!homeFolder) { - log.info('The HOME folder path cannot be determined'); + this.log.info('The HOME folder path cannot be determined'); return; } const currentUpgradeTimestamp = await getWDAUpgradeTimestamp(); if (!_.isInteger(currentUpgradeTimestamp)) { - log.info('It is impossible to determine the timestamp of the package'); + this.log.info('It is impossible to determine the timestamp of the package'); return; } @@ -213,31 +214,31 @@ class WebDriverAgent { try { await fs.access(timestampPath, fs.W_OK); } catch (ign) { - log.info(`WebDriverAgent upgrade timestamp at '${timestampPath}' is not writeable. ` + + this.log.info(`WebDriverAgent upgrade timestamp at '${timestampPath}' is not writeable. ` + `Skipping sources cleanup`); return; } const recentUpgradeTimestamp = parseInt(await fs.readFile(timestampPath, 'utf8'), 10); if (_.isInteger(recentUpgradeTimestamp)) { if (recentUpgradeTimestamp >= currentUpgradeTimestamp) { - log.info(`WebDriverAgent does not need a cleanup. The sources are up to date ` + + this.log.info(`WebDriverAgent does not need a cleanup. The sources are up to date ` + `(${recentUpgradeTimestamp} >= ${currentUpgradeTimestamp})`); return; } - log.info(`WebDriverAgent sources have been upgraded ` + + this.log.info(`WebDriverAgent sources have been upgraded ` + `(${recentUpgradeTimestamp} < ${currentUpgradeTimestamp})`); } else { - log.warn(`The recent upgrade timestamp at '${timestampPath}' is corrupted. Trying to fix it`); + this.log.warn(`The recent upgrade timestamp at '${timestampPath}' is corrupted. Trying to fix it`); } } try { await mkdirp(path.dirname(timestampPath)); await fs.writeFile(timestampPath, `${currentUpgradeTimestamp}`, 'utf8'); - log.debug(`Stored the recent WebDriverAgent upgrade timestamp ${currentUpgradeTimestamp} ` + + this.log.debug(`Stored the recent WebDriverAgent upgrade timestamp ${currentUpgradeTimestamp} ` + `at '${timestampPath}'`); } catch (e) { - log.info(`Unable to create the recent WebDriverAgent upgrade timestamp at '${timestampPath}'. ` + + this.log.info(`Unable to create the recent WebDriverAgent upgrade timestamp at '${timestampPath}'. ` + `Original error: ${e.message}`); return; } @@ -245,7 +246,7 @@ class WebDriverAgent { try { await this.xcodebuild.cleanProject(); } catch (e) { - log.warn(`Cannot perform WebDriverAgent project cleanup. Original error: ${e.message}`); + this.log.warn(`Cannot perform WebDriverAgent project cleanup. Original error: ${e.message}`); } } @@ -274,13 +275,13 @@ class WebDriverAgent { */ async launch (sessionId) { if (this.webDriverAgentUrl) { - log.info(`Using provided WebdriverAgent at '${this.webDriverAgentUrl}'`); + this.log.info(`Using provided WebdriverAgent at '${this.webDriverAgentUrl}'`); this.url = this.webDriverAgentUrl; this.setupProxies(sessionId); return await this.getStatus(); } - log.info('Launching WebDriverAgent on the device'); + this.log.info('Launching WebDriverAgent on the device'); this.setupProxies(sessionId); @@ -292,7 +293,7 @@ class WebDriverAgent { // useXctestrunFile and usePrebuiltWDA use existing dependencies // It depends on user side if (this.idb || this.useXctestrunFile || (this.derivedDataPath && this.usePrebuiltWDA)) { - log.info('Skipped WDA project cleanup according to the provided capabilities'); + this.log.info('Skipped WDA project cleanup according to the provided capabilities'); } else { const synchronizationKey = path.normalize(this.bootstrapPath); await SHARED_RESOURCES_GUARD.acquire(synchronizationKey, @@ -316,7 +317,7 @@ class WebDriverAgent { } async startWithIDB () { - log.info('Will launch WDA with idb instead of xcodebuild since the corresponding flag is enabled'); + this.log.info('Will launch WDA with idb instead of xcodebuild since the corresponding flag is enabled'); const {wdaBundleId, testBundleId} = await this.prepareWDA(); const env = { USE_PORT: this.wdaRemotePort, @@ -371,6 +372,7 @@ class WebDriverAgent { setupProxies (sessionId) { const proxyOpts = { + log: this.log, server: this.url.hostname, port: this.url.port, base: this.basePath, @@ -386,7 +388,7 @@ class WebDriverAgent { } async quit () { - log.info('Shutting down sub-processes'); + this.log.info('Shutting down sub-processes'); await this.xcodebuild.quit(); await this.xcodebuild.reset(); @@ -443,7 +445,7 @@ class WebDriverAgent { async setupCaching () { const status = await this.getStatus(); if (!status || !status.build) { - log.debug('WDA is currently not running. There is nothing to cache'); + this.log.debug('WDA is currently not running. There is nothing to cache'); return; } @@ -453,20 +455,20 @@ class WebDriverAgent { } = status.build; // for real device if (util.hasValue(productBundleIdentifier) && util.hasValue(this.updatedWDABundleId) && this.updatedWDABundleId !== productBundleIdentifier) { - log.info(`Will uninstall running WDA since it has different bundle id. The actual value is '${productBundleIdentifier}'.`); + this.log.info(`Will uninstall running WDA since it has different bundle id. The actual value is '${productBundleIdentifier}'.`); return await this.uninstall(); } // for simulator if (util.hasValue(productBundleIdentifier) && !util.hasValue(this.updatedWDABundleId) && WDA_RUNNER_BUNDLE_ID !== productBundleIdentifier) { - log.info(`Will uninstall running WDA since its bundle id is not equal to the default value ${WDA_RUNNER_BUNDLE_ID}`); + this.log.info(`Will uninstall running WDA since its bundle id is not equal to the default value ${WDA_RUNNER_BUNDLE_ID}`); return await this.uninstall(); } const actualUpgradeTimestamp = await getWDAUpgradeTimestamp(); - log.debug(`Upgrade timestamp of the currently bundled WDA: ${actualUpgradeTimestamp}`); - log.debug(`Upgrade timestamp of the WDA on the device: ${upgradedAt}`); + this.log.debug(`Upgrade timestamp of the currently bundled WDA: ${actualUpgradeTimestamp}`); + this.log.debug(`Upgrade timestamp of the WDA on the device: ${upgradedAt}`); if (actualUpgradeTimestamp && upgradedAt && _.toLower(`${actualUpgradeTimestamp}`) !== _.toLower(`${upgradedAt}`)) { - log.info('Will uninstall running WDA since it has different version in comparison to the one ' + + this.log.info('Will uninstall running WDA since it has different version in comparison to the one ' + `which is bundled with appium-xcuitest-driver module (${actualUpgradeTimestamp} != ${upgradedAt})`); return await this.uninstall(); } @@ -474,7 +476,7 @@ class WebDriverAgent { const message = util.hasValue(productBundleIdentifier) ? `Will reuse previously cached WDA instance at '${this.url.href}' with '${productBundleIdentifier}'` : `Will reuse previously cached WDA instance at '${this.url.href}'`; - log.info(`${message}. Set the wdaLocalPort capability to a value different from ${this.url.port} if this is an undesired behavior.`); + this.log.info(`${message}. Set the wdaLocalPort capability to a value different from ${this.url.port} if this is an undesired behavior.`); this.webDriverAgentUrl = this.url.href; } diff --git a/lib/xcodebuild.js b/lib/xcodebuild.js index fbbf1be8e..aca528aab 100644 --- a/lib/xcodebuild.js +++ b/lib/xcodebuild.js @@ -1,7 +1,7 @@ import { retryInterval } from 'asyncbox'; import { SubProcess, exec } from 'teen_process'; import { fs, logger, timing } from '@appium/support'; -import log from './logger'; +import defaultLogger from './logger'; import B from 'bluebird'; import { setRealDeviceSecurity, generateXcodeConfigFile, setXctestrunFile, @@ -33,10 +33,11 @@ const xcodeLog = logger.getLogger('Xcode'); class XcodeBuild { - constructor (xcodeVersion, device, args = {}) { + constructor (xcodeVersion, device, args = {}, log = null) { this.xcodeVersion = xcodeVersion; this.device = device; + this.log = log ?? defaultLogger; this.realDevice = args.realDevice; @@ -121,20 +122,20 @@ class XcodeBuild { try { ({stdout} = await exec('xcodebuild', ['-project', this.agentPath, '-showBuildSettings'])); } catch (err) { - log.warn(`Cannot retrieve WDA build settings. Original error: ${err.message}`); + this.log.warn(`Cannot retrieve WDA build settings. Original error: ${err.message}`); return; } const pattern = /^\s*BUILD_DIR\s+=\s+(\/.*)/m; const match = pattern.exec(stdout); if (!match) { - log.warn(`Cannot parse WDA build dir from ${_.truncate(stdout, {length: 300})}`); + this.log.warn(`Cannot parse WDA build dir from ${_.truncate(stdout, {length: 300})}`); return; } - log.debug(`Parsed BUILD_DIR configuration value: '${match[1]}'`); + this.log.debug(`Parsed BUILD_DIR configuration value: '${match[1]}'`); // Derived data root is two levels higher over the build dir this.derivedDataPath = path.dirname(path.dirname(path.normalize(match[1]))); - log.debug(`Got derived data root: '${this.derivedDataPath}'`); + this.log.debug(`Got derived data root: '${this.derivedDataPath}'`); return this.derivedDataPath; })(); return await this._derivedDataPathPromise; @@ -149,7 +150,7 @@ class XcodeBuild { async prebuild () { // first do a build phase - log.debug('Pre-building WDA before launching test'); + this.log.debug('Pre-building WDA before launching test'); this.usePrebuiltWDA = true; await this.start(true); @@ -165,7 +166,7 @@ class XcodeBuild { const runnerScheme = tmpIsTvOS ? RUNNER_SCHEME_TV : RUNNER_SCHEME_IOS; for (const scheme of [libScheme, runnerScheme]) { - log.debug(`Cleaning the project scheme '${scheme}' to make sure there are no leftovers from previous installs`); + this.log.debug(`Cleaning the project scheme '${scheme}' to make sure there are no leftovers from previous installs`); await exec('xcodebuild', [ 'clean', '-project', this.agentPath, @@ -216,12 +217,12 @@ class XcodeBuild { if (versionMatch) { args.push(`IPHONEOS_DEPLOYMENT_TARGET=${versionMatch[1]}.${versionMatch[2]}`); } else { - log.warn(`Cannot parse major and minor version numbers from platformVersion "${this.platformVersion}". ` + + this.log.warn(`Cannot parse major and minor version numbers from platformVersion "${this.platformVersion}". ` + 'Will build for the default platform instead'); } if (this.realDevice && this.xcodeConfigFile) { - log.debug(`Using Xcode configuration file: '${this.xcodeConfigFile}'`); + this.log.debug(`Using Xcode configuration file: '${this.xcodeConfigFile}'`); args.push('-xcconfig', this.xcodeConfigFile); } @@ -248,8 +249,8 @@ class XcodeBuild { } const {cmd, args} = this.getCommand(buildOnly); - log.debug(`Beginning ${buildOnly ? 'build' : 'test'} with command '${cmd} ${args.join(' ')}' ` + - `in directory '${this.bootstrapPath}'`); + this.log.debug(`Beginning ${buildOnly ? 'build' : 'test'} with command '${cmd} ${args.join(' ')}' ` + + `in directory '${this.bootstrapPath}'`); const env = Object.assign({}, process.env, { USE_PORT: this.wdaRemotePort, WDA_PRODUCT_BUNDLE_IDENTIFIER: this.updatedWDABundleId || WDA_RUNNER_BUNDLE_ID, @@ -273,7 +274,7 @@ class XcodeBuild { const logMsg = _.isBoolean(this.showXcodeLog) ? `Output from xcodebuild ${this.showXcodeLog ? 'will' : 'will not'} be logged` : 'Output from xcodebuild will only be logged if any errors are present there'; - log.debug(`${logMsg}. To change this, use 'showXcodeLog' desired capability`); + this.log.debug(`${logMsg}. To change this, use 'showXcodeLog' desired capability`); xcodebuild.on('output', (stdout, stderr) => { let out = stdout || stderr; // we want to pull out the log file that is created, and highlight it @@ -282,7 +283,7 @@ class XcodeBuild { // pull out the first line that begins with the path separator // which *should* be the line indicating the log file generated xcodebuild.logLocation = _.first(_.remove(out.trim().split('\n'), (v) => v.startsWith(path.sep))); - log.debug(`Log file for xcodebuild test: ${xcodebuild.logLocation}`); + xcodeLog.debug(`Log file for xcodebuild test: ${xcodebuild.logLocation}`); } // if we have an error we want to output the logs @@ -319,7 +320,7 @@ class XcodeBuild { // any startup errors that are thrown as events return await new B((resolve, reject) => { this.xcodebuild.on('exit', async (code, signal) => { - log.error(`xcodebuild exited with code '${code}' and signal '${signal}'`); + xcodeLog.error(`xcodebuild exited with code '${code}' and signal '${signal}'`); // print out the xcodebuild file if users have asked for it if (this.showXcodeLog && this.xcodebuild.logLocation) { xcodeLog.error(`Contents of xcodebuild log file '${this.xcodebuild.logLocation}':`); @@ -329,7 +330,7 @@ class XcodeBuild { xcodeLog.error(line); } } catch (err) { - log.error(`Unable to access xcodebuild log file: '${err.message}'`); + xcodeLog.error(`Unable to access xcodebuild log file: '${err.message}'`); } } this.xcodebuild.processExited = true; @@ -353,7 +354,7 @@ class XcodeBuild { } } catch (err) { let msg = `Unable to start WebDriverAgent: ${err}`; - log.error(msg); + this.log.error(msg); reject(new Error(msg)); } })(); @@ -362,7 +363,7 @@ class XcodeBuild { async waitForStart (timer) { // try to connect once every 0.5 seconds, until `launchTimeout` is up - log.debug(`Waiting up to ${this.launchTimeout}ms for WebDriverAgent to start`); + this.log.debug(`Waiting up to ${this.launchTimeout}ms for WebDriverAgent to start`); let currentStatus = null; try { let retries = parseInt(this.launchTimeout / 500, 10); @@ -378,8 +379,8 @@ class XcodeBuild { if (currentStatus && currentStatus.ios && currentStatus.ios.ip) { this.agentUrl = currentStatus.ios.ip; } - log.debug(`WebDriverAgent information:`); - log.debug(JSON.stringify(currentStatus, null, 2)); + this.log.debug(`WebDriverAgent information:`); + this.log.debug(JSON.stringify(currentStatus, null, 2)); } catch (err) { throw new Error(`Unable to connect to running WebDriverAgent: ${err.message}`); } finally { @@ -392,12 +393,12 @@ class XcodeBuild { return currentStatus; } - log.debug(`WebDriverAgent successfully started after ${timer.getDuration().asMilliSeconds.toFixed(0)}ms`); + this.log.debug(`WebDriverAgent successfully started after ${timer.getDuration().asMilliSeconds.toFixed(0)}ms`); } catch (err) { // at this point, if we have not had any errors from xcode itself (reported // elsewhere), we can let this go through and try to create the session - log.debug(err.message); - log.warn(`Getting status of WebDriverAgent on device timed out. Continuing`); + this.log.debug(err.message); + this.log.warn(`Getting status of WebDriverAgent on device timed out. Continuing`); } return currentStatus; } diff --git a/package.json b/package.json index 0f9dc5720..6269704a4 100644 --- a/package.json +++ b/package.json @@ -59,7 +59,7 @@ "sinon": "^13.0.0" }, "dependencies": { - "@appium/base-driver": "^8.0.0", + "@appium/base-driver": "^8.3.0", "@appium/support": "^2.55.3", "@babel/runtime": "^7.0.0", "appium-ios-simulator": "^4.0.0",