Bug 1272522 Handle stderr of native app r?kmag draft
authorAndrew Swan <aswan@mozilla.com>
Wed, 06 Jul 2016 14:57:56 -0700
changeset 385049 41edfe61af003659417cb21a2060f0bb54fb7a76
parent 384476 95ffbc4ff63584631c408e8d9912961fcf68bb09
child 385280 5c8096a278ca8513d9276a98fbd7917abe9a2a38
push id22412
push useraswan@mozilla.com
push dateThu, 07 Jul 2016 16:31:49 +0000
reviewerskmag
bugs1272522
milestone50.0a1
Bug 1272522 Handle stderr of native app r?kmag MozReview-Commit-ID: 5qGw83uTYTu
toolkit/components/extensions/NativeMessaging.jsm
toolkit/components/extensions/test/mochitest/.eslintrc
toolkit/components/extensions/test/mochitest/chrome.ini
toolkit/components/extensions/test/mochitest/head.js
toolkit/components/extensions/test/mochitest/test_chrome_ext_native_messaging.html
--- a/toolkit/components/extensions/NativeMessaging.jsm
+++ b/toolkit/components/extensions/NativeMessaging.jsm
@@ -197,23 +197,25 @@ this.NativeApp = class extends EventEmit
           // here.  If it is relative, we get the proper absolute path here.
           command = OS.Path.join(OS.Path.dirname(hostInfo.path), command);
         }
 
         let subprocessOpts = {
           command: command,
           arguments: [hostInfo.path],
           workdir: OS.Path.dirname(command),
+          stderr: "pipe",
         };
         return Subprocess.call(subprocessOpts);
       }).then(proc => {
         this.startupPromise = null;
         this.proc = proc;
         this._startRead();
         this._startWrite();
+        this._startStderrRead();
       }).catch(err => {
         this.startupPromise = null;
         Cu.reportError(err.message);
         this._cleanup(err);
       });
   }
 
   // A port is definitely "alive" if this.proc is non-null.  But we have
@@ -263,16 +265,42 @@ this.NativeApp = class extends EventEmit
       this.writePromise = null;
       this._startWrite();
     }).catch(err => {
       Cu.reportError(err.message);
       this._cleanup(err);
     });
   }
 
+  _startStderrRead() {
+    let proc = this.proc;
+    let app = this.name;
+    Task.spawn(function* () {
+      let partial = "";
+      while (true) {
+        let data = yield proc.stderr.readString();
+        if (data.length == 0) {
+          // We have hit EOF, just stop reading
+          if (partial) {
+            Services.console.logStringMessage(`stderr output from native app ${app}: ${partial}`);
+          }
+          break;
+        }
+
+        let lines = data.split(/\r?\n/);
+        lines[0] = partial + lines[0];
+        partial = lines.pop();
+
+        for (let line of lines) {
+          Services.console.logStringMessage(`stderr output from native app ${app}: ${line}`);
+        }
+      }
+    });
+  }
+
   send(msg) {
     if (this._isDisconnected) {
       throw new this.context.cloneScope.Error("Attempt to postMessage on disconnected port");
     }
 
     let json;
     try {
       json = this.context.jsonStringify(msg);
--- a/toolkit/components/extensions/test/mochitest/.eslintrc
+++ b/toolkit/components/extensions/test/mochitest/.eslintrc
@@ -4,14 +4,15 @@
   "env": {
     "webextensions": true,
   },
 
   "globals": {
     "sendAsyncMessage": false,
 
     "waitForLoad": true,
+    "promiseConsoleOutput": true,
 
     "ExtensionTestUtils": false,
     "NetUtil": true,
     "XPCOMUtils": true,
   },
 }
--- a/toolkit/components/extensions/test/mochitest/chrome.ini
+++ b/toolkit/components/extensions/test/mochitest/chrome.ini
@@ -1,10 +1,11 @@
 [DEFAULT]
 support-files =
+  head.js
   file_download.html
   file_download.txt
   interruptible.sjs
   file_sample.html
 
 [test_chrome_ext_background_debug_global.html]
 skip-if = (os == 'android') # android doesn't have devtools
 [test_chrome_ext_background_page.html]
--- a/toolkit/components/extensions/test/mochitest/head.js
+++ b/toolkit/components/extensions/test/mochitest/head.js
@@ -5,8 +5,9 @@
 function waitForLoad(win) {
   return new Promise(resolve => {
     win.addEventListener("load", function listener() {
       win.removeEventListener("load", listener, true);
       resolve();
     }, true);
   });
 }
+
--- a/toolkit/components/extensions/test/mochitest/test_chrome_ext_native_messaging.html
+++ b/toolkit/components/extensions/test/mochitest/test_chrome_ext_native_messaging.html
@@ -1,38 +1,66 @@
 <!DOCTYPE HTML>
 <html>
 <head>
   <title>WebExtension test</title>
   <script src="chrome://mochikit/content/tests/SimpleTest/SimpleTest.js"></script>
   <script src="chrome://mochikit/content/tests/SimpleTest/SpawnTask.js"></script>
   <script src="chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js"></script>
   <script type="text/javascript" src="head.js"></script>
-  <script type="text/javascript" src="test_constants.js"></script>
   <link rel="stylesheet" href="chrome://mochikit/contents/tests/SimpleTest/test.css"/>
 </head>
 <body>
 
 <script type="text/javascript">
 "use strict";
 
 /* globals OS */
 
 const {classes: Cc, interfaces: Ci, utils: Cu, results: Cr} = Components;
 
 Cu.import("resource://gre/modules/AppConstants.jsm");
 Cu.import("resource://gre/modules/FileUtils.jsm");
 Cu.import("resource://gre/modules/osfile.jsm");
 Cu.import("resource://gre/modules/Services.jsm");
 let {Subprocess, SubprocessImpl} = Cu.import("resource://gre/modules/Subprocess.jsm");
+Components.utils.import("resource://gre/modules/Task.jsm");
 
 if (AppConstants.platform == "win") {
   Cu.import("resource://testing-common/MockRegistry.jsm");
 }
 
+var promiseConsoleOutput = Task.async(function* (task) {
+  const DONE = "=== extension test console listener done ===";
+
+  let listener;
+  let messages = [];
+  let awaitListener = new Promise(resolve => {
+    listener = msg => {
+      if (msg == DONE) {
+        resolve();
+      } else if (msg instanceof Ci.nsIConsoleMessage) {
+        messages.push(msg.message);
+      }
+    };
+  });
+
+  Services.console.registerListener(listener);
+  try {
+    let result = yield task();
+
+    Services.console.logStringMessage(DONE);
+    yield awaitListener;
+
+    return {messages, result};
+  } finally {
+    Services.console.unregisterListener(listener);
+  }
+});
+
 const PREF_MAX_READ = "webextensions.native-messaging.max-input-message-bytes";
 const PREF_MAX_WRITE = "webextensions.native-messaging.max-output-message-bytes";
 
 function getSubprocessCount() {
   return SubprocessImpl.Process.getWorker().call("getProcesses", [])
                        .then(result => result.size);
 }
 function waitForSubprocessExit() {
@@ -91,32 +119,52 @@ while True:
         signal.pause()
     msglen = struct.unpack('@I', rawlen)[0]
     msg = sys.stdin.read(msglen)
 
     sys.stdout.write(struct.pack('@I', msglen))
     sys.stdout.write(msg)
 `;
 
+const STDERR_LINES = ["hello stderr", "this should be a separate line"];
+let STDERR_MSG = STDERR_LINES.join("\\n");
+
+// Python apparently line-buffers stderr even with the -u arg on
+// Windows 7.  Dealing with that is more hassle than its worth but
+// on other platforms, we want to keep testing partial lines.
+if (AppConstants.isPlatformAndVersionAtMost("win", "7")) {
+  STDERR_MSG += "\\n";
+}
+
+const STDERR_BODY = String.raw`
+import sys
+sys.stderr.write("${STDERR_MSG}")
+`;
+
 const SCRIPTS = [
   {
     name: "echo",
     description: "a native app that echoes back messages it receives",
     script: ECHO_BODY,
   },
   {
     name: "info",
     description: "a native app that gives some info about how it was started",
     script: INFO_BODY,
   },
   {
     name: "wontdie",
     description: "a native app that does not exit when stdin closes or on SIGTERM",
     script: WONTDIE_BODY,
   },
+  {
+    name: "stderr",
+    description: "a native app that writes to stderr and then exits",
+    script: STDERR_BODY,
+  },
 ];
 
 add_task(function* setup() {
   const PERMS = {unixMode: 0o755};
   let pythonPath = yield Subprocess.pathSearch("python2.7").catch(err => {
     if (err.errorCode != Subprocess.ERROR_BAD_EXECUTABLE) {
       throw err;
     }
@@ -605,12 +653,41 @@ add_task(function* test_unresponsive_nat
   let exitPromise = waitForSubprocessExit();
   yield extension.unload();
   yield exitPromise;
 
   procCount = yield getSubprocessCount();
   is(procCount, 0, "subprocess was succesfully killed");
 });
 
+add_task(function* test_stderr() {
+  function background() {
+    let port = browser.runtime.connectNative("stderr");
+    port.onDisconnect.addListener(() => {
+      browser.test.sendMessage("finished");
+    });
+  }
+
+  let {messages} = yield promiseConsoleOutput(function* () {
+    let extension = ExtensionTestUtils.loadExtension({
+      background: `(${background})()`,
+      manifest: {
+        permissions: ["nativeMessaging"],
+      },
+    }, ID);
+
+    yield extension.startup();
+    yield extension.awaitMessage("finished");
+    yield extension.unload();
+  });
+
+  let lines = STDERR_LINES.map(line => messages.findIndex(msg => msg.includes(line)));
+  isnot(lines[0], -1, "Saw first line of stderr output on the console");
+  isnot(lines[1], -1, "Saw second line of stderr output on the console");
+  isnot(lines[0], lines[1], "Stderr output lines are separated in the console");
+
+  yield waitForSubprocessExit();
+});
+
 </script>
 
 </body>
 </html>