824495 - Date.now() and performance.now() both very slow

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect, P3)

Description

[Vladimir Vukicevic [:vlad] [:vladv] (needinfo me, slow to respond)]

(This is probably split between JS & DOM, given the APIs)

window.performance.now() is 6x slower than calling Date.now() (windows 7 platform)

Date.now() is in turn 4x slower than Chrome's Date.now().

Chrome's performance.now() is equally 5x slower than their Date.now(), but their perf.now() is 5x faster than our perf.now() to begin with!

See http://jsperf.com/timing for a testcase.  (Note: I don't know if either browser is smart enough to ignore the calls since the return value is ignored..)

Anything we can fix here?  I realize this is very microbenchmarky and we're probably talking nanoseconds difference, but it's still a big percentage difference.

Comment 1

[Boris Zbarsky [:bzbarsky]]

This really depends on the OS.

On Mac, on the linked testcase, I get 430 ops/s for window.performance.now(), and 23,548 ops/s for Date.now() in a current nightly.

For comparison, Chrome on the same hardware gives me 4,198 runs/s for window.performance.now() and 14,315 runs/s for Date.now().

Converting to actual runtimes, that means Date.now() is taking about 42ns on my hardware and OS, while window.performance.now() is taking 2326ns(!).  For Chrome, those numbers are 70ns and 238ns respectively.

What do the numbers look like on your Win7 setup?

Past that, we really need profiles.  Date.now() is all JS engine, but performance.now() is JS engine, DOM bindings, and our TimeStamp code, so mostly not JS engine...

Comment 2

[Boris Zbarsky [:bzbarsky]]

That said, I just did a quick profile on Mac and the overwhelming majority of the time I see for window.performance.now is the expected proxy overhead, at least once I quickstub the property (which it's not right now; I filed bug 824517).  We're calling into outer window proxies, calling the window resolve hook, and all the usual insanity.  Which makes sense; the 2us time is about what I expect out of getting stuff off the window.  :(  Just the fact that we have to re-resolve on every get through the outer window proxy is killing us.

And if I change the testcase to use bareword "performance", things get a bit faster, but then ion::GetNameCache ends up calling lookupName, which calls the resolve hook over and over.  The resolve hook (still on Mac) is taking like 60% of the time at that point.  Why exactly is that happening once the property has been resolved the first time???

But in any case, I'm curious as to how you're only seeing a 5x difference between window.performance.now() and Date.now() on Windows.  Is the time there dominated by asking the OS for the time or something?  Again, would be interested in what the absolute numbers look like for you.

Comment 3

[Vladimir Vukicevic [:vlad] [:vladv] (needinfo me, slow to respond)]

Different windows machine right now, but the numbers look similar:

perf.now():  403 ops/sec
Date.now(): 2852 ops/sec

I have no idea why Date.now() is 10x slower than yours.  I guess I have a profiler to answer questions like that.

Comment 4

[Vladimir Vukicevic [:vlad] [:vladv] (needinfo me, slow to respond)]

On Windows, mystery partially solved:

97.7% date_now
95.5%  PRMJ_Now
78.7%   ZwQuerySystemInformation
 4.5%   PRMJ_Now
 3.4%   RtlEnterCriticalSection
 2.8%   RtlLeaveCriticalSection
 1.7%   RtlQueryPerformanceCounter
 0.6%   GetSystemTimeAsFileTimeStub
 0.6%   GetSystemTimeAsFileTime

What.  I suspect we're missing some data that allows us to walk the stack of the NT symbols; I'm not sure what we're calling that's doing ZwQuerySystemInformation, but it could be underneath any of the OS functions.

https://mxr.mozilla.org/mozilla-central/source/js/src/prmjtime.cpp#211

The win32 code is very complex, as the comment at the start of it says, referencing bug 363258.

Comment 5

[Boris Zbarsky [:bzbarsky]]

Ok, yeah.  The Windows Date.now is in fact gated on all the weird "make it return useful numbers" stuff...  But clearly that's not the gating factor on your performance.now() so far.

Making the window.performance get faster is bug 709452.

The ion behavior on bareword "performance" is annoying, though I can see why it's happening.  I filed bug 824522 on that.

One interesting test to do is to separate the window insanity from the actual cost of the now() call.  I set up a test at http://jsperf.com/timing/2 that does just that; compare the first, 5th, and 6th snippets.  For me, on Mac, the "perf.now with perf a var" test is just as fast as Date.now(), about 3.5x faster than Chrome.  What do you see on Windows?

Comment 6

[Vladimir Vukicevic [:vlad] [:vladv] (needinfo me, slow to respond)]

Oh wow, yeah.  So in your testcase with a cached 'perf' var, I get 17,264 ops/sec.  performance.now() is the same speed as window.performance.now().  With the cached perf var it's way faster than the fastest Chrome op (which is Date.now() -- we should look at their Date.now() impl on Windows).

For comparison:

                        Firefox   Chrome
window.performance.now()    448     3877
Date.now()                 2913    11966*
(new Date()).getTime()     2299     6156
performance.now()           437     6722
perf.now()                17264*    8316

With * being the fastest timing for each.  At least we're more consistent than Chrome ;)

Comment 7

[Boris Zbarsky [:bzbarsky]]

OK, so sounds like we have two separate things going on:

1)  Date.now() on Windows is slow.
2)  Window's getters are total performance fail, whether going through the "window" proxy
    or not.  That's basically bug 709452 for the proxy case and bug 824522 or bug 824524
    for the bareword case.

Comment 9

[Jan de Mooij [:jandem]]

This should be way better now. Bug 1004923 made Date.now() a lot faster, and Ion also improved (not sure it affects this). It'd be interesting to try this with a recent m-c/m-i build (can't do it myself atm; not near a non-virtual Windows machine).

Comment 10

[Boris Zbarsky [:bzbarsky]]

I just tested again on Windows.  In Firefox 29, on this bug's testcase, I see:

  window.performance.now(): 1,151 runs/s
  Date.now(): 2,707 runs/s

In a nightly including the fix for bug 1004923 I see (note that some of this includes general DOM/Ion wins):

  window.performance.now(): 1,665 runs/s
  Date.now(): 11,131 runs/s

In a Chrome dev build, I see:

  window.performance.now(): 5,866 runs/s
  Date.now(): 7,736 runs/s

If I modify the testcase to use "performance.now()" instead of "window.performance.now()", which you can see at <http://jsperf.com/timing/4>, I get in the nightly:

  performance.now(): 4,897 runs/s

and in Chrome:

  performance.now): 5,954 runs/s

so the main gating factor there is the slowness of property lookups on the window proxy.  :(  That's covered by bug 964915.

Comment 11

[Boris Zbarsky [:bzbarsky]]

And if I use a WebIDL-Window build, then on the http://jsperf.com/timing/4 testcase I get 5,748 runs/s, fwiw.

That's about 173ns per call.  I did test, and just the performance getter runs at 21,600 runs/s, which is about 47ns per call.  Still seems a bit slow to me, but clearly not the main gating factor.

Comment 12

[Guilherme Lima]

On Windows 7

Nightly 32.0a1 (2014-05-28)
window.performance.now(): 4200 ops/s
date.now(): 8550 ops/s
(new Date()).getTime(): 3500 ops/s
performance.now(): 4800 ops/s

Chrome 35
window.performance.now(): 5500 ops/s
date.now(): 6600 ops/s
(new Date()).getTime(): 3600 ops/s
performance.now(): 5600 ops/s

Internet Explorer 11
window.performance.now(): 900 ops/s
date.now(): 2800 ops/s
(new Date()).getTime(): 2100 ops/s
performance.now(): 900 ops/s

Comment 13

[Vladimir Vukicevic [:vlad] [:vladv] (needinfo me, slow to respond)]

Those numbers look reasonable (modulo performance.now() being 15% slower than Chrome), what fixed this? bug 964915?

Comment 14

[:Gijs (he/him)]

(In reply to Vladimir Vukicevic [:vlad] [:vladv] from comment #13)
> Those numbers look reasonable (modulo performance.now() being 15% slower
> than Chrome), what fixed this? bug 964915?

Would webidl'ifying windows have anything to do with this? (bug 789261 )

Comment 15

[Benjamin Bouvier [:bbouvier] (inactive)]

Probably thanks to bug 1004923

Comment 16

[Boris Zbarsky [:bzbarsky]]

Bug 964915 made "window.performance" faster.

Bug 789261 made both that and bareword "performance" faster.

Bug 1004923 made Date.now() faster.

For what it's worth, on Mac I see numbers like so on http://jsperf.com/timing/6 :

Current nightly:
window.performance.now(): 14,500 ops/s
date.now(): 24,000 ops/s
(new Date()).getTime(): 9,500 ops/s
performance.now(): 17,700 ops/s
perf.now: 26,300 ops/s

Chrome 37 dev:
window.performance.now(): 6,000 ops/s
date.now(): 10,700 ops/s
(new Date()).getTime(): 6,300 ops/s
performance.now(): 6,000 ops/s
perf.now: 8,800 ops/s

so the slowdown compared to Chrome on performance.now() in Windows is _probably_ due to the actual TimeStamp impl, not the DOM/JIT bits.  That said, we do have some headroom on the JS/JIT stuff (compare the "performance.now" number to the "perf.now" number) still.  Right now, on Mac on my hardware, we can do a performance.now() in about 56ns and a perf.now() in about 38ns.  So that's 18ns we could try to shave off if really needed.

Comment 17

[Boris Zbarsky [:bzbarsky]]

I filed bug 1017425 on making window.performance even faster.