Speed up iproxy and ffmpeg startup

lib/commands/recordscreen.js

@@ -4,6 +4,7 @@ import { SubProcess } from 'teen_process';
 import log from '../logger';
 import { encodeBase64OrUpload } from '../utils';
 import iProxy from '../wda/iproxy';
+import { waitForCondition } from 'asyncbox';
 
 let commands = {};
 
@@ -66,14 +67,34 @@ class ScreenRecorder {
       '-vcodec', this.opts.videoType,
       '-y', this.videoPath
     );
+
     this.mainProcess = new SubProcess(FFMPEG_BINARY, args);
+    let isCaptureStarted = false;
     this.mainProcess.on('output', (stdout, stderr) => {
-      if (stderr && !stderr.includes('frame=')) {
-        ffmpegLogger.info(`${stderr}`);
+      if (stderr) {
+        if (stderr.trim().startsWith('frame=')) {
+          if (!isCaptureStarted) {
+            isCaptureStarted = true;
+          }
+        } else {
+          ffmpegLogger.info(`${stderr}`);
+        }
       }
     });
-    // Give ffmpeg some time for init
-    await this.mainProcess.start(5000);
+    await this.mainProcess.start(0);
+    const startupTimeout = 5000;
+    try {
+      await waitForCondition(() => isCaptureStarted, {
+        waitMs: startupTimeout,
+        intervalMs: 300,
+      });
+    } catch (e) {
+      log.warn(`Screen capture process did not start within ${startupTimeout}ms. Continuing anyway`);
+    }
+    if (!this.mainProcess.isRunning) {
+      throw new Error(`The screen capture process '${FFMPEG_BINARY}' died unexpectedly. ` +
+        `Check server logs for more details`);
+    }
     log.info(`Starting screen capture on the device '${this.udid}' with command: '${FFMPEG_BINARY} ${args.join(' ')}'. ` +
       `Will timeout in ${timeoutMs}ms`);
 
@@ -85,7 +106,7 @@ class ScreenRecorder {
   }
 
   async startIproxy (localPort) {
-    this.iproxy = new iProxy(this.udid, localPort, this.opts.remotePort);
+    this.iproxy = new iProxy(this.udid, localPort, this.opts.remotePort, false);
     try {
       await this.iproxy.start();
     } catch (err) {

lib/wda/iproxy.js

@@ -3,24 +3,29 @@ import { killProcess } from './utils';
 import B from 'bluebird';
 import { logger } from 'appium-support';
 import { SubProcess } from 'teen_process';
+import { checkPortStatus } from 'portscanner';
+import { waitForCondition } from 'asyncbox';
 
 
-const IPROXY_TIMEOUT = 5000;
+const IPROXY_STARTUP_TIMEOUT = 5000;
 
 const iproxyLog = logger.getLogger('iProxy');
 
 class iProxy {
-  constructor (udid, localport, deviceport) {
-    log.debug(`Starting iproxy to forward traffic from local port ${localport} to device port ${deviceport} over USB ` +
-      `for the device ${udid}`);
+  constructor (udid, localport, deviceport, detached = true) {
     this.expectIProxyErrors = true;
+    this.localport = parseInt(localport, 10);
+    this.deviceport = parseInt(deviceport, 10);
+    this.udid = udid;
     this.iproxy = new SubProcess('iproxy', [localport, deviceport, udid], {
-      detached: true,
+      detached,
       stdio: ['ignore', 'pipe', 'pipe'],
     });
   }
 
   async start () {
+    log.debug(`Starting iproxy to forward traffic from local port ${this.localport} ` +
+      `to device port ${this.deviceport} over USB for the device ${this.udid}`);
     this.expectIProxyErrors = true;
 
     return await new B((resolve, reject) => {
@@ -54,11 +59,32 @@ class iProxy {
 
       return (async () => {
         try {
-          await this.iproxy.start(IPROXY_TIMEOUT, true);
+          if ((await checkPortStatus(this.localport, '127.0.0.1')) === 'open') {
+            throw new Error(`The port #${this.localport} is occupied by an other app. ` +
+              `You can customize its value by setting the 'wdaLocalPort' capability.`);
+          }
+          await this.iproxy.start(0);
+          try {
+            await waitForCondition(async () => {
+              try {
+                return (await checkPortStatus(this.localport, '127.0.0.1')) === 'open';
+              } catch (ign) {
+                return false;
+              }
+            }, {
+              waitMs: IPROXY_STARTUP_TIMEOUT,
+              intervalMs: 300,
+            });
+            log.debug(`iProxy is running and is listening on port #${this.localport}`);
+          } catch (e) {
+            log.warn(`The local port ${this.localport} is still closed after ${IPROXY_STARTUP_TIMEOUT}ms. ` +
+              `Continuing anyway`);
+          }
           resolve();
         } catch (err) {
           log.error(`Error starting iproxy: '${err.message}'`);
-          reject(new Error('Unable to start iproxy. Is it installed?'));
+          reject(new Error('Unable to start iproxy. Make sure libusbmuxd is installed and ' +
+            'PATH contains the folder, where the binary is located.'));
         }
       })();
     });

package.json

@@ -47,6 +47,7 @@
     "js2xmlparser2": "^0.2.0",
     "lodash": "^4.17.10",
     "node-simctl": "^5.0.0",
+    "portscanner": "2.2.0",
     "request": "^2.79.0",
     "request-promise": "^4.1.1",
     "source-map-support": "^0.5.5",