1426034 - Access to `undefined` is slow in modules loaded via require()

Status: NEW

(Core :: JavaScript Engine, defect, P2)

Description

[Yury Delendik (:yury)]

I was investigating why WasmDisassembler.prototype.printOperator is slow (see https://perfht.ml/2BI7CSE) -- it takes only <5sec in jsshel. However in m-c it takes >16seconds.

Looks like all `undefined` property accesses inside this function (and module) use DoGetNameFallback . By adding `var undefined;` to the top function function, the printOperator function performs way faster (was 16.2 second, now 4.3 sec). See also https://perfht.ml/2BGjmVY

It's is expected that performance of a module loaded via require() will not be affected.

Comment 1

[Luke Wagner [:luke]]

I'm guessing this is related to the merging of JSMs to share a single module by injecting pretend global scopes on the scope chain.

CC'ing some JS folks who know more about the details; maybe there's something we can do to optimize better here b/c this might have a significant overall impact on browser JS perf.

Comment 2

[Jason Laster [:jlast]]

Nice find!

Comment 3

[Ted Campbell [:tcampbell]]

Need info myself to investigate. Non-syntactic environments are not fast in the JITs right now. Previously this affected a subset of loadSubscript uses, now it includes all JSM cases. Some of this perf changes would have been seen in the past turning on and off the compile-and-go feature of B2G days. Realistically I won't get to this until the new year.

I will probably try to finish Bug 1406153 first which should make it easier to mimic various gecko embeddings in the jsshell.

Comment 4

[Jason Orendorff [:jorendorff]]

You know... we could support caching property accesses in dynamic scopes. It has always been considered too *silly* to bother with, not too hard. And it would be effective here.

I mention it because the alternatives are like: figure out which JSMs in our tree require dynamic scopes; whitelist them, and switch all other JSMs to static scoping. It doesn't sound like less work to me.

Comment 5

[Ted Campbell [:tcampbell]]

A lot of the delays are in with environment unscopables checks. These would not have been changed by the JSM sharing work.

In general, require will be slower in gecko because of a whole lot of horrors of the embedding. I'll look at this in the new year and see what sort of low-hanging fruit we can address.

I wasn't able to reproduce it yet because WASM demos keep crashing my nightly, but that is another matter..

Comment 6

[Yury Delendik (:yury)]

STR were:
1. Open debugger panel
2. Open http://webassembly.org/demo/Tanks/
3. Start profiler to capture GeckoMain with large buffer
4. Click source tree to view wasm:blob:http://webassembly.org/3254255b-6f3e-d44a-8d4e-a5e4c72cf945:1d94844895c5ea0e source
5. If applicable, continue on slow script dialog
6. When the source text appears, capture the profile

I optimized WasmDisassembler.prototype.printOperator, so currently it does not take 16 sec however it's still longer than what jsshell shows (and DoGetNameFallback is still visible). To reproduce original "performance", get the older devtools/client/shared/vendor/WasmDis.js file.

Comment 7

[Ted Campbell [:tcampbell]]

Using your STR on Fedora27, I get the following JS errors on a local build: (The source shows as loading forever on local and release builds; on windows and linux)

JavaScript warning: blob:http://webassembly.org/177abf9c-17e9-4584-9d2e-e9ce53fdfe1f, line 2156: unreachable code after return statement
SourceActor threw an exception: [Exception... "Failed to open input source 'file:////webassembly.org/177abf9c-17e9-4584-9d2e-e9ce53fdfe1f'"  nsresult: "0x80520015 (NS_ERROR_FILE_ACCESS_DENIED)"  location: "JS frame :: resource://devtools/shared/base-loader.js -> resource://devtools/shared/DevToolsUtils.js :: mainThreadFetch :: line 640"  data: yes]
Stack: mainThreadFetch@resource://devtools/shared/base-loader.js -> resource://devtools/shared/DevToolsUtils.js:640:5
_getSourceText/<@resource://devtools/shared/base-loader.js -> resource://devtools/server/actors/source.js:404:27
process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:455:5
onSource@resource://devtools/shared/base-loader.js -> resource://devtools/server/actors/source.js:482:12
handler@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:1106:19
onPacket@resource://devtools/shared/base-loader.js -> resource://devtools/server/main.js:1788:15
receiveMessage@resource://devtools/shared/base-loader.js -> resource://devtools/shared/transport/transport.js:761:7
Line: 640, column: 0
console.error: 
  SourceActor threw an exception: [Exception... "Failed to open input source 'file:////webassembly.org/177abf9c-17e9-4584-9d2e-e9ce53fdfe1f'"  nsresult: "0x80520015 (NS_ERROR_FILE_ACCESS_DENIED)"  location: "JS frame :: resource://devtools/shared/base-loader.js -> resource://devtools/shared/DevToolsUtils.js :: mainThreadFetch :: line 640"  data: yes]
Stack: mainThreadFetch@resource://devtools/shared/base-loader.js -> resource://devtools/shared/DevToolsUtils.js:640:5
_getSourceText/<@resource://devtools/shared/base-loader.js -> resource://devtools/server/actors/source.js:404:27
process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:455:5
onSource@resource://devtools/shared/base-loader.js -> resource://devtools/server/actors/source.js:482:12
handler@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:1106:19
onPacket@resource://devtools/shared/base-loader.js -> resource://devtools/server/main.js:1788:15
receiveMessage@resource://devtools/shared/base-loader.js -> resource://devtools/shared/transport/transport.js:761:7
Line: 640, column: 0
console.error: 
  	
  {
console.error: 
  	
      "actor": "server1.conn0.child1/source29",
console.error: 
  	
      "generatedUrl": null,
console.error: 
  	
      "url": "blob:http://webassembly.org/177abf9c-17e9-4584-9d2e-e9ce53fdfe1f",
console.error: 
  	
      "isBlackBoxed": false,
console.error: 
  	
      "isPrettyPrinted": false,
console.error: 
  	
      "isSourceMapped": false,
console.error: 
  	
      "sourceMapURL": null,
console.error: 
  	
      "introductionUrl": null,
console.error: 
  	
      "introductionType": "scriptElement"
console.error: 
  	
  }
console.error: 
  Message: Error: Could not load the source for blob:http://webassembly.org/177abf9c-17e9-4584-9d2e-e9ce53fdfe1f.
[Exception... "Failed to open input source 'file:////webassembly.org/177abf9c-17e9-4584-9d2e-e9ce53fdfe1f'"  nsresult: "0x80520015 (NS_ERROR_FILE_ACCESS_DENIED)"  location: "JS frame :: resource://devtools/shared/base-loader.js -> resource://devtools/shared/DevToolsUtils.js :: mainThreadFetch :: line 640"  data: yes]
Stack: mainThreadFetch@resource://devtools/shared/base-loader.js -> resource://devtools/shared/DevToolsUtils.js:640:5
_getSourceText/<@resource://devtools/shared/base-loader.js -> resource://devtools/server/actors/source.js:404:27
process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:922:23
walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:455:5
onSource@resource://devtools/shared/base-loader.js -> resource://devtools/server/actors/source.js:482:12
handler@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:1106:19
onPacket@resource://devtools/shared/base-loader.js -> resource://devtools/server/main.js:1788:15
receiveMessage@resource://devtools/shared/base-loader.js -> resource://devtools/shared/transport/transport.js:761:7
Line: 640, column: 0
  Stack:
    onSource/<@resource://devtools/shared/base-loader.js -> resource://devtools/server/actors/source.js:500:15
process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:925:21
walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:455:5
onSource@resource://devtools/shared/base-loader.js -> resource://devtools/server/actors/source.js:482:12
handler@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:1106:19
onPacket@resource://devtools/shared/base-loader.js -> resource://devtools/server/main.js:1788:15
receiveMessage@resource://devtools/shared/base-loader.js -> resource://devtools/shared/transport/transport.js:761:7

onSource/<@resource://devtools/shared/base-loader.js -> resource://devtools/server/actors/source.js:500:15
process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:925:21
walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:455:5
onSource@resource://devtools/shared/base-loader.js -> resource://devtools/server/actors/source.js:482:12
handler@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:1106:19
onPacket@resource://devtools/shared/base-loader.js -> resource://devtools/server/main.js:1788:15
receiveMessage@resource://devtools/shared/base-loader.js -> resource://devtools/shared/transport/transport.js:761:7

Comment 8

[Ted Campbell [:tcampbell]]

Additionally, if it is loading for you. I'd like you to try profiling with the following prefs changed to false.

https://searchfox.org/mozilla-central/rev/137f1b2f434346a0c3756ebfcbdbee4069e15dc8/devtools/client/shared/browser-loader.js#115
https://searchfox.org/mozilla-central/rev/137f1b2f434346a0c3756ebfcbdbee4069e15dc8/devtools/shared/Loader.jsm#65

I'm exploring removing this for all of devtools since Bug 1186409 should supersede Bug 1013997.

Comment 9

[Ted Campbell [:tcampbell]]

With some help from Yury, I am able to reproduce now. I need to make sure the debugger is open before the WASM runs, and I need to select the wasm:// resource and not the blob:// resource.

The error in Comment 7 still occurs for me if I use the blob:// resource. I'll open that as a separate bug later.