Slow on startup when enable Hermes #5

leegeunhyeok · 2023-08-13T14:25:34Z

Description

On debug build(Android, iOS), Slow on startup.

To reproduce

Start dev server & build debug application
Run application
After bundle loaded, showing white screen few seconds (slow)

Engine	Android	iOS
JSC	✅	✅
V8 (Debugger Proxy)	✅	✅
Hermes	⚠️	⚠️

Log

+ import com.facebook.react.bridge.ReactMarker;
+ import com.facebook.react.bridge.ReactMarkerConstants;

public class MainApplication extends Application implements ReactApplication  {
+ private class MarkerListener implements ReactMarker.MarkerListener {
+   @Override
+   public void logMarker(ReactMarkerConstants name, @Nullable String tag, int instanceKey) {
+     Log.i("ReactMarker", name.toString() + ": " + tag);
+   }
+ }

  @Override
  public void onCreate() {
    super.onCreate();
+   ReactMarker.addListener(new MarkerListener());
  }
}

metro

# 1st NATIVE_MODULE_SETUP_START: 2023-08-13 22:46:43.427
# 2nd NATIVE_MODULE_SETUP_START: 2023-08-13 22:46:43.446
# 3rd NATIVE_MODULE_SETUP_START: 2023-08-13 22:46:43.469
# ...
# last NATIVE_MODULE_SETUP_START: 2023-08-13 22:46:50.204
#
# total: > 10s

2023-08-13 22:46:43.427 15920-16289 ReactMarker             com.application                  I  NATIVE_MODULE_SETUP_START: PlatformConstants
2023-08-13 22:46:43.428 15920-16289 ReactMarker             com.application                  I  GET_CONSTANTS_START: PlatformConstants
2023-08-13 22:46:43.428 15920-16289 ReactMarker             com.application                  I  CREATE_MODULE_START: PlatformConstants
2023-08-13 22:46:43.428 15920-16289 ReactMarker             com.application                  I  INITIALIZE_MODULE_START: PlatformConstants
2023-08-13 22:46:43.428 15920-16289 ReactMarker             com.application                  I  INITIALIZE_MODULE_END: PlatformConstants
2023-08-13 22:46:43.428 15920-16289 ReactMarker             com.application                  I  CREATE_MODULE_END: PlatformConstants
2023-08-13 22:46:43.430 15920-16289 ReactMarker             com.application                  I  CONVERT_CONSTANTS_START: PlatformConstants
2023-08-13 22:46:43.430 15920-16289 ReactMarker             com.application                  I  CONVERT_CONSTANTS_END: PlatformConstants
2023-08-13 22:46:43.430 15920-16289 ReactMarker             com.application                  I  GET_CONSTANTS_END: PlatformConstants
2023-08-13 22:46:43.433 15920-16289 ReactMarker             com.application                  I  NATIVE_MODULE_SETUP_END: PlatformConstants
2023-08-13 22:46:43.446 15920-16289 ReactMarker             com.application                  I  NATIVE_MODULE_SETUP_START: Timing
2023-08-13 22:46:43.446 15920-16289 ReactMarker             com.application                  I  GET_CONSTANTS_START: Timing
2023-08-13 22:46:43.446 15920-16289 ReactMarker             com.application                  I  CREATE_MODULE_START: Timing
2023-08-13 22:46:43.447 15920-16289 ReactMarker             com.application                  I  INITIALIZE_MODULE_START: Timing
2023-08-13 22:46:43.447 15920-16289 ReactMarker             com.application                  I  INITIALIZE_MODULE_END: Timing
2023-08-13 22:46:43.447 15920-16289 ReactMarker             com.application                  I  CREATE_MODULE_END: Timing
2023-08-13 22:46:43.447 15920-16289 ReactMarker             com.application                  I  CONVERT_CONSTANTS_START: Timing
2023-08-13 22:46:43.447 15920-16289 ReactMarker             com.application                  I  CONVERT_CONSTANTS_END: Timing
2023-08-13 22:46:43.447 15920-16289 ReactMarker             com.application                  I  GET_CONSTANTS_END: Timing
2023-08-13 22:46:43.448 15920-16289 ReactMarker             com.application                  I  NATIVE_MODULE_SETUP_END: Timing
2023-08-13 22:46:43.469 15920-16289 ReactMarker             com.application                  I  NATIVE_MODULE_SETUP_START: AppState
2023-08-13 22:46:43.469 15920-16289 ReactMarker             com.application                  I  GET_CONSTANTS_START: AppState
2023-08-13 22:46:43.469 15920-16289 ReactMarker             com.application                  I  CREATE_MODULE_START: AppState
2023-08-13 22:46:43.470 15920-16289 ReactMarker             com.application                  I  INITIALIZE_MODULE_START: AppState
2023-08-13 22:46:43.470 15920-16289 ReactMarker             com.application                  I  INITIALIZE_MODULE_END: AppState
2023-08-13 22:46:43.470 15920-16289 ReactMarker             com.application                  I  CREATE_MODULE_END: AppState
2023-08-13 22:46:43.470 15920-16289 ReactMarker             com.application                  I  CONVERT_CONSTANTS_START: AppState
2023-08-13 22:46:43.470 15920-16289 ReactMarker             com.application                  I  CONVERT_CONSTANTS_END: AppState
2023-08-13 22:46:43.470 15920-16289 ReactMarker             com.application                  I  GET_CONSTANTS_END: AppState
2023-08-13 22:46:43.470 15920-16289 ReactMarker             com.application                  I  NATIVE_MODULE_SETUP_END: AppState

react-native-esbuild

# 1st NATIVE_MODULE_SETUP_START: 2023-08-13 22:48:21.471
# 2nd NATIVE_MODULE_SETUP_START: 2023-08-13 22:48:21.856
# 3rd NATIVE_MODULE_SETUP_START: 2023-08-13 22:48:22.419
# ...
# last NATIVE_MODULE_SETUP_START: 2023-08-13 22:49:59.077
#
# total: about 100s (depends on native modules count)

2023-08-13 22:48:21.471 17029-17241 ReactMarker             com.application                  I  NATIVE_MODULE_SETUP_START: PlatformConstants
2023-08-13 22:48:21.472 17029-17241 ReactMarker             com.application                  I  GET_CONSTANTS_START: PlatformConstants
2023-08-13 22:48:21.472 17029-17241 ReactMarker             com.application                  I  CREATE_MODULE_START: PlatformConstants
2023-08-13 22:48:21.472 17029-17241 ReactMarker             com.application                  I  INITIALIZE_MODULE_START: PlatformConstants
2023-08-13 22:48:21.472 17029-17241 ReactMarker             com.application                  I  INITIALIZE_MODULE_END: PlatformConstants
2023-08-13 22:48:21.472 17029-17241 ReactMarker             com.application                  I  CREATE_MODULE_END: PlatformConstants
2023-08-13 22:48:21.474 17029-17241 ReactMarker             com.application                  I  CONVERT_CONSTANTS_START: PlatformConstants
2023-08-13 22:48:21.474 17029-17241 ReactMarker             com.application                  I  CONVERT_CONSTANTS_END: PlatformConstants
2023-08-13 22:48:21.474 17029-17241 ReactMarker             com.application                  I  GET_CONSTANTS_END: PlatformConstants
2023-08-13 22:48:21.517 17029-17241 ReactMarker             com.application                  I  NATIVE_MODULE_SETUP_END: PlatformConstants
2023-08-13 22:48:21.856 17029-17241 ReactMarker             com.application                  I  NATIVE_MODULE_SETUP_START: Timing
2023-08-13 22:48:21.856 17029-17241 ReactMarker             com.application                  I  GET_CONSTANTS_START: Timing
2023-08-13 22:48:21.856 17029-17241 ReactMarker             com.application                  I  CREATE_MODULE_START: Timing
2023-08-13 22:48:21.856 17029-17241 ReactMarker             com.application                  I  INITIALIZE_MODULE_START: Timing
2023-08-13 22:48:21.857 17029-17241 ReactMarker             com.application                  I  INITIALIZE_MODULE_END: Timing
2023-08-13 22:48:21.857 17029-17241 ReactMarker             com.application                  I  CREATE_MODULE_END: Timing
2023-08-13 22:48:21.857 17029-17241 ReactMarker             com.application                  I  CONVERT_CONSTANTS_START: Timing
2023-08-13 22:48:21.857 17029-17241 ReactMarker             com.application                  I  CONVERT_CONSTANTS_END: Timing
2023-08-13 22:48:21.857 17029-17241 ReactMarker             com.application                  I  GET_CONSTANTS_END: Timing
2023-08-13 22:48:21.857 17029-17241 ReactMarker             com.application                  I  NATIVE_MODULE_SETUP_END: Timing
2023-08-13 22:48:22.419 17029-17241 ReactMarker             com.application                  I  NATIVE_MODULE_SETUP_START: AppState
2023-08-13 22:48:22.419 17029-17241 ReactMarker             com.application                  I  GET_CONSTANTS_START: AppState
2023-08-13 22:48:22.419 17029-17241 ReactMarker             com.application                  I  CREATE_MODULE_START: AppState
2023-08-13 22:48:22.419 17029-17241 ReactMarker             com.application                  I  INITIALIZE_MODULE_START: AppState
2023-08-13 22:48:22.419 17029-17241 ReactMarker             com.application                  I  INITIALIZE_MODULE_END: AppState
2023-08-13 22:48:22.419 17029-17241 ReactMarker             com.application                  I  CREATE_MODULE_END: AppState
2023-08-13 22:48:22.419 17029-17241 ReactMarker             com.application                  I  CONVERT_CONSTANTS_START: AppState
2023-08-13 22:48:22.419 17029-17241 ReactMarker             com.application                  I  CONVERT_CONSTANTS_END: AppState
2023-08-13 22:48:22.419 17029-17241 ReactMarker             com.application                  I  GET_CONSTANTS_END: AppState
2023-08-13 22:48:22.420 17029-17241 ReactMarker             com.application                  I  NATIVE_MODULE_SETUP_END: AppState

References

Similar issue: Android application becomes super slow on startup after enabling Hermes facebook/react-native#30750
NativeModules[[Get]]
- NativeModules is proxy that linked with native.
- Native Proxy: https://github.com/facebook/react-native/blob/v0.72.0/packages/react-native/ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp#L30-L55
- getModule: https://github.com/facebook/react-native/blob/v0.72.0/packages/react-native/ReactCommon/jsiexecutor/jsireact/JSINativeModules.cpp#L28-L61
- createModule: https://github.com/facebook/react-native/blob/v0.72.0/packages/react-native/ReactCommon/jsiexecutor/jsireact/JSINativeModules.cpp#L68-L101
Hermes:Debug: using HermesExecutorDebug context.
Hermes:Debug + Chrome Debugging Mode: using ProxyJavaScriptExecutor context.
- Execute bundle from chrome v8 engine
Slow evaluation code position: https://github.com/facebook/react-native/blob/v0.72.0/packages/react-native/Libraries/BatchedBridge/NativeModules.js#L28-L83
- delayed at enqueueNativeCall (native: callNativeModules)
- delayed at callNativeSyncHook (native: nativeCallSyncHook)
Inject from: https://github.com/facebook/react-native/blob/v0.72.0/packages/react-native/ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp#L91-L122
nativeCallSyncHook: https://github.com/facebook/react-native/blob/v0.72.0/packages/react-native/ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp#L467-L526
callNativeModules: https://github.com/facebook/react-native/blob/v0.72.0/packages/react-native/ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp#L404-L418

The text was updated successfully, but these errors were encountered:

leegeunhyeok · 2023-08-22T05:56:30Z

Notes

Performance issues on Hermes

var __esm = (fn2, res) => function __init() {
  return fn2 && (res = (0, fn2[__getOwnPropNames(fn2)[0]])(fn2 = 0)), res;
  // ---------------------------------------------------- ^ slow here
};

var __commonJS = (cb, mod) => function __require2() {
  // ------------------------ ^ slow here
  return mod || (0, cb[__getOwnPropNames(cb)[0]])((mod = { exports: {} }).exports, mod), mod.exports;
  // ------------------------------------------- ^ slow here
};

Performance graph

initializeCore: 1.5s
node_modules/react-native-gesture-handler/src/index.ts: 3.58s
node_modules/@apollo/client/main.cjs: 8.1s

Reason

~~Too many module calls.~~
Useless repeated imports when using external modules evanw/esbuild#475

leegeunhyeok · 2023-09-19T14:32:41Z

Updates

Reason: Hermes didn't optimize nested module calls in inner scope(not a global scope).
- Works fine on global context but, inner context isn't (for eg. wrap with iife)

Trobleshooting

Hermes flags: -O -dump-bytecode
Code A: ❌ Initialize on inner context (current, wrapped with iife)
- Every module wrappers are store to inner context(StoreToEnvironment) and when call module wrappers, get each own environment(GetEnvironment) and load value from scopes(LoadFromEnvironment)
- It can be nested -> poor performance on search modules
Code B: ✅ Initialize on global context (unwrap iife, works fine!)
- Every module wrappers are store to global context with own id(PutById) and when call module wrappers, get value with id(GetByIdShort) in global context.
- Get modules from global context using id

Test Code

Code A

(() => {
  var __getOwnPropNames = Object.getOwnPropertyNames;
  var __commonJS = (cb, mod) => function __require2() {
    return mod || (0, cb[__getOwnPropNames(cb)[0]])((mod = { exports: {} }).exports, mod), mod.exports;
  };
  
  var require_sub_module_1 = __commonJS({
    "sub_module_1"(exports, module) {
      "use strict";
      module.exports = "sub-1";
    }
  });
  
  var require_sub_module_2 = __commonJS({
    "sub_module_2"(exports, module) {
      "use strict";
      module.exports = "sub-2";
    }
  });
  
  var require_sub_module_3 = __commonJS({
    "sub_module_3"(exports, module) {
      "use strict";
      module.exports = "sub-3";
    }
  });
  
  
  var require_main_module = __commonJS({
    "main-module" (exports, module) {
      "use strict";
  
      var sub_1 = require_sub_module_1();
      var sub_2 = require_sub_module_2();
      var sub_3 = require_sub_module_3();
  
      module.exports = () => {
        return sub_1 + sub_2 + sub_3;
      };
    }
  });
  
  var main_module = require_main_module();
  print(main_module());  
})();

Code B

var __getOwnPropNames = Object.getOwnPropertyNames;
var __commonJS = (cb, mod) => function __require2() {
  return mod || (0, cb[__getOwnPropNames(cb)[0]])((mod = { exports: {} }).exports, mod), mod.exports;
};

var require_sub_module_1 = __commonJS({
  "sub_module_1"(exports, module) {
    "use strict";
    module.exports = "sub-1";
  }
});

var require_sub_module_2 = __commonJS({
  "sub_module_2"(exports, module) {
    "use strict";
    module.exports = "sub-2";
  }
});

var require_sub_module_3 = __commonJS({
  "sub_module_3"(exports, module) {
    "use strict";
    module.exports = "sub-3";
  }
});


var require_main_module = __commonJS({
  "main-module" (exports, module) {
    "use strict";

    var sub_1 = require_sub_module_1();
    var sub_2 = require_sub_module_2();
    var sub_3 = require_sub_module_3();

    module.exports = () => {
      return sub_1 + sub_2 + sub_3;
    };
  }
});

var main_module = require_main_module();
print(main_module());

Hermes Bytecode

Code A: ❌ Initialize on inner context (current, wrapped with iife)

Bytecode File Information:
  Bytecode version number: 95
  Source hash: 8b1ea71fa8f01099388d7a8cb912c9a227788f0f
  Function count: 9
  String count: 15
  BigInt count: 0
  String Kind Entry count: 2
  RegExp count: 0
  Segment ID: 0
  CommonJS module count: 0
  CommonJS module count (static): 0
  Function source count: 0
  Bytecode options:
    staticBuiltins: 0
    cjsModulesStaticallyResolved: 0

Global String Table:
s0[ASCII, 0..-1]: 
s1[ASCII, 0..9]: __commonJS
s2[ASCII, 10..19]: __require2
s3[ASCII, 20..25]: global
s4[ASCII, 42..46]: sub-1
s5[ASCII, 65..69]: sub-2
s6[ASCII, 70..74]: sub-3
i7[ASCII, 26..36] #41EEA7AB: main-module
i8[ASCII, 36..42] #C765D706: exports
i9[ASCII, 47..65] #24A84FD3: getOwnPropertyNames
i10[ASCII, 75..80] #9615E9FA: Object
i11[ASCII, 81..85] #A689F65B: print
i12[ASCII, 86..97] #25F04B35: sub_module_1
i13[ASCII, 98..109] #25F077C4: sub_module_2
i14[ASCII, 110..121] #25F073D7: sub_module_3

Function<global>(1 params, 9 registers, 0 symbols):
Offset in debug table: source 0x0000, scope 0x0000, textified callees 0x0000
    CreateEnvironment r0
    CreateClosure     r1, r0, NCFunction<>
    LoadConstUndefined r0
    Call1             r1, r1, r0
    Ret               r0

NCFunction<>(1 params, 14 registers, 4 symbols):
Offset in debug table: source 0x000a, scope 0x0000, textified callees 0x0000
    CreateEnvironment r4
    GetGlobalObject   r2
    TryGetById        r0, r2, 1, "Object"
    GetByIdShort      r0, r0, 2, "getOwnPropertyNam"...
    StoreToEnvironment r4, 0, r0
    CreateClosure     r3, r4, NCFunction<__commonJS>
    NewObject         r1
    CreateClosure     r0, r4, Function<sub_module_1>
    PutNewOwnByIdShort r1, r0, "sub_module_1"
    LoadConstUndefined r0
    Call2             r1, r3, r0, r1
+   StoreToEnvironment r4, 1, r1
    NewObject         r1
    CreateClosure     r5, r4, Function<sub_module_2>
    PutNewOwnByIdShort r1, r5, "sub_module_2"
    Call2             r1, r3, r0, r1
+   StoreToEnvironment r4, 2, r1
    NewObject         r1
    CreateClosure     r5, r4, Function<sub_module_3>
    PutNewOwnByIdShort r1, r5, "sub_module_3"
    Call2             r1, r3, r0, r1
+   StoreToEnvironment r4, 3, r1
    NewObject         r1
    CreateClosure     r4, r4, Function<main-module>
    PutNewOwnByIdShort r1, r4, "main-module"
    Call2             r1, r3, r0, r1
    Call1             r1, r1, r0
    TryGetById        r2, r2, 3, "print"
    Call1             r1, r1, r0
    Call2             r1, r2, r0, r1
    Ret               r0

NCFunction<__commonJS>(3 params, 2 registers, 2 symbols):
    CreateEnvironment r0
    LoadParam         r1, 1
    StoreToEnvironment r0, 0, r1
    CreateClosure     r0, r0, Function<__require2>
    Ret               r0

Function<__require2>(1 params, 14 registers, 0 symbols):
Offset in debug table: source 0x0054, scope 0x0000, textified callees 0x0000
    GetEnvironment    r0, 0
    LoadFromEnvironment r1, r0, 1
    JmpTrue           L1, r1
    LoadFromEnvironment r2, r0, 0
    GetEnvironment    r1, 1
    LoadFromEnvironment r1, r1, 0
    LoadConstUndefined r4
    Call2             r3, r1, r4, r2
    LoadConstZero     r1
    GetByVal          r1, r3, r1
    GetByVal          r3, r2, r1
    NewObject         r1
    NewObject         r2
    PutNewOwnByIdShort r1, r2, "exports"
    StoreToEnvironment r0, 1, r1
    GetByIdShort      r2, r1, 1, "exports"
    LoadFromEnvironment r1, r0, 1
    Call3             r1, r3, r4, r2, r1
L1:
    LoadFromEnvironment r0, r0, 1
    GetByIdShort      r0, r0, 1, "exports"
    Ret               r0

Function<sub_module_1>(3 params, 2 registers, 0 symbols):
Offset in debug table: source 0x0097, scope 0x0000, textified callees 0x0000
    LoadConstString   r1, "sub-1"
    LoadParam         r0, 2
    PutById           r0, r1, 1, "exports"
    LoadConstUndefined r0
    Ret               r0

Function<sub_module_2>(3 params, 2 registers, 0 symbols):
Offset in debug table: source 0x00a4, scope 0x0000, textified callees 0x0000
    LoadConstString   r1, "sub-2"
    LoadParam         r0, 2
    PutById           r0, r1, 1, "exports"
    LoadConstUndefined r0
    Ret               r0

Function<sub_module_3>(3 params, 2 registers, 0 symbols):
Offset in debug table: source 0x00b1, scope 0x0000, textified callees 0x0000
    LoadConstString   r1, "sub-3"
    LoadParam         r0, 2
    PutById           r0, r1, 1, "exports"
    LoadConstUndefined r0
    Ret               r0

Function<main-module>(3 params, 11 registers, 3 symbols):
Offset in debug table: source 0x00be, scope 0x0000, textified callees 0x0000
    CreateEnvironment r1
    GetEnvironment    r2, 0
+   LoadFromEnvironment r3, r2, 1
    LoadConstUndefined r0
    Call1             r3, r3, r0
    StoreToEnvironment r1, 0, r3
+   LoadFromEnvironment r3, r2, 2
    Call1             r3, r3, r0
    StoreToEnvironment r1, 1, r3
+   LoadFromEnvironment r2, r2, 3
    Call1             r2, r2, r0
    StoreToEnvironment r1, 2, r2
    CreateClosure     r2, r1, NCFunction<>
    LoadParam         r1, 2
    PutById           r1, r2, 1, "exports"
    Ret               r0

NCFunction<>(1 params, 3 registers, 0 symbols):
Offset in debug table: source 0x00d6, scope 0x0000, textified callees 0x0000
    GetEnvironment    r0, 0
    LoadFromEnvironment r2, r0, 0
    LoadFromEnvironment r1, r0, 1
    Add               r1, r2, r1
    LoadFromEnvironment r0, r0, 2
    Add               r0, r1, r0
    Ret               r0

Debug filename table:
  0: /tmp/hermes-input.js

Debug file table:
  source table offset 0x0000: filename id 0

Debug source table:
  0x0000  function idx 0, starts at line 1 col 1
    bc 9: line 45 col 3 scope offset 0x0000 env r1
  0x000a  function idx 1, starts at line 1 col 2
    bc 4: line 2 col 27 scope offset 0x0000 env r0
    bc 10: line 2 col 33 scope offset 0x0000 env r0
    bc 31: line 7 col 41 scope offset 0x0000 env r0
    bc 37: line 7 col 40 scope offset 0x0000 env r1
    bc 53: line 14 col 41 scope offset 0x0000 env r5
    bc 57: line 14 col 40 scope offset 0x0000 env r1
    bc 73: line 21 col 41 scope offset 0x0000 env r5
    bc 77: line 21 col 40 scope offset 0x0000 env r1
    bc 93: line 29 col 40 scope offset 0x0000 env r4
    bc 97: line 29 col 39 scope offset 0x0000 env r1
    bc 102: line 43 col 40 scope offset 0x0000 env r1
    bc 106: line 44 col 3 scope offset 0x0000 env r2
    bc 112: line 44 col 20 scope offset 0x0000 env r1
    bc 116: line 44 col 8 scope offset 0x0000 env r1
  0x0054  function idx 3, starts at line 3 col 33
    bc 23: line 4 col 43 scope offset 0x0000 env none
    bc 30: line 4 col 47 scope offset 0x0000 env none
    bc 34: line 4 col 25 scope offset 0x0000 env none
    bc 42: line 4 col 60 scope offset 0x0000 env none
    bc 50: line 4 col 76 scope offset 0x0000 env none
    bc 59: line 4 col 52 scope offset 0x0000 env none
    bc 69: line 4 col 95 scope offset 0x0000 env none
  0x0097  function idx 4, starts at line 8 col 5
    bc 7: line 10 col 22 scope offset 0x0000 env none
  0x00a4  function idx 5, starts at line 15 col 5
    bc 7: line 17 col 22 scope offset 0x0000 env none
  0x00b1  function idx 6, starts at line 22 col 5
    bc 7: line 24 col 22 scope offset 0x0000 env none
  0x00be  function idx 7, starts at line 30 col 5
    bc 11: line 33 col 39 scope offset 0x0000 env r3
    bc 23: line 34 col 39 scope offset 0x0000 env r3
    bc 35: line 35 col 39 scope offset 0x0000 env r2
    bc 51: line 37 col 22 scope offset 0x0000 env r1
  0x00d6  function idx 8, starts at line 37 col 24
    bc 11: line 38 col 16 scope offset 0x0000 env none
    bc 19: line 38 col 16 scope offset 0x0000 env none
  0x00ec  end of debug source table

Debug scope descriptor table:
  0x0000  lexical parent:   none, flags:    , variable count: 0
  0x0003  end of debug scope descriptor table

Textified callees table:
  0x0000  entries: 0
  0x0001  end of textified callees table

Debug string table:
  0x0000  end of debug string table

Code B: ✅ Initialize on global context (unwrap iife, works fine!)

Bytecode File Information:
  Bytecode version number: 95
  Source hash: d33282c5b78070be99c66c84ba1d7fc9d4cdd73f
  Function count: 8
  String count: 21
  BigInt count: 0
  String Kind Entry count: 2
  RegExp count: 0
  Segment ID: 0
  CommonJS module count: 0
  CommonJS module count (static): 0
  Function source count: 0
  Bytecode options:
    staticBuiltins: 0
    cjsModulesStaticallyResolved: 0

Global String Table:
s0[ASCII, 0..-1]: 
s1[ASCII, 0..9]: __require2
s2[ASCII, 10..15]: global
s3[ASCII, 32..36]: sub-1
s4[ASCII, 53..57]: sub-2
s5[ASCII, 76..80]: sub-3
i6[ASCII, 16..32] #F8F3D015: __getOwnPropNames
i7[ASCII, 37..47] #41EEA7AB: main-module
i8[ASCII, 47..53] #C765D706: exports
i9[ASCII, 58..76] #24A84FD3: getOwnPropertyNames
i10[ASCII, 81..86] #9615E9FA: Object
i11[ASCII, 87..96] #1CA2411B: __commonJS
i12[ASCII, 97..115] #71FCFA56: require_main_module
i13[ASCII, 105..115] #2A42DFC4: main_module
i14[ASCII, 116..120] #A689F65B: print
i15[ASCII, 121..140] #FF28719D: require_sub_module_1
i16[ASCII, 129..140] #25F04B35: sub_module_1
i17[ASCII, 141..160] #FF284D6C: require_sub_module_2
i18[ASCII, 149..160] #25F077C4: sub_module_2
i19[ASCII, 161..180] #FF28497B: require_sub_module_3
i20[ASCII, 169..180] #25F073D7: sub_module_3

Function<global>(1 params, 14 registers, 0 symbols):
Offset in debug table: source 0x0000, scope 0x0000, textified callees 0x0000
    DeclareGlobalVar  "__getOwnPropNames"
    DeclareGlobalVar  "__commonJS"
    DeclareGlobalVar  "require_sub_modul"...
    DeclareGlobalVar  "require_sub_modul"...
    DeclareGlobalVar  "require_sub_modul"...
    DeclareGlobalVar  "require_main_modu"...
    DeclareGlobalVar  "main_module"
    CreateEnvironment r4
    GetGlobalObject   r0
    TryGetById        r1, r0, 1, "Object"
    GetByIdShort      r1, r1, 2, "getOwnPropertyNam"...
    PutById           r0, r1, 1, "__getOwnPropNames"
    CreateClosure     r1, r4, NCFunction<__commonJS>
    PutById           r0, r1, 2, "__commonJS"
    GetByIdShort      r3, r0, 3, "__commonJS"
    NewObject         r1
    CreateClosure     r2, r4, Function<sub_module_1>
    PutNewOwnByIdShort r1, r2, "sub_module_1"
    LoadConstUndefined r2
    Call2             r1, r3, r2, r1
+   PutById           r0, r1, 3, "require_sub_modul"...
    GetByIdShort      r3, r0, 3, "__commonJS"
    NewObject         r1
    CreateClosure     r5, r4, Function<sub_module_2>
    PutNewOwnByIdShort r1, r5, "sub_module_2"
    Call2             r1, r3, r2, r1
+   PutById           r0, r1, 4, "require_sub_modul"...
    GetByIdShort      r3, r0, 3, "__commonJS"
    NewObject         r1
    CreateClosure     r5, r4, Function<sub_module_3>
    PutNewOwnByIdShort r1, r5, "sub_module_3"
    Call2             r1, r3, r2, r1
+   PutById           r0, r1, 5, "require_sub_modul"...
    GetByIdShort      r3, r0, 3, "__commonJS"
    NewObject         r1
    CreateClosure     r4, r4, Function<main-module>
    PutNewOwnByIdShort r1, r4, "main-module"
    Call2             r1, r3, r2, r1
    PutById           r0, r1, 6, "require_main_modu"...
    GetByIdShort      r1, r0, 4, "require_main_modu"...
    Call1             r1, r1, r2
    PutById           r0, r1, 7, "main_module"
    TryGetById        r1, r0, 5, "print"
    GetByIdShort      r0, r0, 6, "main_module"
    Call1             r0, r0, r2
    Call2             r0, r1, r2, r0
    Ret               r0

NCFunction<__commonJS>(3 params, 2 registers, 2 symbols):
    CreateEnvironment r0
    LoadParam         r1, 1
    StoreToEnvironment r0, 0, r1
    LoadParam         r1, 2
    StoreToEnvironment r0, 1, r1
    CreateClosure     r0, r0, Function<__require2>
    Ret               r0

Function<__require2>(1 params, 14 registers, 0 symbols):
Offset in debug table: source 0x008b, scope 0x0000, textified callees 0x0000
    GetEnvironment    r0, 0
    LoadFromEnvironment r1, r0, 1
    JmpTrue           L1, r1
    LoadFromEnvironment r2, r0, 0
    GetGlobalObject   r1
    GetByIdShort      r1, r1, 1, "__getOwnPropNames"
    LoadConstUndefined r4
    Call2             r3, r1, r4, r2
    LoadConstZero     r1
    GetByVal          r1, r3, r1
    GetByVal          r3, r2, r1
    NewObject         r1
    NewObject         r2
    PutNewOwnByIdShort r1, r2, "exports"
    StoreToEnvironment r0, 1, r1
    GetByIdShort      r2, r1, 2, "exports"
    LoadFromEnvironment r1, r0, 1
    Call3             r1, r3, r4, r2, r1
L1:
    LoadFromEnvironment r0, r0, 1
    GetByIdShort      r0, r0, 2, "exports"
    Ret               r0

Function<sub_module_1>(3 params, 2 registers, 0 symbols):
Offset in debug table: source 0x00d7, scope 0x0000, textified callees 0x0000
    LoadConstString   r1, "sub-1"
    LoadParam         r0, 2
    PutById           r0, r1, 1, "exports"
    LoadConstUndefined r0
    Ret               r0

Function<sub_module_2>(3 params, 2 registers, 0 symbols):
Offset in debug table: source 0x00e4, scope 0x0000, textified callees 0x0000
    LoadConstString   r1, "sub-2"
    LoadParam         r0, 2
    PutById           r0, r1, 1, "exports"
    LoadConstUndefined r0
    Ret               r0

Function<sub_module_3>(3 params, 2 registers, 0 symbols):
Offset in debug table: source 0x00f1, scope 0x0000, textified callees 0x0000
    LoadConstString   r1, "sub-3"
    LoadParam         r0, 2
    PutById           r0, r1, 1, "exports"
    LoadConstUndefined r0
    Ret               r0

Function<main-module>(3 params, 11 registers, 3 symbols):
Offset in debug table: source 0x00fe, scope 0x0000, textified callees 0x0000
    CreateEnvironment r1
    GetGlobalObject   r2
+   GetByIdShort      r3, r2, 1, "require_sub_modul"...
    LoadConstUndefined r0
    Call1             r3, r3, r0
    StoreToEnvironment r1, 0, r3
+   GetByIdShort      r3, r2, 2, "require_sub_modul"...
    Call1             r3, r3, r0
    StoreToEnvironment r1, 1, r3
+   GetByIdShort      r2, r2, 3, "require_sub_modul"...
    Call1             r2, r2, r0
    StoreToEnvironment r1, 2, r2
    CreateClosure     r2, r1, NCFunction<>
    LoadParam         r1, 2
    PutById           r1, r2, 1, "exports"
    Ret               r0

NCFunction<>(1 params, 3 registers, 0 symbols):
Offset in debug table: source 0x0125, scope 0x0000, textified callees 0x0000
    GetEnvironment    r0, 0
    LoadFromEnvironment r2, r0, 0
    LoadFromEnvironment r1, r0, 1
    Add               r1, r2, r1
    LoadFromEnvironment r0, r0, 2
    Add               r0, r1, r0
    Ret               r0

Debug filename table:
  0: /tmp/hermes-input.js

Debug file table:
  source table offset 0x0000: filename id 0

Debug source table:
  0x0000  function idx 0, starts at line 1 col 1
    bc 39: line 1 col 25 scope offset 0x0000 env r1
    bc 45: line 1 col 31 scope offset 0x0000 env r1
    bc 50: line 1 col 23 scope offset 0x0000 env r1
    bc 61: line 2 col 16 scope offset 0x0000 env r1
    bc 67: line 6 col 28 scope offset 0x0000 env r3
    bc 79: line 6 col 39 scope offset 0x0000 env r2
    bc 85: line 6 col 38 scope offset 0x0000 env r1
    bc 90: line 6 col 26 scope offset 0x0000 env r1
    bc 96: line 13 col 28 scope offset 0x0000 env r3
    bc 108: line 13 col 39 scope offset 0x0000 env r5
    bc 112: line 13 col 38 scope offset 0x0000 env r1
    bc 117: line 13 col 26 scope offset 0x0000 env r1
    bc 123: line 20 col 28 scope offset 0x0000 env r3
    bc 135: line 20 col 39 scope offset 0x0000 env r5
    bc 139: line 20 col 38 scope offset 0x0000 env r1
    bc 144: line 20 col 26 scope offset 0x0000 env r1
    bc 150: line 28 col 27 scope offset 0x0000 env r3
    bc 162: line 28 col 38 scope offset 0x0000 env r4
    bc 166: line 28 col 37 scope offset 0x0000 env r1
    bc 171: line 28 col 25 scope offset 0x0000 env r1
    bc 177: line 42 col 19 scope offset 0x0000 env r1
    bc 182: line 42 col 38 scope offset 0x0000 env r1
    bc 186: line 42 col 17 scope offset 0x0000 env r1
    bc 192: line 43 col 1 scope offset 0x0000 env r1
    bc 198: line 43 col 7 scope offset 0x0000 env r0
    bc 203: line 43 col 18 scope offset 0x0000 env r0
    bc 207: line 43 col 6 scope offset 0x0000 env r0
  0x008b  function idx 2, starts at line 2 col 31
    bc 16: line 3 col 24 scope offset 0x0000 env none
    bc 23: line 3 col 41 scope offset 0x0000 env none
    bc 30: line 3 col 45 scope offset 0x0000 env none
    bc 34: line 3 col 23 scope offset 0x0000 env none
    bc 42: line 3 col 58 scope offset 0x0000 env none
    bc 50: line 3 col 74 scope offset 0x0000 env none
    bc 59: line 3 col 50 scope offset 0x0000 env none
    bc 69: line 3 col 93 scope offset 0x0000 env none
  0x00d7  function idx 3, starts at line 7 col 3
    bc 7: line 9 col 20 scope offset 0x0000 env none
  0x00e4  function idx 4, starts at line 14 col 3
    bc 7: line 16 col 20 scope offset 0x0000 env none
  0x00f1  function idx 5, starts at line 21 col 3
    bc 7: line 23 col 20 scope offset 0x0000 env none
  0x00fe  function idx 6, starts at line 29 col 3
    bc 4: line 32 col 17 scope offset 0x0000 env r3
    bc 11: line 32 col 37 scope offset 0x0000 env r3
    bc 19: line 33 col 17 scope offset 0x0000 env r3
    bc 24: line 33 col 37 scope offset 0x0000 env r3
    bc 32: line 34 col 17 scope offset 0x0000 env r2
    bc 37: line 34 col 37 scope offset 0x0000 env r2
    bc 53: line 36 col 20 scope offset 0x0000 env r1
  0x0125  function idx 7, starts at line 36 col 22
    bc 11: line 37 col 14 scope offset 0x0000 env none
    bc 19: line 37 col 14 scope offset 0x0000 env none
  0x013b  end of debug source table

Debug scope descriptor table:
  0x0000  lexical parent:   none, flags:    , variable count: 0
  0x0003  end of debug scope descriptor table

Textified callees table:
  0x0000  entries: 0
  0x0001  end of textified callees table

Debug string table:
  0x0000  end of debug string table

Test Result (on Production project)

Before (__require2 + __init, > 8000ms)
After (__require2 + __init, < 1000ms)

Action Items

Change bundle format to esm in Esbuild configuration (iife to esm for unwrap iife)

- in local scope(iife), poor performance on hermes runtime - remove iife for modules initialize on global scope - change esbuild bundle format iife to esm for remove iife close #5

leegeunhyeok added the bug Something isn't working label Aug 13, 2023

leegeunhyeok self-assigned this Aug 13, 2023

leegeunhyeok changed the title ~~Slow on startup when NATIVE_MODULE_SETUP_START~~ Slow on startup when enable Hermes Aug 15, 2023

leegeunhyeok mentioned this issue Aug 25, 2023

[Question] 궁금한 점 질문 드립니다 #6

Closed

leegeunhyeok mentioned this issue Sep 19, 2023

Unwrap IIFE for hermes optimization #7

Merged

leegeunhyeok closed this as completed in #7 Sep 19, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Slow on startup when enable Hermes #5

Slow on startup when enable Hermes #5

leegeunhyeok commented Aug 13, 2023 •

edited

leegeunhyeok commented Aug 22, 2023 •

edited

leegeunhyeok commented Sep 19, 2023 •

edited

Slow on startup when enable Hermes #5

Slow on startup when enable Hermes #5

Comments

leegeunhyeok commented Aug 13, 2023 • edited

Description

To reproduce

Log

References

leegeunhyeok commented Aug 22, 2023 • edited

Notes

Reason

leegeunhyeok commented Sep 19, 2023 • edited

Updates

Trobleshooting

Action Items

leegeunhyeok commented Aug 13, 2023 •

edited

leegeunhyeok commented Aug 22, 2023 •

edited

leegeunhyeok commented Sep 19, 2023 •

edited