native messaging is slow

RESOLVED FIXED in Firefox 50

Status

WebExtensions
Untriaged
P2
normal
RESOLVED FIXED
2 years ago
a month ago

People

(Reporter: Jon Wilkes, Assigned: kmag)

Tracking

50 Branch
mozilla50
Dependency tree / graph

Firefox Tracking Flags

(firefox50 fixed)

Details

(Whiteboard: [native messaging] triaged)

MozReview Requests

Submitter Diff Changes Open Issues Last Updated
Loading...
Error loading review requests:

Attachments

(2 attachments)

(Reporter)

Description

2 years ago
Created attachment 8774065 [details]
native-messenger.zip

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:47.0) Gecko/20100101 Firefox/47.0
Build ID: 20160630070928

Steps to reproduce:

I created an extension to test the RTT and throughput of native messaging.


Actual results:

As of this writing, RTT and throughput are poorer than expected.  On my Phenom II machine, throughput is ~90 ms / message and average RTT is about 60 ms / message.


Expected results:

On my machine chromium's throughput is 4.5 ms / message with an average RTT of 1 ms.
(Assignee)

Updated

2 years ago
Assignee: nobody → kmaglione+bmo
Depends on: 1276390

Updated

2 years ago
Priority: -- → P2
Whiteboard: [native messaging] triaged
Jon, when you originally reported this on IRC you also reported that the RTT increased the longer your extension ran, are you still seeing that?
Flags: needinfo?(jon)
(Assignee)

Comment 2

2 years ago
Created attachment 8775859 [details]
Bug 1288912: Add tests for native messaging round trip time.

Review commit: https://reviewboard.mozilla.org/r/67920/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/67920/
Attachment #8775859 - Flags: review?(aswan)
Attachment #8775859 - Flags: review?(aswan) → review+
Comment on attachment 8775859 [details]
Bug 1288912: Add tests for native messaging round trip time.

https://reviewboard.mozilla.org/r/67920/#review65104

::: toolkit/components/extensions/test/xpcshell/test_ext_native_messaging.js:128
(Diff revision 1)
> +                          `${REGKEY}\\${script.name}`, "", manifestPath);
> +      }
> +      break;
> +
> +    default:
> +      ok(false, `Native messaing is not supported on ${AppConstants.platform}`);

You copied my typo over verbatim :-)
(Assignee)

Comment 4

2 years ago
https://reviewboard.mozilla.org/r/67920/#review65104

> You copied my typo over verbatim :-)

Eh. I think it adds charm. Gives the place a nice, lived-in look.
(Assignee)

Updated

2 years ago
Blocks: 1290598

Comment 7

2 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/657d86828018
https://hg.mozilla.org/mozilla-central/rev/6d35194aa0f1
Status: UNCONFIRMED → RESOLVED
Last Resolved: 2 years ago
status-firefox50: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla50
(Reporter)

Comment 8

2 years ago
It's better but still a little wobbly.

> Jon, when you originally reported this on IRC you also reported that
> the RTT increased the longer your extension ran, are you still
> seeing that?

The linear increase in RTT I reported in IRC was caused by simply stuffing messages in a queue faster than Firefox could process them (thus increasing the RTT for the messages that had to wait for all the messages ahead in the queue to be processed).  It was an artifact of the *real* bug, which is that each message took too long to process.

After the above fixes, I now see:

    firefox nightly:
    # of messages 1000 messages
    total time    8134.81 ms
    throughput    8.13 ms per message
    minimum RTT   1.57 ms
    maximum RTT   54 ms
    average RTT   3.97 ms
    standard dev  3.38
    weirdos  0

    chromium 51.0.2704.106:
    # of messages 1000 messages
    total time    5231.91 ms
    throughput    5.23 ms per message
    minimum RTT   0.49 ms
    maximum RTT   3.54 ms
    average RTT   1.02 ms
    standard dev  0.19
    weirdos  0

I.e., firefox is now at least in the same ballpark as chromium.

But there's still some wobble.  The standard deviation for firefox shows that some messages other than the first few take longer than expected.  Using the attached sample code and a value of 500 for bookend size, I see, for example that while most messages are processed quickly, some messages took 53 or 54 milliseconds to complete.

    .
    .
    .
    6.06 ms
    4.24 ms
    4.08 ms
    53.32 ms
    54 ms
    7.06 ms
    3.65 ms
    4.15 ms
    .
    .
    .

I notice Kris Maglione's tests contain:

    const MAX_ROUND_TRIP_TIME_MS = AppConstants.DEBUG || AppConstants.ASAN ? 36 : 18;

If I'm right about the wobble, the tests may fail on occasion, depending on the machine.
Flags: needinfo?(jon)
(In reply to Jon Wilkes from comment #8)
> I notice Kris Maglione's tests contain:
> 
>     const MAX_ROUND_TRIP_TIME_MS = AppConstants.DEBUG || AppConstants.ASAN ?
> 36 : 18;
> 
> If I'm right about the wobble, the tests may fail on occasion, depending on
> the machine.

I believe that is the threshold for the average response time of 1000 messages, but you're just seeing individual outliers, not consistently highly RTTs that would pull the average up that high.
(Assignee)

Comment 10

2 years ago
(In reply to Jon Wilkes from comment #8)
> But there's still some wobble.  The standard deviation for firefox shows
> that some messages other than the first few take longer than expected. 
> Using the attached sample code and a value of 500 for bookend size, I see,
> for example that while most messages are processed quickly, some messages
> took 53 or 54 milliseconds to complete.

That's not unexpected. Extensions currently run in the main browser process.
Things like GC and other code executing in the same event loop will cause
aberrations.

> I notice Kris Maglione's tests contain:
> 
>     const MAX_ROUND_TRIP_TIME_MS = AppConstants.DEBUG || AppConstants.ASAN ?
> 36 : 18;
> 
> If I'm right about the wobble, the tests may fail on occasion, depending on
> the machine.

Those numbers have a lot of built-in padding. But even so, the timing in
xpcshell tests is pretty consistent.
(Reporter)

Comment 11

2 years ago
Using Kris Maglione's snazzy sans-setTimeout technique, the discrepancy between throughput and average RTT disappeared.  For the record, here are the new numbers from my machine for Firefox and Chromium:

    Firefox nightly
    # of messages   1000 messages
    total time      2986.02 ms
    1/throughput    2.99 ms per message
    minimum RTT     1.54 ms
    maximum RTT     85.77 ms
    average RTT     2.98 ms
    standard dev    3.35

    Chromium 51.0.2704.106
    # of messages   1000 messages
    total time      422.94 ms
    1/throughput    0.42 ms per message
    minimum RTT     0.22 ms
    maximum RTT     8.15 ms
    average RTT     0.42 ms
    standard dev    0.33

Updated

a month ago
Product: Toolkit → WebExtensions
You need to log in before you can comment on or make changes to this bug.