1272522 - Handle native app output on stderr

Status: RESOLVED FIXED

(WebExtensions :: Untriaged, defect)

Description

[Andrew Swan [:aswan]]

The Chrome documentation for native messaging says:
> When the native messaging host [...] writes to stderr [...], output is written to the error log of Chrome.

To implement this, we'll need a change to the interface to read() / readString() on the InputPipe class in subprocess so that we can do a read of an unspecified size (which should give us a promise that resolves immediately whenever data is available with whatever data is available at that moment).

Comment 1

[Andrew Swan [:aswan]]

Attachment: Bug 1272522 Handle stderr of native app

Review commit: https://reviewboard.mozilla.org/r/59570/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/59570/

Comment 2

[Kris Maglione [:kmag]]

Comment on attachment 8763408 [details]
Bug 1272522 Handle stderr of native app

https://reviewboard.mozilla.org/r/59570/#review56852

::: toolkit/components/extensions/NativeMessaging.jsm:274
(Diff revision 1)
> +      return proc.stderr.readString().then(data => {
> +        if (data.length == 0) {
> +          // We have hit EOF, just stop reading
> +          return;
> +        }
> +        Services.console.logStringMessage(`stderr output from native app ${app}: ${data}`);

This may a bit of overkill, but I think we should only log chunks up to the last `\n` (and strip any trailing `\r?\n`), and then buffer the rest for the next chunk.

It may not be an issue in practice, but since stderr is generally unbuffered, we're not unlikely to wind up with several chunks that make up a single line. I wouldn't be entirely surprised if we wound up getting stack traces that are bigger than the buffer size either, for that matter.

Also, I think this would be a bit easier to follow as an async function, as in [1], rather than as recursive promise handlers.

[1]: http://gecko.readthedocs.io/en/latest/toolkit/modules/subprocess/toolkit_modules/subprocess/index.html#process-and-pipe-lifecycles

::: toolkit/components/extensions/test/mochitest/test_chrome_ext_native_messaging.html:580
(Diff revision 1)
> +
> +    return {messages, result};
> +  } finally {
> +    Services.console.unregisterListener(listener);
> +  }
> +});

Can you move this to `head.js`?

Comment 3

[Andrew Swan [:aswan]]

Comment on attachment 8763408 [details]
Bug 1272522 Handle stderr of native app

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/59570/diff/1-2/

Comment 4

[Andrew Swan [:aswan]]

https://reviewboard.mozilla.org/r/59570/#review56852

> This may a bit of overkill, but I think we should only log chunks up to the last `\n` (and strip any trailing `\r?\n`), and then buffer the rest for the next chunk.
> 
> It may not be an issue in practice, but since stderr is generally unbuffered, we're not unlikely to wind up with several chunks that make up a single line. I wouldn't be entirely surprised if we wound up getting stack traces that are bigger than the buffer size either, for that matter.
> 
> Also, I think this would be a bit easier to follow as an async function, as in [1], rather than as recursive promise handlers.
> 
> [1]: http://gecko.readthedocs.io/en/latest/toolkit/modules/subprocess/toolkit_modules/subprocess/index.html#process-and-pipe-lifecycles

Did you mean an actual js async function?  My understanding is we don't support those yet, the bug to support them has not yet been resolved.
I rewrote it with Task.spawn() which does seem cleaner, apologies if I'm misunderstanding your comment...

Comment 5

[Kris Maglione [:kmag]]

Comment on attachment 8763408 [details]
Bug 1272522 Handle stderr of native app

https://reviewboard.mozilla.org/r/59570/#review58448

::: toolkit/components/extensions/NativeMessaging.jsm:274
(Diff revision 2)
> +      let partial = "";
> +      while (true) {
> +        let data = yield proc.stderr.readString();
> +        if (data.length == 0) {
> +          // We have hit EOF, just stop reading
> +          if (partial.length > 0) {

`if (partial) ...`

::: toolkit/components/extensions/NativeMessaging.jsm:281
(Diff revision 2)
> +          }
> +          break;
> +        }
> +
> +        let lines = data.split(/\r?\n/);
> +        if (partial.length > 0) {

This check is unnecessary. If `partial` is an empty string, prepending it has no effect.

::: toolkit/components/extensions/test/mochitest/head.js:19
(Diff revision 2)
>  }
> +
> +var promiseConsoleOutput = Task.async(function* (task) {
> +  const DONE = "=== extension test console listener done ===";
> +
> +  let listener, messages = [];

One declaration per line, please.

::: toolkit/components/extensions/test/mochitest/test_chrome_ext_native_messaging.html:575
(Diff revision 2)
> +    yield extension.awaitMessage("finished");
> +    yield extension.unload();
> +  });
> +
> +  let found = messages.filter(msg => msg.includes(STDERR_MSG));
> +  is(found.length, 1, "Saw stderr message on the console");

Should write a multi-line message and make sure we get multiple messages.

Comment 6

[Andrew Swan [:aswan]]

Comment on attachment 8763408 [details]
Bug 1272522 Handle stderr of native app

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/59570/diff/2-3/

Comment 7

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d4379d1513fd
Handle stderr of native app r=kmag

Comment 8

[Andrew Swan [:aswan]]

Attachment: Temporarily fix bustage

Kris, I'm going to be offline most of the day, can you land this
if it looks okay?  The first version of this broke since there was
a reference to Components.utils in head.js which is shared between
regular and chrome mochitests.  There's probably a more elegant
way to handle this but this is just to fix the breakage in the
short term.  I also need to look at the Windows failures, again
this is just to fix the breakage until then.

MozReview-Commit-ID: D5on2N7iMz7

Comment 9

[Carsten Book [:Tomcat]]

backed out for breaking tests like  https://treeherder.mozilla.org/logviewer.html#?job_id=197468&repo=autoland

Comment 10

[Pulsebot]

Backout by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/f11c5f94798a
Backed out changeset d4379d1513fd for failures in test_ext_alarms.html

Comment 11

[Andrew Swan [:aswan]]

Comment on attachment 8763408 [details]
Bug 1272522 Handle stderr of native app

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/59570/diff/3-4/

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/1aa56f978ec8
Handle stderr of native app r=kmag

Comment 13

[Andrew Swan [:aswan]]

Attachment: Bug 1272522 Apply windows test hack to all windows versions

Review commit: https://reviewboard.mozilla.org/r/63004/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/63004/

Comment 14

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/1aa56f978ec8