From aa5850369b943ab46ea77db26b936e997a69a7c6 Mon Sep 17 00:00:00 2001 From: Ramanpreet Nara Date: Wed, 13 May 2020 19:18:56 -0700 Subject: [PATCH 1/7] Introduce NativeModulePerfLogger Summary: ## Description This diff introduces `NativeModulePerfLogger`, its BUCK, Cocoapod, android-ndk targets. This diff also wires up those targets into the React Native bridge and TurboModules targets, so that we get signal on if the code compiles. This diff also introduces `TurboModulePerfLogger`, which is a namespace that holds the `NativeModulePerfLogger` that'll do perf-logging for TurboModules. ## How will perflogging work on iOS? 1. Each application will, during React Native initialization, create a NativeModule perf logger. 2. If TurboModules are enabled, we'll call `TurboModulePerfLogger::setInstance(perfLogger)`. If TurboModules are disabled, we'll call `NativeModulePerfLogger::setInstance(perfLogger)`. 3. TurboModules, when they're created and used, will log events via `TurboModulePerfLogger::getInstance()`. NativeModules (i.e: bridge modules), when they're created and used, will log events via the `NativeModulePerfLogger::getInstance()`. > **Note:** The NativeModule system will log events for non-TurboModules as well. Maybe we should log events for only NativeModules that conform to the `TurboModule` interface, when TurboModules are disabled. This'll ensure a fair comparison between the two systems. ## How will perflogging work on Android? Please see the subsequent diff. Changelog: [Both][Added] - Introduce `NativeModulePerfLogger` Differential Revision: D21318053 fbshipit-source-id: 518116228bf55c4b674b0339343f92f77ebf8921 --- RNTester/Podfile.lock | 27 ++- React-Core.podspec | 1 + .../src/main/jni/react/jni/Android.mk | 1 + ReactCommon/ReactCommon.podspec | 1 + ReactCommon/perflogger/.clang-tidy | 5 + ReactCommon/perflogger/Android.mk | 25 +++ ReactCommon/perflogger/BUCK | 35 ++++ .../perflogger/React-perflogger.podspec | 34 ++++ .../ReactCommon/NativeModulePerfLogger.cpp | 144 +++++++++++++++ .../ReactCommon/NativeModulePerfLogger.h | 165 ++++++++++++++++++ ReactCommon/turbomodule/core/BUCK | 2 + .../core/TurboModulePerfLogger.cpp | 27 +++ .../turbomodule/core/TurboModulePerfLogger.h | 22 +++ scripts/react_native_pods.rb | 1 + 14 files changed, 488 insertions(+), 2 deletions(-) create mode 100644 ReactCommon/perflogger/.clang-tidy create mode 100644 ReactCommon/perflogger/Android.mk create mode 100644 ReactCommon/perflogger/BUCK create mode 100644 ReactCommon/perflogger/React-perflogger.podspec create mode 100644 ReactCommon/perflogger/ReactCommon/NativeModulePerfLogger.cpp create mode 100644 ReactCommon/perflogger/ReactCommon/NativeModulePerfLogger.h create mode 100644 ReactCommon/turbomodule/core/TurboModulePerfLogger.cpp create mode 100644 ReactCommon/turbomodule/core/TurboModulePerfLogger.h diff --git a/RNTester/Podfile.lock b/RNTester/Podfile.lock index f19e86f52a71..09cde73049f2 100644 --- a/RNTester/Podfile.lock +++ b/RNTester/Podfile.lock @@ -99,6 +99,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/ARTHeaders (1000.0.0): - Folly (= 2020.01.13.00) @@ -107,6 +108,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/CoreModulesHeaders (1000.0.0): - Folly (= 2020.01.13.00) @@ -115,6 +117,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/Default (1000.0.0): - Folly (= 2020.01.13.00) @@ -122,6 +125,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/DevSupport (1000.0.0): - Folly (= 2020.01.13.00) @@ -132,6 +136,7 @@ PODS: - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) - React-jsinspector (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/RCTActionSheetHeaders (1000.0.0): - Folly (= 2020.01.13.00) @@ -140,6 +145,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/RCTAnimationHeaders (1000.0.0): - Folly (= 2020.01.13.00) @@ -148,6 +154,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/RCTBlobHeaders (1000.0.0): - Folly (= 2020.01.13.00) @@ -156,6 +163,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/RCTImageHeaders (1000.0.0): - Folly (= 2020.01.13.00) @@ -164,6 +172,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/RCTLinkingHeaders (1000.0.0): - Folly (= 2020.01.13.00) @@ -172,6 +181,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/RCTNetworkHeaders (1000.0.0): - Folly (= 2020.01.13.00) @@ -180,6 +190,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/RCTPushNotificationHeaders (1000.0.0): - Folly (= 2020.01.13.00) @@ -188,6 +199,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/RCTSettingsHeaders (1000.0.0): - Folly (= 2020.01.13.00) @@ -196,6 +208,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/RCTTextHeaders (1000.0.0): - Folly (= 2020.01.13.00) @@ -204,6 +217,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/RCTVibrationHeaders (1000.0.0): - Folly (= 2020.01.13.00) @@ -212,6 +226,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-Core/RCTWebSocket (1000.0.0): - Folly (= 2020.01.13.00) @@ -220,6 +235,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsiexecutor (= 1000.0.0) + - React-perflogger (= 1000.0.0) - Yoga - React-CoreModules (1000.0.0): - FBReactNativeSpec (= 1000.0.0) @@ -255,6 +271,7 @@ PODS: - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) - React-jsinspector (1000.0.0) + - React-perflogger (1000.0.0) - React-RCTActionSheet (1000.0.0): - React-Core/RCTActionSheetHeaders (= 1000.0.0) - React-RCTAnimation (1000.0.0): @@ -329,6 +346,7 @@ PODS: - React-Core (= 1000.0.0) - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) + - React-perflogger (= 1000.0.0) - ReactCommon/turbomodule/samples (1000.0.0): - DoubleConversion - Folly (= 2020.01.13.00) @@ -337,6 +355,7 @@ PODS: - React-Core (= 1000.0.0) - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) + - React-perflogger (= 1000.0.0) - ReactCommon/turbomodule/core (= 1000.0.0) - Yoga (1.14.0) - YogaKit (1.18.1): @@ -380,6 +399,7 @@ DEPENDENCIES: - React-jsi (from `../ReactCommon/jsi`) - React-jsiexecutor (from `../ReactCommon/jsiexecutor`) - React-jsinspector (from `../ReactCommon/jsinspector`) + - React-perflogger (from `../ReactCommon/perflogger`) - React-RCTActionSheet (from `../Libraries/ActionSheetIOS`) - React-RCTAnimation (from `../Libraries/NativeAnimation`) - React-RCTBlob (from `../Libraries/Blob`) @@ -444,6 +464,8 @@ EXTERNAL SOURCES: :path: "../ReactCommon/jsiexecutor" React-jsinspector: :path: "../ReactCommon/jsinspector" + React-perflogger: + :path: "../ReactCommon/perflogger" React-RCTActionSheet: :path: "../Libraries/ActionSheetIOS" React-RCTAnimation: @@ -495,12 +517,13 @@ SPEC CHECKSUMS: React: cafb3c2321f7df55ce90dbf29d513799a79e4418 React-ART: df0460bdff42ef039e28ee3ffd41f50b75644788 React-callinvoker: 0dada022d38b73e6e15b33e2a96476153f79bbf6 - React-Core: 08c69f013e6fd654ea8f9fd84bbd66780a54d886 + React-Core: d85e4563acbfbb6e6be7414a813ad55d05d675df React-CoreModules: d13d148c851af5780f864be74bc2165140923dc7 React-cxxreact: b43a94e679b307660de530a3af872ab4c7d9925d React-jsi: fe94132da767bfc4801968c2a12abae43e9a833e React-jsiexecutor: 55eff40b2e0696e7a979016e321793ec8b28a2ac React-jsinspector: 7fbf9b42b58b02943a0d89b0ba9fff0070f2de98 + React-perflogger: d32d3423e466a825ef2e9934fe9d62b149e5d9f8 React-RCTActionSheet: 51c43beeb74ef41189e87fe9823e53ebf6210359 React-RCTAnimation: 9d09196c641c1ebfef3a4e9ae670bcda5fadb420 React-RCTBlob: 715489626cf44d28ee51e5277a4d559167351696 @@ -513,7 +536,7 @@ SPEC CHECKSUMS: React-RCTText: 6c01963d3e562109f5548262b09b1b2bc260dd60 React-RCTVibration: d42d73dafd9f63cf758656ee743aa80c566798ff React-runtimeexecutor: 60dd6204a13f68a1aa1118870edcc604a791df2b - ReactCommon: 39e00b754f5e1628804fab28f44146d06280f700 + ReactCommon: 511b4a9ea129c129c6dbc982942007d195903a9a Yoga: f7fa200d8c49f97b54c9421079e781fb900b5cae YogaKit: f782866e155069a2cca2517aafea43200b01fd5a diff --git a/React-Core.podspec b/React-Core.podspec index cf65263fbdd0..35ff5a6ae6f4 100644 --- a/React-Core.podspec +++ b/React-Core.podspec @@ -94,6 +94,7 @@ Pod::Spec.new do |s| s.dependency "Folly", folly_version s.dependency "React-cxxreact", version + s.dependency "React-perflogger", version s.dependency "React-jsi", version s.dependency "React-jsiexecutor", version s.dependency "Yoga" diff --git a/ReactAndroid/src/main/jni/react/jni/Android.mk b/ReactAndroid/src/main/jni/react/jni/Android.mk index dabd4b7c5125..8939df568142 100644 --- a/ReactAndroid/src/main/jni/react/jni/Android.mk +++ b/ReactAndroid/src/main/jni/react/jni/Android.mk @@ -69,6 +69,7 @@ $(call import-module,cxxreact) $(call import-module,jsi) $(call import-module,jsiexecutor) $(call import-module,callinvoker) +$(call import-module,perflogger) $(call import-module,hermes) $(call import-module,runtimeexecutor) diff --git a/ReactCommon/ReactCommon.podspec b/ReactCommon/ReactCommon.podspec index 765ec10e6b88..b8cd4043acc1 100644 --- a/ReactCommon/ReactCommon.podspec +++ b/ReactCommon/ReactCommon.podspec @@ -38,6 +38,7 @@ Pod::Spec.new do |s| s.subspec "turbomodule" do |ss| ss.dependency "React-callinvoker", version + ss.dependency "React-perflogger", version ss.dependency "React-Core", version ss.dependency "React-cxxreact", version ss.dependency "React-jsi", version diff --git a/ReactCommon/perflogger/.clang-tidy b/ReactCommon/perflogger/.clang-tidy new file mode 100644 index 000000000000..c98fd78ff64b --- /dev/null +++ b/ReactCommon/perflogger/.clang-tidy @@ -0,0 +1,5 @@ +--- +Checks: '> +clang-diagnostic-*, +' +... diff --git a/ReactCommon/perflogger/Android.mk b/ReactCommon/perflogger/Android.mk new file mode 100644 index 000000000000..3e33354bf2d6 --- /dev/null +++ b/ReactCommon/perflogger/Android.mk @@ -0,0 +1,25 @@ +# Copyright (c) Facebook, Inc. and its affiliates. +# +# This source code is licensed under the MIT license found in the +# LICENSE file in the root directory of this source tree. + +LOCAL_PATH := $(call my-dir) + +include $(CLEAR_VARS) + +# Header search path for all source files in this module. +LOCAL_C_INCLUDES := $(LOCAL_PATH)/ReactCommon + +# Header search path for modules that depend on this module +LOCAL_EXPORT_C_INCLUDES := $(LOCAL_PATH) + +LOCAL_CFLAGS += -fexceptions -frtti -std=c++14 -Wall + +# Name of this module. +LOCAL_MODULE := perflogger + +# Compile all local c++ files under ./ReactCommon +LOCAL_SRC_FILES := $(wildcard $(LOCAL_PATH)/ReactCommon/*.cpp) + +# Build the files in this directory as a shared library +include $(BUILD_STATIC_LIBRARY) diff --git a/ReactCommon/perflogger/BUCK b/ReactCommon/perflogger/BUCK new file mode 100644 index 000000000000..6618b210ac73 --- /dev/null +++ b/ReactCommon/perflogger/BUCK @@ -0,0 +1,35 @@ +load("//tools/build_defs/oss:rn_defs.bzl", "ANDROID", "APPLE", "rn_xplat_cxx_library", "subdir_glob") + +rn_xplat_cxx_library( + name = "perflogger", + srcs = glob(["**/*.cpp"]), + header_namespace = "", + exported_headers = subdir_glob( + [ + ("ReactCommon", "*.h"), + ], + prefix = "ReactCommon", + ), + compiler_flags = [ + "-fexceptions", + "-frtti", + "-std=c++14", + "-Wall", + "-Wno-global-constructors", + ], + fbandroid_labels = [ + "supermodule:android/default/public.react_native.infra", + ], + fbobjc_labels = [ + "supermodule:ios/default/public.react_native.infra", + ], + platforms = (ANDROID, APPLE), + preferred_linkage = "static", + preprocessor_flags = [ + "-DLOG_TAG=\"ReactNative\"", + "-DWITH_FBSYSTRACE=1", + ], + visibility = [ + "PUBLIC", + ], +) diff --git a/ReactCommon/perflogger/React-perflogger.podspec b/ReactCommon/perflogger/React-perflogger.podspec new file mode 100644 index 000000000000..3f8808229d80 --- /dev/null +++ b/ReactCommon/perflogger/React-perflogger.podspec @@ -0,0 +1,34 @@ +# Copyright (c) Facebook, Inc. and its affiliates. +# +# This source code is licensed under the MIT license found in the +# LICENSE file in the root directory of this source tree. + +require "json" + +package = JSON.parse(File.read(File.join(__dir__, "..", "..", "package.json"))) +version = package['version'] + +source = { :git => 'https://github.com/facebook/react-native.git' } +if version == '1000.0.0' + # This is an unpublished version, use the latest commit hash of the react-native repo, which we’re presumably in. + source[:commit] = `git rev-parse HEAD`.strip +else + source[:tag] = "v#{version}" +end + +folly_compiler_flags = '-DFOLLY_NO_CONFIG -DFOLLY_MOBILE=1 -DFOLLY_USE_LIBCPP=1 -Wno-comma -Wno-shorten-64-to-32' +folly_version = '2020.01.13.00' +boost_compiler_flags = '-Wno-documentation' + +Pod::Spec.new do |s| + s.name = "React-perflogger" + s.version = version + s.summary = "-" # TODO + s.homepage = "https://reactnative.dev/" + s.license = package["license"] + s.author = "Facebook, Inc. and its affiliates" + s.platforms = { :ios => "10.0", :tvos => "10.0" } + s.source = source + s.source_files = "**/*.{cpp,h}" + s.header_dir = "ReactCommon" +end diff --git a/ReactCommon/perflogger/ReactCommon/NativeModulePerfLogger.cpp b/ReactCommon/perflogger/ReactCommon/NativeModulePerfLogger.cpp new file mode 100644 index 000000000000..ca9e3b1c4c76 --- /dev/null +++ b/ReactCommon/perflogger/ReactCommon/NativeModulePerfLogger.cpp @@ -0,0 +1,144 @@ +/* + * Copyright (c) Facebook, Inc. and its affiliates. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ + +#include "NativeModulePerfLogger.h" + +namespace facebook { +namespace react { + +std::shared_ptr NativeModulePerfLogger::s_perfLogger = + nullptr; + +NativeModulePerfLogger &NativeModulePerfLogger::getInstance() { + static std::shared_ptr defaultPerfLogger = + std::make_shared(); + return s_perfLogger ? *s_perfLogger : *defaultPerfLogger; +} +void NativeModulePerfLogger::setInstance( + std::shared_ptr newPerfLogger) { + s_perfLogger = newPerfLogger; +} + +NativeModulePerfLogger::~NativeModulePerfLogger() {} + +void NativeModulePerfLogger::moduleDataCreateStart( + const char *moduleName, + int32_t id) {} +void NativeModulePerfLogger::moduleDataCreateEnd( + const char *moduleName, + int32_t id) {} + +void NativeModulePerfLogger::moduleCreateStart( + const char *moduleName, + int32_t id) {} +void NativeModulePerfLogger::moduleCreateCacheHit( + const char *moduleName, + int32_t id) {} +void NativeModulePerfLogger::moduleCreateConstructStart( + const char *moduleName, + int32_t id) {} +void NativeModulePerfLogger::moduleCreateConstructEnd( + const char *moduleName, + int32_t id) {} +void NativeModulePerfLogger::moduleCreateSetUpStart( + const char *moduleName, + int32_t id) {} +void NativeModulePerfLogger::moduleCreateSetUpEnd( + const char *moduleName, + int32_t id) {} +void NativeModulePerfLogger::moduleCreateEnd( + const char *moduleName, + int32_t id) {} +void NativeModulePerfLogger::moduleCreateFail( + const char *moduleName, + int32_t id) {} + +void NativeModulePerfLogger::moduleJSRequireBeginningStart( + const char *moduleName) {} +void NativeModulePerfLogger::moduleJSRequireBeginningCacheHit( + const char *moduleName) {} +void NativeModulePerfLogger::moduleJSRequireBeginningEnd( + const char *moduleName) {} +void NativeModulePerfLogger::moduleJSRequireBeginningFail( + const char *moduleName) {} + +void NativeModulePerfLogger::moduleJSRequireEndingStart( + const char *moduleName) {} +void NativeModulePerfLogger::moduleJSRequireEndingEnd(const char *moduleName) {} +void NativeModulePerfLogger::moduleJSRequireEndingFail(const char *moduleName) { +} + +void NativeModulePerfLogger::syncMethodCallStart( + const char *moduleName, + const char *methodName) {} +void NativeModulePerfLogger::syncMethodCallArgConversionStart( + const char *moduleName, + const char *methodName) {} +void NativeModulePerfLogger::syncMethodCallArgConversionEnd( + const char *moduleName, + const char *methodName) {} +void NativeModulePerfLogger::syncMethodCallExecutionStart( + const char *moduleName, + const char *methodName) {} +void NativeModulePerfLogger::syncMethodCallExecutionEnd( + const char *moduleName, + const char *methodName) {} +void NativeModulePerfLogger::syncMethodCallReturnConversionStart( + const char *moduleName, + const char *methodName) {} +void NativeModulePerfLogger::syncMethodCallReturnConversionEnd( + const char *moduleName, + const char *methodName) {} +void NativeModulePerfLogger::syncMethodCallEnd( + const char *moduleName, + const char *methodName) {} +void NativeModulePerfLogger::syncMethodCallFail( + const char *moduleName, + const char *methodName) {} + +void NativeModulePerfLogger::asyncMethodCallStart( + const char *moduleName, + const char *methodName) {} +void NativeModulePerfLogger::asyncMethodCallArgConversionStart( + const char *moduleName, + const char *methodName) {} +void NativeModulePerfLogger::asyncMethodCallArgConversionEnd( + const char *moduleName, + const char *methodName) {} +void NativeModulePerfLogger::asyncMethodCallDispatch( + const char *moduleName, + const char *methodName) {} +void NativeModulePerfLogger::asyncMethodCallEnd( + const char *moduleName, + const char *methodName) {} + +void NativeModulePerfLogger::asyncMethodCallBatchPreprocessStart() {} +void NativeModulePerfLogger::asyncMethodCallBatchPreprocessEnd(int batchSize) {} + +void NativeModulePerfLogger::asyncMethodCallExecutionStart( + const char *moduleName, + const char *methodName, + int32_t id) {} +void NativeModulePerfLogger::asyncMethodCallExecutionArgConversionStart( + const char *moduleName, + const char *methodName, + int32_t id) {} +void NativeModulePerfLogger::asyncMethodCallExecutionArgConversionEnd( + const char *moduleName, + const char *methodName, + int32_t id) {} +void NativeModulePerfLogger::asyncMethodCallExecutionEnd( + const char *moduleName, + const char *methodName, + int32_t id) {} +void NativeModulePerfLogger::asyncMethodCallExecutionFail( + const char *moduleName, + const char *methodName, + int32_t id) {} + +} // namespace react +} // namespace facebook diff --git a/ReactCommon/perflogger/ReactCommon/NativeModulePerfLogger.h b/ReactCommon/perflogger/ReactCommon/NativeModulePerfLogger.h new file mode 100644 index 000000000000..08b04c016549 --- /dev/null +++ b/ReactCommon/perflogger/ReactCommon/NativeModulePerfLogger.h @@ -0,0 +1,165 @@ +/* + * Copyright (c) Facebook, Inc. and its affiliates. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ + +#pragma once +#include + +namespace facebook { +namespace react { + +/** + * A platform-agnostic interface to do performance logging on NativeModules and + * TuboModules. + */ +class NativeModulePerfLogger { + private: + static std::shared_ptr s_perfLogger; + + public: + static NativeModulePerfLogger &getInstance(); + static void setInstance(std::shared_ptr perfLogger); + + virtual ~NativeModulePerfLogger(); + + /** + * NativeModule Initialization. + * + * The initialization of two NativeModules can interleave. Therefore, + * performance markers should use the moduleName as a unique key. + */ + + /** + * On iOS: + * - NativeModule initialization is split into two phases, which sometimes + * have a pause in the middle. + * - TurboModule initialization happens all at once. + * + * On Android: + * - NativeModule and TurboModule initialization happens all at once. + * + * These markers are meant for iOS NativeModules: + * - moduleDataCreateStart: very beginning of first phase. + * - moduleDataCreateEnd: after RCTModuleData has been created. + */ + virtual void moduleDataCreateStart(const char *moduleName, int32_t id); + virtual void moduleDataCreateEnd(const char *moduleName, int32_t id); + + /** + * How long does it take to create the platform NativeModule object? + * - moduleCreateStart: start creating platform NativeModule + * - moduleCreateEnd: stop creating platform NativeModule + */ + virtual void moduleCreateStart(const char *moduleName, int32_t id); + virtual void moduleCreateCacheHit(const char *moduleName, int32_t id); + virtual void moduleCreateConstructStart(const char *moduleName, int32_t id); + virtual void moduleCreateConstructEnd(const char *moduleName, int32_t id); + virtual void moduleCreateSetUpStart(const char *moduleName, int32_t id); + virtual void moduleCreateSetUpEnd(const char *moduleName, int32_t id); + virtual void moduleCreateEnd(const char *moduleName, int32_t id); + virtual void moduleCreateFail(const char *moduleName, int32_t id); + + /** + * How long, after starting JS require, does it take to start creating the + * platform NativeModule? + * - moduleJSRequireBeginningStart: start of JS require + * - moduleJSRequireBeginningEnd: start creating platform NativeModule + */ + virtual void moduleJSRequireBeginningStart(const char *moduleName); + virtual void moduleJSRequireBeginningCacheHit(const char *moduleName); + virtual void moduleJSRequireBeginningEnd(const char *moduleName); + virtual void moduleJSRequireBeginningFail(const char *moduleName); + + /** + * How long does it take to return from the JS require after the platform + * NativeModule is created? + * - moduleJSRequireEndingStart: end creating platform NativeModule + * - moduleJSRequireEndingEnd: end of JS require + */ + virtual void moduleJSRequireEndingStart(const char *moduleName); + virtual void moduleJSRequireEndingEnd(const char *moduleName); + virtual void moduleJSRequireEndingFail(const char *moduleName); + + // Sync method calls + virtual void syncMethodCallStart( + const char *moduleName, + const char *methodName); + virtual void syncMethodCallArgConversionStart( + const char *moduleName, + const char *methodName); + virtual void syncMethodCallArgConversionEnd( + const char *moduleName, + const char *methodName); + virtual void syncMethodCallExecutionStart( + const char *moduleName, + const char *methodName); + virtual void syncMethodCallExecutionEnd( + const char *moduleName, + const char *methodName); + virtual void syncMethodCallReturnConversionStart( + const char *moduleName, + const char *methodName); + virtual void syncMethodCallReturnConversionEnd( + const char *moduleName, + const char *methodName); + virtual void syncMethodCallEnd( + const char *moduleName, + const char *methodName); + virtual void syncMethodCallFail( + const char *moduleName, + const char *methodName); + + // Async method calls + virtual void asyncMethodCallStart( + const char *moduleName, + const char *methodName); + virtual void asyncMethodCallArgConversionStart( + const char *moduleName, + const char *methodName); + virtual void asyncMethodCallArgConversionEnd( + const char *moduleName, + const char *methodName); + virtual void asyncMethodCallDispatch( + const char *moduleName, + const char *methodName); + virtual void asyncMethodCallEnd( + const char *moduleName, + const char *methodName); + + /** + * In the NativeModule system, we batch async NativeModule method calls. + * When we execute a batch of NativeModule method calls, we convert the batch + * from a jsi::Value to folly::dynamic to std::vector. This marker + * documents that work. + */ + virtual void asyncMethodCallBatchPreprocessStart(); + virtual void asyncMethodCallBatchPreprocessEnd(int batchSize); + + // Async method call execution + virtual void asyncMethodCallExecutionStart( + const char *moduleName, + const char *methodName, + int32_t id); + virtual void asyncMethodCallExecutionArgConversionStart( + const char *moduleName, + const char *methodName, + int32_t id); + virtual void asyncMethodCallExecutionArgConversionEnd( + const char *moduleName, + const char *methodName, + int32_t id); + virtual void asyncMethodCallExecutionEnd( + const char *moduleName, + const char *methodName, + int32_t id); + virtual void asyncMethodCallExecutionFail( + const char *moduleName, + const char *methodName, + int32_t id); +}; + +} // namespace react +} // namespace facebook diff --git a/ReactCommon/turbomodule/core/BUCK b/ReactCommon/turbomodule/core/BUCK index af7350e7f2cc..338413ba2a41 100644 --- a/ReactCommon/turbomodule/core/BUCK +++ b/ReactCommon/turbomodule/core/BUCK @@ -18,6 +18,7 @@ rn_xplat_cxx_library( "-frtti", "-std=c++14", "-Wall", + "-Wno-global-constructors", ], fbandroid_deps = [ react_native_target("jni/react/jni:jni"), @@ -80,6 +81,7 @@ rn_xplat_cxx_library( react_native_xplat_target("cxxreact:bridge"), react_native_xplat_target("cxxreact:module"), react_native_xplat_target("callinvoker:callinvoker"), + react_native_xplat_target("perflogger:perflogger"), ], exported_deps = [ "//xplat/jsi:jsi", diff --git a/ReactCommon/turbomodule/core/TurboModulePerfLogger.cpp b/ReactCommon/turbomodule/core/TurboModulePerfLogger.cpp new file mode 100644 index 000000000000..ba9babdb38ca --- /dev/null +++ b/ReactCommon/turbomodule/core/TurboModulePerfLogger.cpp @@ -0,0 +1,27 @@ +/* + * Copyright (c) Facebook, Inc. and its affiliates. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ + +#include "TurboModulePerfLogger.h" + +namespace facebook { +namespace react { +namespace TurboModulePerfLogger { + +std::shared_ptr g_perfLogger = nullptr; + +NativeModulePerfLogger &getInstance() { + static std::shared_ptr defaultPerfLogger = + std::make_shared(); + return g_perfLogger ? *g_perfLogger : *defaultPerfLogger; +} +void setInstance(std::shared_ptr perfLogger) { + g_perfLogger = perfLogger; +} + +} // namespace TurboModulePerfLogger +} // namespace react +} // namespace facebook diff --git a/ReactCommon/turbomodule/core/TurboModulePerfLogger.h b/ReactCommon/turbomodule/core/TurboModulePerfLogger.h new file mode 100644 index 000000000000..354734e94471 --- /dev/null +++ b/ReactCommon/turbomodule/core/TurboModulePerfLogger.h @@ -0,0 +1,22 @@ +/* + * Copyright (c) Facebook, Inc. and its affiliates. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ + +#pragma once + +#include +#include + +namespace facebook { +namespace react { +namespace TurboModulePerfLogger { + +NativeModulePerfLogger &getInstance(); +void setInstance(std::shared_ptr perfLogger); + +} // namespace TurboModulePerfLogger +} // namespace react +} // namespace facebook diff --git a/scripts/react_native_pods.rb b/scripts/react_native_pods.rb index d54c09f34068..6950b6562db4 100644 --- a/scripts/react_native_pods.rb +++ b/scripts/react_native_pods.rb @@ -42,6 +42,7 @@ def use_react_native! (options={}) pod 'React-jsinspector', :path => "#{prefix}/ReactCommon/jsinspector" pod 'React-callinvoker', :path => "#{prefix}/ReactCommon/callinvoker" pod 'React-runtimeexecutor', :path => "#{prefix}/ReactCommon/runtimeexecutor" + pod 'React-perflogger', :path => "#{prefix}/ReactCommon/perflogger" pod 'ReactCommon/turbomodule/core', :path => "#{prefix}/ReactCommon" pod 'Yoga', :path => "#{prefix}/ReactCommon/yoga", :modular_headers => true From ff97662db57b0740ea29358e86db1cbab7541431 Mon Sep 17 00:00:00 2001 From: Ramanpreet Nara Date: Wed, 13 May 2020 19:18:56 -0700 Subject: [PATCH 2/7] Switch TurboModules over to NativeModulePerfLogger Differential Revision: D21363243 fbshipit-source-id: 8abffead99ef935dcc8a3e769a1260815fd5400d --- .../core/platform/ios/RCTTurboModule.h | 118 +---------- .../core/platform/ios/RCTTurboModule.mm | 153 +++++++-------- .../core/platform/ios/RCTTurboModuleManager.h | 9 +- .../platform/ios/RCTTurboModuleManager.mm | 184 ++++++++++-------- 4 files changed, 181 insertions(+), 283 deletions(-) diff --git a/ReactCommon/turbomodule/core/platform/ios/RCTTurboModule.h b/ReactCommon/turbomodule/core/platform/ios/RCTTurboModule.h index 89aa23832b82..42dfd285928a 100644 --- a/ReactCommon/turbomodule/core/platform/ios/RCTTurboModule.h +++ b/ReactCommon/turbomodule/core/platform/ios/RCTTurboModule.h @@ -5,6 +5,8 @@ * LICENSE file in the root directory of this source tree. */ +#pragma once + #import #import @@ -22,101 +24,6 @@ ((RCTTurboModuleEnabled() && [(klass) conformsToProtocol:@protocol(RCTTurboModule)])) #define RCT_IS_TURBO_MODULE_INSTANCE(module) RCT_IS_TURBO_MODULE_CLASS([(module) class]) -typedef int MethodCallId; - -/** - * This interface exists to allow the application to collect performance - * metrics of the TurboModule system. By implementing each function, you can - * hook into various stages of TurboModule creation and method dispatch (both async and sync). - * - * Note: - * - TurboModule async method invocations can interleave, so methodCallId should be used as a unique id for a method - * call. - */ -@protocol RCTTurboModulePerformanceLogger -// Create TurboModule JS Object -- (void)createTurboModuleStart:(const char *)moduleName; -- (void)createTurboModuleEnd:(const char *)moduleName; -- (void)createTurboModuleCacheHit:(const char *)moduleName; -- (void)getCppTurboModuleFromTMMDelegateStart:(const char *)moduleName; -- (void)getCppTurboModuleFromTMMDelegateEnd:(const char *)moduleName; -- (void)getTurboModuleFromRCTTurboModuleStart:(const char *)moduleName; -- (void)getTurboModuleFromRCTTurboModuleEnd:(const char *)moduleName; -- (void)getTurboModuleFromRCTCxxModuleStart:(const char *)moduleName; -- (void)getTurboModuleFromRCTCxxModuleEnd:(const char *)moduleName; -- (void)getTurboModuleFromTMMDelegateStart:(const char *)moduleName; -- (void)getTurboModuleFromTMMDelegateEnd:(const char *)moduleName; - -// Create RCTTurboModule object -- (void)createRCTTurboModuleStart:(const char *)moduleName; -- (void)createRCTTurboModuleEnd:(const char *)moduleName; -- (void)createRCTTurboModuleCacheHit:(const char *)moduleName; -- (void)getRCTTurboModuleClassStart:(const char *)moduleName; -- (void)getRCTTurboModuleClassEnd:(const char *)moduleName; -- (void)getRCTTurboModuleInstanceStart:(const char *)moduleName; -- (void)getRCTTurboModuleInstanceEnd:(const char *)moduleName; -- (void)setupRCTTurboModuleDispatch:(const char *)moduleName; -- (void)setupRCTTurboModuleStart:(const char *)moduleName; -- (void)setupRCTTurboModuleEnd:(const char *)moduleName; -- (void)attachRCTBridgeToRCTTurboModuleStart:(const char *)moduleName; -- (void)attachRCTBridgeToRCTTurboModuleEnd:(const char *)moduleName; -- (void)attachMethodQueueToRCTTurboModuleStart:(const char *)moduleName; -- (void)attachMethodQueueToRCTTurboModuleEnd:(const char *)moduleName; -- (void)registerRCTTurboModuleForFrameUpdatesStart:(const char *)moduleName; -- (void)registerRCTTurboModuleForFrameUpdatesEnd:(const char *)moduleName; -- (void)dispatchDidInitializeModuleNotificationForRCTTurboModuleStart:(const char *)moduleName; -- (void)dispatchDidInitializeModuleNotificationForRCTTurboModuleEnd:(const char *)moduleName; - -// Sync method invocation -- (void)syncMethodCallStart:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)syncMethodCallEnd:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)syncMethodCallArgumentConversionStart:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)syncMethodCallArgumentConversionEnd:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)syncRCTTurboModuleMethodCallStart:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)syncRCTTurboModuleMethodCallEnd:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)syncMethodCallReturnConversionStart:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)syncMethodCallReturnConversionEnd:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; - -// Async method invocation -- (void)asyncMethodCallStart:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)asyncMethodCallEnd:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)asyncMethodCallArgumentConversionStart:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)asyncMethodCallArgumentConversionEnd:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)asyncRCTTurboModuleMethodCallDispatch:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)asyncRCTTurboModuleMethodCallStart:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -- (void)asyncRCTTurboModuleMethodCallEnd:(const char *)moduleName - methodName:(const char *)methodName - methodCallId:(MethodCallId)methodCallId; -@end - namespace facebook { namespace react { @@ -133,7 +40,8 @@ class JSI_EXPORT ObjCTurboModule : public TurboModule { id instance; std::shared_ptr jsInvoker; std::shared_ptr nativeInvoker; - id perfLogger; + // Does the NativeModule dispatch async methods to the JS thread? + bool isSyncModule; }; ObjCTurboModule(const InitParams ¶ms); @@ -159,17 +67,9 @@ class JSI_EXPORT ObjCTurboModule : public TurboModule { */ NSMutableDictionary *methodArgConversionSelectors_; NSDictionary *> *methodArgumentTypeNames_; + const bool isSyncModule_; + bool isMethodSync(TurboModuleMethodValueKind returnType); NSString *getArgumentTypeName(NSString *methodName, int argIndex); - id performanceLogger_; - - /** - * Required for performance logging async method invocations. - * This field is static because two nth async method calls from different - * TurboModules can interleave, and should therefore be treated as two distinct calls. - */ - static MethodCallId methodCallId_; - - static MethodCallId getNewMethodCallId(); NSInvocation *getMethodInvocation( jsi::Runtime &runtime, @@ -178,15 +78,13 @@ class JSI_EXPORT ObjCTurboModule : public TurboModule { SEL selector, const jsi::Value *args, size_t count, - NSMutableArray *retainedObjectsForInvocation, - MethodCallId methodCallId); + NSMutableArray *retainedObjectsForInvocation); jsi::Value performMethodInvocation( jsi::Runtime &runtime, TurboModuleMethodValueKind returnType, const char *methodName, NSInvocation *inv, - NSMutableArray *retainedObjectsForInvocation, - MethodCallId methodCallId); + NSMutableArray *retainedObjectsForInvocation); BOOL hasMethodArgConversionSelector(NSString *methodName, int argIndex); SEL getMethodArgConversionSelector(NSString *methodName, int argIndex); diff --git a/ReactCommon/turbomodule/core/platform/ios/RCTTurboModule.mm b/ReactCommon/turbomodule/core/platform/ios/RCTTurboModule.mm index 221bff76829c..58ef36340257 100644 --- a/ReactCommon/turbomodule/core/platform/ios/RCTTurboModule.mm +++ b/ReactCommon/turbomodule/core/platform/ios/RCTTurboModule.mm @@ -9,6 +9,7 @@ #import #import +#import #import #import @@ -21,9 +22,16 @@ #import #import #import +#import #import -using namespace facebook; +using namespace facebook::react; + +static int32_t getUniqueId() +{ + static int32_t counter = 0; + return counter++; +} /** * All static helper functions are ObjC++ specific. @@ -90,17 +98,15 @@ return jsi::Value::undefined(); } -static id convertJSIValueToObjCObject( - jsi::Runtime &runtime, - const jsi::Value &value, - std::shared_ptr jsInvoker); +static id +convertJSIValueToObjCObject(jsi::Runtime &runtime, const jsi::Value &value, std::shared_ptr jsInvoker); static NSString *convertJSIStringToNSString(jsi::Runtime &runtime, const jsi::String &value) { return [NSString stringWithUTF8String:value.utf8(runtime).c_str()]; } static NSArray * -convertJSIArrayToNSArray(jsi::Runtime &runtime, const jsi::Array &value, std::shared_ptr jsInvoker) +convertJSIArrayToNSArray(jsi::Runtime &runtime, const jsi::Array &value, std::shared_ptr jsInvoker) { size_t size = value.size(runtime); NSMutableArray *result = [NSMutableArray new]; @@ -112,10 +118,8 @@ static id convertJSIValueToObjCObject( return [result copy]; } -static NSDictionary *convertJSIObjectToNSDictionary( - jsi::Runtime &runtime, - const jsi::Object &value, - std::shared_ptr jsInvoker) +static NSDictionary * +convertJSIObjectToNSDictionary(jsi::Runtime &runtime, const jsi::Object &value, std::shared_ptr jsInvoker) { jsi::Array propertyNames = value.getPropertyNames(runtime); size_t size = propertyNames.size(runtime); @@ -131,14 +135,10 @@ static id convertJSIValueToObjCObject( return [result copy]; } -static RCTResponseSenderBlock convertJSIFunctionToCallback( - jsi::Runtime &runtime, - const jsi::Function &value, - std::shared_ptr jsInvoker); -static id convertJSIValueToObjCObject( - jsi::Runtime &runtime, - const jsi::Value &value, - std::shared_ptr jsInvoker) +static RCTResponseSenderBlock +convertJSIFunctionToCallback(jsi::Runtime &runtime, const jsi::Function &value, std::shared_ptr jsInvoker); +static id +convertJSIValueToObjCObject(jsi::Runtime &runtime, const jsi::Value &value, std::shared_ptr jsInvoker) { if (value.isUndefined() || value.isNull()) { return nil; @@ -166,12 +166,10 @@ static id convertJSIValueToObjCObject( throw std::runtime_error("Unsupported jsi::jsi::Value kind"); } -static RCTResponseSenderBlock convertJSIFunctionToCallback( - jsi::Runtime &runtime, - const jsi::Function &value, - std::shared_ptr jsInvoker) +static RCTResponseSenderBlock +convertJSIFunctionToCallback(jsi::Runtime &runtime, const jsi::Function &value, std::shared_ptr jsInvoker) { - auto weakWrapper = react::CallbackWrapper::createWeak(value.getFunction(runtime), runtime, jsInvoker); + auto weakWrapper = CallbackWrapper::createWeak(value.getFunction(runtime), runtime, jsInvoker); BOOL __block wrapperWasCalled = NO; return ^(NSArray *responses) { if (wrapperWasCalled) { @@ -203,7 +201,7 @@ static RCTResponseSenderBlock convertJSIFunctionToCallback( jsi::Value ObjCTurboModule::createPromise( jsi::Runtime &runtime, - std::shared_ptr jsInvoker, + std::shared_ptr jsInvoker, PromiseInvocationBlock invoke) { if (!invoke) { @@ -228,10 +226,8 @@ static RCTResponseSenderBlock convertJSIFunctionToCallback( return jsi::Value::undefined(); } - auto weakResolveWrapper = - react::CallbackWrapper::createWeak(args[0].getObject(rt).getFunction(rt), rt, jsInvoker); - auto weakRejectWrapper = - react::CallbackWrapper::createWeak(args[1].getObject(rt).getFunction(rt), rt, jsInvoker); + auto weakResolveWrapper = CallbackWrapper::createWeak(args[0].getObject(rt).getFunction(rt), rt, jsInvoker); + auto weakRejectWrapper = CallbackWrapper::createWeak(args[1].getObject(rt).getFunction(rt), rt, jsInvoker); __block BOOL resolveWasCalled = NO; __block BOOL rejectWasCalled = NO; @@ -324,15 +320,15 @@ static RCTResponseSenderBlock convertJSIFunctionToCallback( TurboModuleMethodValueKind returnType, const char *methodName, NSInvocation *inv, - NSMutableArray *retainedObjectsForInvocation, - MethodCallId methodCallId) + NSMutableArray *retainedObjectsForInvocation) { __block id result; jsi::Runtime *rt = &runtime; __weak id weakModule = instance_; - id performanceLogger = performanceLogger_; const char *moduleName = name_.c_str(); - const bool isSync = returnType != VoidKind && returnType != PromiseKind; + std::string methodNameStr{methodName}; + __block int32_t asyncCallCounter = 0; + bool wasMethodSync = isMethodSync(returnType); void (^block)() = ^{ if (!weakModule) { @@ -341,40 +337,45 @@ static RCTResponseSenderBlock convertJSIFunctionToCallback( id strongModule = weakModule; - if (isSync) { - [performanceLogger syncRCTTurboModuleMethodCallStart:moduleName methodName:methodName methodCallId:methodCallId]; + if (wasMethodSync) { + TurboModulePerfLogger::getInstance().syncMethodCallExecutionStart(moduleName, methodNameStr.c_str()); } else { - [performanceLogger asyncRCTTurboModuleMethodCallStart:moduleName methodName:methodName methodCallId:methodCallId]; + TurboModulePerfLogger::getInstance().asyncMethodCallExecutionStart( + moduleName, methodNameStr.c_str(), asyncCallCounter); } + // TODO(T66699874) Should we guard this with a try/catch? [inv invokeWithTarget:strongModule]; [retainedObjectsForInvocation removeAllObjects]; - if (returnType == VoidKind) { - [performanceLogger asyncRCTTurboModuleMethodCallEnd:moduleName methodName:methodName methodCallId:methodCallId]; + if (!wasMethodSync) { + TurboModulePerfLogger::getInstance().asyncMethodCallExecutionEnd( + moduleName, methodNameStr.c_str(), asyncCallCounter); return; } + + TurboModulePerfLogger::getInstance().syncMethodCallExecutionEnd(moduleName, methodNameStr.c_str()); + TurboModulePerfLogger::getInstance().syncMethodCallReturnConversionStart(moduleName, methodNameStr.c_str()); + void *rawResult; [inv getReturnValue:&rawResult]; result = (__bridge id)rawResult; - [performanceLogger syncRCTTurboModuleMethodCallEnd:moduleName methodName:methodName methodCallId:methodCallId]; }; - if (returnType == VoidKind) { - nativeInvoker_->invokeAsync([block]() -> void { block(); }); - } else { + if (wasMethodSync) { nativeInvoker_->invokeSync([block]() -> void { block(); }); + } else { + asyncCallCounter = getUniqueId(); + TurboModulePerfLogger::getInstance().asyncMethodCallDispatch(moduleName, methodName); + nativeInvoker_->invokeAsync([block]() -> void { block(); }); + return jsi::Value::undefined(); } - // VoidKind can't be null - // PromiseKind, and FunctionKind must throw errors always - if (returnType != VoidKind && returnType != PromiseKind && returnType != FunctionKind && - (result == (id)kCFNull || result == nil)) { + if (result == (id)kCFNull || result == nil) { return jsi::Value::null(); } jsi::Value returnValue = jsi::Value::undefined(); - [performanceLogger_ syncMethodCallReturnConversionStart:moduleName methodName:methodName methodCallId:methodCallId]; // TODO: Re-use value conversion logic from existing impl, if possible. switch (returnType) { @@ -407,7 +408,7 @@ static RCTResponseSenderBlock convertJSIFunctionToCallback( throw std::runtime_error("convertInvocationResultToJSIValue: PromiseKind wasn't handled properly."); } - [performanceLogger_ syncMethodCallReturnConversionEnd:moduleName methodName:methodName methodCallId:methodCallId]; + TurboModulePerfLogger::getInstance().syncMethodCallReturnConversionEnd(moduleName, methodName); return returnValue; } @@ -476,21 +477,15 @@ static RCTResponseSenderBlock convertJSIFunctionToCallback( SEL selector, const jsi::Value *args, size_t count, - NSMutableArray *retainedObjectsForInvocation, - MethodCallId methodCallId) + NSMutableArray *retainedObjectsForInvocation) { - const bool isSync = returnType != VoidKind && returnType != PromiseKind; const char *moduleName = name_.c_str(); const id module = instance_; - if (isSync) { - [performanceLogger_ syncMethodCallArgumentConversionStart:moduleName - methodName:methodName - methodCallId:methodCallId]; + if (isMethodSync(returnType)) { + TurboModulePerfLogger::getInstance().syncMethodCallArgConversionStart(moduleName, methodName); } else { - [performanceLogger_ asyncMethodCallArgumentConversionStart:moduleName - methodName:methodName - methodCallId:methodCallId]; + TurboModulePerfLogger::getInstance().asyncMethodCallArgConversionStart(moduleName, methodName); } NSInvocation *inv = @@ -594,32 +589,28 @@ static RCTResponseSenderBlock convertJSIFunctionToCallback( } } - if (isSync) { - [performanceLogger_ syncMethodCallArgumentConversionEnd:moduleName methodName:methodName methodCallId:methodCallId]; + if (isMethodSync(returnType)) { + TurboModulePerfLogger::getInstance().syncMethodCallArgConversionEnd(moduleName, methodName); } else { - [performanceLogger_ asyncMethodCallArgumentConversionEnd:moduleName - methodName:methodName - methodCallId:methodCallId]; + TurboModulePerfLogger::getInstance().asyncMethodCallArgConversionEnd(moduleName, methodName); } return inv; } +bool ObjCTurboModule::isMethodSync(TurboModuleMethodValueKind returnType) +{ + return isSyncModule_ || !(returnType == VoidKind || returnType == PromiseKind); +} + ObjCTurboModule::ObjCTurboModule(const InitParams ¶ms) : TurboModule(params.moduleName, params.jsInvoker), instance_(params.instance), nativeInvoker_(params.nativeInvoker), - performanceLogger_(params.perfLogger) + isSyncModule_(params.isSyncModule) { } -MethodCallId ObjCTurboModule::methodCallId_{0}; - -MethodCallId ObjCTurboModule::getNewMethodCallId() -{ - return methodCallId_++; -} - jsi::Value ObjCTurboModule::invokeObjCMethod( jsi::Runtime &runtime, TurboModuleMethodValueKind returnType, @@ -628,20 +619,18 @@ static RCTResponseSenderBlock convertJSIFunctionToCallback( const jsi::Value *args, size_t count) { - MethodCallId methodCallId = getNewMethodCallId(); - const bool isSync = returnType != VoidKind && returnType != PromiseKind; const char *moduleName = name_.c_str(); const char *methodName = methodNameStr.c_str(); - if (isSync) { - [performanceLogger_ syncMethodCallStart:moduleName methodName:methodName methodCallId:methodCallId]; + if (isMethodSync(returnType)) { + TurboModulePerfLogger::getInstance().syncMethodCallStart(moduleName, methodName); } else { - [performanceLogger_ asyncMethodCallStart:moduleName methodName:methodName methodCallId:methodCallId]; + TurboModulePerfLogger::getInstance().asyncMethodCallStart(moduleName, methodName); } NSMutableArray *retainedObjectsForInvocation = [NSMutableArray arrayWithCapacity:count + 2]; - NSInvocation *inv = getMethodInvocation( - runtime, returnType, methodName, selector, args, count, retainedObjectsForInvocation, methodCallId); + NSInvocation *inv = + getMethodInvocation(runtime, returnType, methodName, selector, args, count, retainedObjectsForInvocation); jsi::Value returnValue = returnType == PromiseKind ? createPromise( @@ -653,14 +642,14 @@ static RCTResponseSenderBlock convertJSIFunctionToCallback( [retainedObjectsForInvocation addObject:resolveBlock]; [retainedObjectsForInvocation addObject:rejectBlock]; // The return type becomes void in the ObjC side. - performMethodInvocation(runtime, VoidKind, methodName, inv, retainedObjectsForInvocation, methodCallId); + performMethodInvocation(runtime, VoidKind, methodName, inv, retainedObjectsForInvocation); }) - : performMethodInvocation(runtime, returnType, methodName, inv, retainedObjectsForInvocation, methodCallId); + : performMethodInvocation(runtime, returnType, methodName, inv, retainedObjectsForInvocation); - if (isSync) { - [performanceLogger_ syncMethodCallEnd:moduleName methodName:methodName methodCallId:methodCallId]; + if (isMethodSync(returnType)) { + TurboModulePerfLogger::getInstance().syncMethodCallEnd(moduleName, methodName); } else { - [performanceLogger_ asyncMethodCallEnd:moduleName methodName:methodName methodCallId:methodCallId]; + TurboModulePerfLogger::getInstance().asyncMethodCallEnd(moduleName, methodName); } return returnValue; diff --git a/ReactCommon/turbomodule/core/platform/ios/RCTTurboModuleManager.h b/ReactCommon/turbomodule/core/platform/ios/RCTTurboModuleManager.h index 870d1a7d8a2e..87c0c96f07e1 100644 --- a/ReactCommon/turbomodule/core/platform/ios/RCTTurboModuleManager.h +++ b/ReactCommon/turbomodule/core/platform/ios/RCTTurboModuleManager.h @@ -5,6 +5,10 @@ * LICENSE file in the root directory of this source tree. */ +#pragma once + +#import + #import "RCTTurboModule.h" @protocol RCTTurboModuleManagerDelegate @@ -41,11 +45,6 @@ delegate:(id)delegate jsInvoker:(std::shared_ptr)jsInvoker; -- (instancetype)initWithBridge:(RCTBridge *)bridge - delegate:(id)delegate - jsInvoker:(std::shared_ptr)jsInvoker - performanceLogger:(id)performanceLogger; - - (void)installJSBindingWithRuntime:(facebook::jsi::Runtime *)runtime; - (void)invalidate; diff --git a/ReactCommon/turbomodule/core/platform/ios/RCTTurboModuleManager.mm b/ReactCommon/turbomodule/core/platform/ios/RCTTurboModuleManager.mm index f6179e0d3449..c6812b5d14ff 100644 --- a/ReactCommon/turbomodule/core/platform/ios/RCTTurboModuleManager.mm +++ b/ReactCommon/turbomodule/core/platform/ios/RCTTurboModuleManager.mm @@ -23,8 +23,9 @@ #import #import #import +#import -using namespace facebook; +using namespace facebook::react; /** * A global variable whose address we use to associate method queues to id objects. @@ -32,8 +33,15 @@ static char kAssociatedMethodQueueKey; namespace { +int32_t getUniqueId() +{ + static std::atomic counter{0}; + return counter++; +} + class TurboModuleHolder { private: + const int32_t moduleId_; id module_; bool isTryingToCreateModule_; bool isDoneCreatingModule_; @@ -41,6 +49,16 @@ std::condition_variable cv_; public: + TurboModuleHolder() + : moduleId_(getUniqueId()), module_(nil), isTryingToCreateModule_(false), isDoneCreatingModule_(false) + { + } + + int32_t getModuleId() const + { + return moduleId_; + } + void setModule(id module) { module_ = module; @@ -83,7 +101,7 @@ bool isCreatingModule() const } }; -class MethodQueueNativeCallInvoker : public facebook::react::CallInvoker { +class MethodQueueNativeCallInvoker : public CallInvoker { private: dispatch_queue_t methodQueue_; @@ -130,8 +148,7 @@ static Class getFallbackClassFromName(const char *name) @implementation RCTTurboModuleManager { jsi::Runtime *_runtime; - std::shared_ptr _jsInvoker; - id _performanceLogger; + std::shared_ptr _jsInvoker; __weak id _delegate; __weak RCTBridge *_bridge; @@ -142,11 +159,10 @@ @implementation RCTTurboModuleManager { * they want to be long-lived or short-lived. * * All instances of TurboModuleHolder are owned by the _turboModuleHolders map. - * We create TurboModuleHolder via operator[] inside getOrCreateTurboModuleHolder(). - * Henceforth, we only refer to TurboModuleHolders via pointers to entries in the _turboModuleHolders map. + * We only reference TurboModuleHolders via pointers to entries in the _turboModuleHolders map. */ std::unordered_map _turboModuleHolders; - std::unordered_map> _turboModuleCache; + std::unordered_map> _turboModuleCache; // Enforce synchronous access into _delegate std::mutex _turboModuleManagerDelegateMutex; @@ -158,22 +174,13 @@ @implementation RCTTurboModuleManager { - (instancetype)initWithBridge:(RCTBridge *)bridge delegate:(id)delegate - jsInvoker:(std::shared_ptr)jsInvoker -{ - return [self initWithBridge:bridge delegate:delegate jsInvoker:jsInvoker performanceLogger:nil]; -} - -- (instancetype)initWithBridge:(RCTBridge *)bridge - delegate:(id)delegate - jsInvoker:(std::shared_ptr)jsInvoker - performanceLogger:(id)performanceLogger + jsInvoker:(std::shared_ptr)jsInvoker { if (self = [super init]) { _jsInvoker = jsInvoker; _delegate = delegate; _bridge = bridge; _invalidating = false; - _performanceLogger = performanceLogger; // Necessary to allow NativeModules to lookup TurboModules [bridge setRCTTurboModuleLookupDelegate:self]; @@ -213,34 +220,40 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name * (for now). */ -- (std::shared_ptr)provideTurboModule:(const char *)moduleName +- (std::shared_ptr)provideTurboModule:(const char *)moduleName { auto turboModuleLookup = _turboModuleCache.find(moduleName); if (turboModuleLookup != _turboModuleCache.end()) { - [_performanceLogger createTurboModuleCacheHit:moduleName]; + TurboModulePerfLogger::getInstance().moduleJSRequireBeginningCacheHit(moduleName); + TurboModulePerfLogger::getInstance().moduleJSRequireBeginningEnd(moduleName); return turboModuleLookup->second; } + TurboModulePerfLogger::getInstance().moduleJSRequireBeginningEnd(moduleName); + /** * Step 1: Look for pure C++ modules. * Pure C++ modules get priority. */ if ([_delegate respondsToSelector:@selector(getTurboModule:jsInvoker:)]) { - [_performanceLogger getCppTurboModuleFromTMMDelegateStart:moduleName]; + int32_t moduleId = getUniqueId(); + TurboModulePerfLogger::getInstance().moduleCreateStart(moduleName, moduleId); auto turboModule = [_delegate getTurboModule:moduleName jsInvoker:_jsInvoker]; - [_performanceLogger getCppTurboModuleFromTMMDelegateEnd:moduleName]; if (turboModule != nullptr) { _turboModuleCache.insert({moduleName, turboModule}); + TurboModulePerfLogger::getInstance().moduleCreateEnd(moduleName, moduleId); return turboModule; } + + TurboModulePerfLogger::getInstance().moduleCreateFail(moduleName, moduleId); } /** * Step 2: Look for platform-specific modules. */ - [_performanceLogger createRCTTurboModuleStart:moduleName]; id module = [self provideRCTTurboModule:moduleName]; - [_performanceLogger createRCTTurboModuleEnd:moduleName]; + + TurboModulePerfLogger::getInstance().moduleJSRequireEndingStart(moduleName); // If we request that a TurboModule be created, its respective ObjC class must exist // If the class doesn't exist, then provideRCTTurboModule returns nil @@ -255,8 +268,7 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name /** * Step 2c: Create and native CallInvoker from the TurboModule's method queue. */ - std::shared_ptr nativeInvoker = - std::make_shared(methodQueue); + std::shared_ptr nativeInvoker = std::make_shared(methodQueue); /** * Have RCTCxxBridge decorate native CallInvoker, so that it's aware of TurboModule async method calls. @@ -266,20 +278,18 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name nativeInvoker = [_bridge decorateNativeCallInvoker:nativeInvoker]; } - facebook::react::ObjCTurboModule::InitParams params = { + ObjCTurboModule::InitParams params = { .moduleName = moduleName, .instance = module, .jsInvoker = _jsInvoker, .nativeInvoker = nativeInvoker, - .perfLogger = _performanceLogger, + .isSyncModule = methodQueue == RCTJSThread, }; // If RCTTurboModule supports creating its own C++ TurboModule object, // allow it to do so. if ([module respondsToSelector:@selector(getTurboModule:)]) { - [_performanceLogger getTurboModuleFromRCTTurboModuleStart:moduleName]; auto turboModule = [module getTurboModule:params]; - [_performanceLogger getTurboModuleFromRCTTurboModuleEnd:moduleName]; assert(turboModule != nullptr); _turboModuleCache.insert({moduleName, turboModule}); return turboModule; @@ -292,9 +302,7 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name if ([moduleClass isSubclassOfClass:RCTCxxModule.class]) { // Use TurboCxxModule compat class to wrap the CxxModule instance. // This is only for migration convenience, despite less performant. - [_performanceLogger getTurboModuleFromRCTCxxModuleStart:moduleName]; - auto turboModule = std::make_shared([((RCTCxxModule *)module) createModule], _jsInvoker); - [_performanceLogger getTurboModuleFromRCTCxxModuleEnd:moduleName]; + auto turboModule = std::make_shared([((RCTCxxModule *)module) createModule], _jsInvoker); _turboModuleCache.insert({moduleName, turboModule}); return turboModule; } @@ -302,9 +310,7 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name /** * Step 2e: Return an exact sub-class of ObjC TurboModule */ - [_performanceLogger getTurboModuleFromTMMDelegateStart:moduleName]; auto turboModule = [_delegate getTurboModule:moduleName initParams:params]; - [_performanceLogger getTurboModuleFromTMMDelegateEnd:moduleName]; if (turboModule != nullptr) { _turboModuleCache.insert({moduleName, turboModule}); } @@ -332,10 +338,21 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name moduleHolder = &_turboModuleHolders[moduleName]; } - return [self _provideRCTTurboModule:moduleName moduleHolder:moduleHolder]; + TurboModulePerfLogger::getInstance().moduleCreateStart(moduleName, moduleHolder->getModuleId()); + id module = [self _provideRCTTurboModule:moduleName moduleHolder:moduleHolder shouldPerfLog:YES]; + + if (module) { + TurboModulePerfLogger::getInstance().moduleCreateEnd(moduleName, moduleHolder->getModuleId()); + } else { + TurboModulePerfLogger::getInstance().moduleCreateFail(moduleName, moduleHolder->getModuleId()); + } + + return module; } -- (id)_provideRCTTurboModule:(const char *)moduleName moduleHolder:(TurboModuleHolder *)moduleHolder +- (id)_provideRCTTurboModule:(const char *)moduleName + moduleHolder:(TurboModuleHolder *)moduleHolder + shouldPerfLog:(BOOL)shouldPerfLog { bool shouldCreateModule = false; @@ -343,6 +360,9 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name std::lock_guard guard(moduleHolder->mutex()); if (moduleHolder->isDoneCreatingModule()) { + if (shouldPerfLog) { + TurboModulePerfLogger::getInstance().moduleCreateCacheHit(moduleName, moduleHolder->getModuleId()); + } return moduleHolder->getModule(); } @@ -358,7 +378,6 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name /** * Step 2a: Resolve platform-specific class. */ - [_performanceLogger getRCTTurboModuleClassStart:moduleName]; if ([_delegate respondsToSelector:@selector(getModuleClassFromName:)]) { std::lock_guard delegateGuard(_turboModuleManagerDelegateMutex); @@ -370,13 +389,13 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name moduleClass = getFallbackClassFromName(moduleName); } - [_performanceLogger getRCTTurboModuleClassEnd:moduleName]; - __block id module = nil; if ([moduleClass conformsToProtocol:@protocol(RCTTurboModule)]) { dispatch_block_t work = ^{ - module = [self _createAndSetUpRCTTurboModule:moduleClass moduleName:moduleName]; + module = [self _createAndSetUpRCTTurboModule:moduleClass + moduleName:moduleName + moduleId:moduleHolder->getModuleId()]; }; if ([self _requiresMainQueueSetup:moduleClass]) { @@ -422,15 +441,17 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name * - The main thread (if the TurboModule requires main queue init), blocking the thread that calls * provideRCTTurboModule:. */ -- (id)_createAndSetUpRCTTurboModule:(Class)moduleClass moduleName:(const char *)moduleName +- (id)_createAndSetUpRCTTurboModule:(Class)moduleClass + moduleName:(const char *)moduleName + moduleId:(int32_t)moduleId { id module = nil; /** * Step 2b: Ask hosting application/delegate to instantiate this class */ - [_performanceLogger getRCTTurboModuleInstanceStart:moduleName]; + TurboModulePerfLogger::getInstance().moduleCreateConstructStart(moduleName, moduleId); if ([_delegate respondsToSelector:@selector(getModuleInstanceFromClass:)]) { std::lock_guard delegateGuard(_turboModuleManagerDelegateMutex); @@ -438,10 +459,9 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name } else { module = [moduleClass new]; } + TurboModulePerfLogger::getInstance().moduleCreateConstructEnd(moduleName, moduleId); - [_performanceLogger getRCTTurboModuleInstanceEnd:moduleName]; - - [_performanceLogger setupRCTTurboModuleStart:moduleName]; + TurboModulePerfLogger::getInstance().moduleCreateSetUpStart(moduleName, moduleId); if ([module respondsToSelector:@selector(setTurboModuleLookupDelegate:)]) { [module setTurboModuleLookupDelegate:self]; @@ -457,8 +477,6 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name * NativeModule. */ if ([module respondsToSelector:@selector(bridge)] && _bridge) { - [_performanceLogger attachRCTBridgeToRCTTurboModuleStart:moduleName]; - /** * Just because a NativeModule has the `bridge` method, it doesn't mean * that it has synthesized the bridge in its implementation. Therefore, @@ -483,8 +501,6 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name "or provide your own setter method.", RCTBridgeModuleNameForClass([module class])); } - - [_performanceLogger attachRCTBridgeToRCTTurboModuleEnd:moduleName]; } /** @@ -493,8 +509,6 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name * `@synthesize methodQueue = _methodQueue` */ - [_performanceLogger attachMethodQueueToRCTTurboModuleStart:moduleName]; - dispatch_queue_t methodQueue = nil; BOOL moduleHasMethodQueueGetter = [module respondsToSelector:@selector(methodQueue)]; @@ -541,8 +555,6 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name */ objc_setAssociatedObject(module, &kAssociatedMethodQueueKey, methodQueue, OBJC_ASSOCIATION_RETAIN); - [_performanceLogger attachMethodQueueToRCTTurboModuleEnd:moduleName]; - /** * NativeModules that implement the RCTFrameUpdateObserver protocol * require registration with RCTDisplayLink. @@ -551,10 +563,8 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name * rollout. */ if (_bridge) { - [_performanceLogger registerRCTTurboModuleForFrameUpdatesStart:moduleName]; RCTModuleData *data = [[RCTModuleData alloc] initWithModuleInstance:(id)module bridge:_bridge]; [_bridge registerModuleForFrameUpdates:(id)module withModuleData:data]; - [_performanceLogger registerRCTTurboModuleForFrameUpdatesEnd:moduleName]; } /** @@ -563,14 +573,12 @@ - (void)notifyAboutTurboModuleSetup:(const char *)name * TODO(T41180176): Investigate whether we can delete this after TM * rollout. */ - [_performanceLogger dispatchDidInitializeModuleNotificationForRCTTurboModuleStart:moduleName]; [[NSNotificationCenter defaultCenter] postNotificationName:RCTDidInitializeModuleNotification object:_bridge userInfo:@{@"module" : module, @"bridge" : RCTNullIfNil([_bridge parentBridge])}]; - [_performanceLogger dispatchDidInitializeModuleNotificationForRCTTurboModuleEnd:moduleName]; - [_performanceLogger setupRCTTurboModuleEnd:moduleName]; + TurboModulePerfLogger::getInstance().moduleCreateSetUpEnd(moduleName, moduleId); return module; } @@ -643,40 +651,42 @@ - (void)installJSBindingWithRuntime:(jsi::Runtime *)runtime __weak __typeof(self) weakSelf = self; - react::TurboModuleBinding::install( - *_runtime, - [weakSelf, - performanceLogger = _performanceLogger](const std::string &name) -> std::shared_ptr { - if (!weakSelf) { - return nullptr; - } + TurboModuleBinding::install(*_runtime, [weakSelf](const std::string &name) -> std::shared_ptr { + if (!weakSelf) { + return nullptr; + } - __strong __typeof(self) strongSelf = weakSelf; + auto moduleName = name.c_str(); - auto moduleName = name.c_str(); - auto moduleWasNotInitialized = ![strongSelf moduleIsInitialized:moduleName]; - if (moduleWasNotInitialized) { - [strongSelf->_bridge.performanceLogger markStartForTag:RCTPLTurboModuleSetup]; - } + TurboModulePerfLogger::getInstance().moduleJSRequireBeginningStart(moduleName); - [performanceLogger createTurboModuleStart:moduleName]; + __strong __typeof(self) strongSelf = weakSelf; - /** - * By default, all TurboModules are long-lived. - * Additionally, if a TurboModule with the name `name` isn't found, then we - * trigger an assertion failure. - */ - auto turboModule = [strongSelf provideTurboModule:moduleName]; + auto moduleWasNotInitialized = ![strongSelf moduleIsInitialized:moduleName]; + if (moduleWasNotInitialized) { + [strongSelf->_bridge.performanceLogger markStartForTag:RCTPLTurboModuleSetup]; + } - [performanceLogger createTurboModuleEnd:moduleName]; + /** + * By default, all TurboModules are long-lived. + * Additionally, if a TurboModule with the name `name` isn't found, then we + * trigger an assertion failure. + */ + auto turboModule = [strongSelf provideTurboModule:moduleName]; - if (moduleWasNotInitialized && [strongSelf moduleIsInitialized:moduleName]) { - [strongSelf->_bridge.performanceLogger markStopForTag:RCTPLTurboModuleSetup]; - [strongSelf notifyAboutTurboModuleSetup:moduleName]; - } + if (moduleWasNotInitialized && [strongSelf moduleIsInitialized:moduleName]) { + [strongSelf->_bridge.performanceLogger markStopForTag:RCTPLTurboModuleSetup]; + [strongSelf notifyAboutTurboModuleSetup:moduleName]; + } + + if (turboModule) { + TurboModulePerfLogger::getInstance().moduleJSRequireEndingEnd(moduleName); + } else { + TurboModulePerfLogger::getInstance().moduleJSRequireEndingFail(moduleName); + } - return turboModule; - }); + return turboModule; + }); } #pragma mark RCTTurboModuleLookupDelegate @@ -737,7 +747,9 @@ - (void)bridgeDidInvalidateModules:(NSNotification *)notification * for TurboModule init to finish before calling invalidate on it. So, we call _provideRCTTurboModule:moduleHolder, * because it's guaranteed to return a fully initialized NativeModule. */ - id module = [self _provideRCTTurboModule:moduleName.c_str() moduleHolder:moduleHolder]; + id module = [self _provideRCTTurboModule:moduleName.c_str() + moduleHolder:moduleHolder + shouldPerfLog:NO]; if ([module respondsToSelector:@selector(invalidate)]) { if ([module respondsToSelector:@selector(methodQueue)]) { From 3611259b53fe99f4ab762eeed272a0cca17b69cb Mon Sep 17 00:00:00 2001 From: Ramanpreet Nara Date: Wed, 13 May 2020 19:18:56 -0700 Subject: [PATCH 3/7] Instrument RCTModuleData create Summary: `RCTModuleData` holds our NativeModule classes/objects. This diff instruments `RCTModuleData` create. Changelog: [Internal] Differential Revision: D21415433 fbshipit-source-id: ee4d17de45d5ccf0af658f83b1439786610dfb0b --- React/CxxBridge/RCTCxxBridge.mm | 17 +++++++++++++++++ 1 file changed, 17 insertions(+) diff --git a/React/CxxBridge/RCTCxxBridge.mm b/React/CxxBridge/RCTCxxBridge.mm index ec4090a862c3..aed3293cf3e8 100644 --- a/React/CxxBridge/RCTCxxBridge.mm +++ b/React/CxxBridge/RCTCxxBridge.mm @@ -27,6 +27,7 @@ #import #import #import +#import #import #import #import @@ -68,6 +69,12 @@ typedef NS_ENUM(NSUInteger, RCTBridgeFields) { namespace { +int32_t getUniqueId() +{ + static std::atomic counter{0}; + return counter++; +} + class GetDescAdapter : public JSExecutorFactory { public: GetDescAdapter(RCTCxxBridge *bridge, std::shared_ptr factory) : bridge_(bridge), factory_(factory) @@ -653,7 +660,10 @@ - (void)updateModuleWithInstance:(id)instance // Instantiate moduleData // TODO #13258411: can we defer this until config generation? + int32_t moduleDataId = getUniqueId(); + NativeModulePerfLogger::getInstance().moduleDataCreateStart([moduleName UTF8String], moduleDataId); moduleData = [[RCTModuleData alloc] initWithModuleClass:moduleClass bridge:self]; + NativeModulePerfLogger::getInstance().moduleDataCreateEnd([moduleName UTF8String], moduleDataId); _moduleDataByName[moduleName] = moduleData; [_moduleClassesByID addObject:moduleClass]; @@ -713,7 +723,11 @@ - (void)registerExtraModules } // Instantiate moduleData container + int32_t moduleDataId = getUniqueId(); + NativeModulePerfLogger::getInstance().moduleDataCreateStart([moduleName UTF8String], moduleDataId); RCTModuleData *moduleData = [[RCTModuleData alloc] initWithModuleInstance:module bridge:self]; + NativeModulePerfLogger::getInstance().moduleDataCreateEnd([moduleName UTF8String], moduleDataId); + _moduleDataByName[moduleName] = moduleData; [_moduleClassesByID addObject:moduleClass]; [_moduleDataByID addObject:moduleData]; @@ -760,7 +774,10 @@ - (void)registerExtraLazyModules } } + int32_t moduleDataId = getUniqueId(); + NativeModulePerfLogger::getInstance().moduleDataCreateStart([moduleName UTF8String], moduleDataId); moduleData = [[RCTModuleData alloc] initWithModuleClass:moduleClass bridge:self]; + NativeModulePerfLogger::getInstance().moduleDataCreateEnd([moduleName UTF8String], moduleDataId); _moduleDataByName[moduleName] = moduleData; [_moduleClassesByID addObject:moduleClass]; From c76889fe3ff96fec7ba69b7ab5e22afc4ed25a3c Mon Sep 17 00:00:00 2001 From: Ramanpreet Nara Date: Wed, 13 May 2020 19:18:56 -0700 Subject: [PATCH 4/7] Instrument module create Summary: `RCTModuleData instance` is the entry-point for creating and initializing NativeModules on iOS. This diff instruments module-create for the legacy NativeModule system. Changelog: [Internal] Differential Revision: D21415435 fbshipit-source-id: be74ccb137ea78ecbe7acc3df01f749df2fad549 --- React/Base/RCTModuleData.mm | 52 +++++++++++++++++++++++++++++++++---- 1 file changed, 47 insertions(+), 5 deletions(-) diff --git a/React/Base/RCTModuleData.mm b/React/Base/RCTModuleData.mm index b4e48ae5e121..4ac10bfa4884 100644 --- a/React/Base/RCTModuleData.mm +++ b/React/Base/RCTModuleData.mm @@ -8,7 +8,10 @@ #import "RCTModuleData.h" #import -#include +#import +#import + +#import #import "RCTBridge+Private.h" #import "RCTBridge.h" @@ -17,6 +20,16 @@ #import "RCTProfile.h" #import "RCTUtils.h" +using namespace facebook::react; + +namespace { +int32_t getUniqueId() +{ + static std::atomic counter{0}; + return counter++; +} +} + @implementation RCTModuleData { NSDictionary *_constantsToExport; NSString *_queueName; @@ -110,22 +123,29 @@ - (instancetype)initWithModuleInstance:(id)instance bridge:(RCT #pragma mark - private setup methods -- (void)setUpInstanceAndBridge +- (void)setUpInstanceAndBridge:(int32_t)requestId { + NSString *moduleName = [self name]; + RCT_PROFILE_BEGIN_EVENT( RCTProfileTagAlways, @"[RCTModuleData setUpInstanceAndBridge]", @{@"moduleClass" : NSStringFromClass(_moduleClass)}); { std::unique_lock lock(_instanceLock); + BOOL shouldSetup = !_setupComplete && _bridge.valid; - if (!_setupComplete && _bridge.valid) { + if (shouldSetup) { if (!_instance) { if (RCT_DEBUG && _requiresMainQueueSetup) { RCTAssertMainQueue(); } RCT_PROFILE_BEGIN_EVENT(RCTProfileTagAlways, @"[RCTModuleData setUpInstanceAndBridge] Create module", nil); + + NativeModulePerfLogger::getInstance().moduleCreateConstructStart([moduleName UTF8String], requestId); _instance = _moduleProvider ? _moduleProvider() : nil; + NativeModulePerfLogger::getInstance().moduleCreateConstructEnd([moduleName UTF8String], requestId); + RCT_PROFILE_END_EVENT(RCTProfileTagAlways, @""); if (!_instance) { // Module init returned nil, probably because automatic instantiation @@ -143,7 +163,13 @@ - (void)setUpInstanceAndBridge if (_instance && RCTProfileIsProfiling()) { RCTProfileHookInstance(_instance); } + } + if (_instance) { + NativeModulePerfLogger::getInstance().moduleCreateSetUpStart([moduleName UTF8String], requestId); + } + + if (shouldSetup) { // Bridge must be set before methodQueue is set up, as methodQueue // initialization requires it (View Managers get their queue by calling // self.bridge.uiManager.methodQueue) @@ -171,6 +197,10 @@ - (void)setUpInstanceAndBridge // thread. _requiresMainQueueSetup = NO; } + + if (_instance) { + NativeModulePerfLogger::getInstance().moduleCreateSetUpEnd([moduleName UTF8String], requestId); + } } - (void)setBridgeForInstance @@ -286,6 +316,10 @@ - (BOOL)hasInstance - (id)instance { + NSString *moduleName = [self name]; + int32_t requestId = getUniqueId(); + NativeModulePerfLogger::getInstance().moduleCreateStart([moduleName UTF8String], requestId); + if (!_setupComplete) { RCT_PROFILE_BEGIN_EVENT( RCTProfileTagAlways, ([NSString stringWithFormat:@"[RCTModuleData instanceForClass:%@]", _moduleClass]), nil); @@ -301,13 +335,21 @@ - (BOOL)hasInstance } RCTUnsafeExecuteOnMainQueueSync(^{ - [self setUpInstanceAndBridge]; + [self setUpInstanceAndBridge:requestId]; }); RCT_PROFILE_END_EVENT(RCTProfileTagAlways, @""); } else { - [self setUpInstanceAndBridge]; + [self setUpInstanceAndBridge:requestId]; } RCT_PROFILE_END_EVENT(RCTProfileTagAlways, @""); + } else { + NativeModulePerfLogger::getInstance().moduleCreateCacheHit([moduleName UTF8String], requestId); + } + + if (_instance) { + NativeModulePerfLogger::getInstance().moduleCreateEnd([moduleName UTF8String], requestId); + } else { + NativeModulePerfLogger::getInstance().moduleCreateFail([moduleName UTF8String], requestId); } return _instance; } From 638f90d3e6e90991d32b5cfb2f861c296fbcb408 Mon Sep 17 00:00:00 2001 From: Ramanpreet Nara Date: Wed, 13 May 2020 19:18:56 -0700 Subject: [PATCH 5/7] Instrument JS requires Summary: This diff instruments two markers: - JSRequireBeginning: From the start of the JS require to when we start creating the platform NativeModule - JSRequireEnding: From the end of platform NativeModule create to the end of the JS require In order to accomplish this, I had modify `ModuleRegistry::ModuleRegistry()` to accept a `std::shared_ptr`. I also had to implement the public method `ModuleRegistry::getNativeModulePerfLogger()` so that `JSINativeModules` could start logging the JS require beginning and ending. Changelog: [Internal] Differential Revision: D21418803 fbshipit-source-id: 9605886059f4ca84c60d32c4b39786f17c581d42 --- RNTester/Podfile.lock | 6 ++- React/Base/RCTModuleData.mm | 18 ++++++++ ReactCommon/cxxreact/Android.mk | 3 +- ReactCommon/cxxreact/BUCK | 1 + ReactCommon/cxxreact/ModuleRegistry.cpp | 41 ++++++++++++++++++- ReactCommon/cxxreact/React-cxxreact.podspec | 2 + ReactCommon/jsiexecutor/Android.mk | 2 +- ReactCommon/jsiexecutor/BUCK | 1 + .../jsiexecutor/React-jsiexecutor.podspec | 1 + .../jsiexecutor/jsireact/JSINativeModules.cpp | 16 +++++++- 10 files changed, 84 insertions(+), 7 deletions(-) diff --git a/RNTester/Podfile.lock b/RNTester/Podfile.lock index 09cde73049f2..32e98d714c94 100644 --- a/RNTester/Podfile.lock +++ b/RNTester/Podfile.lock @@ -252,6 +252,7 @@ PODS: - glog - React-callinvoker (= 1000.0.0) - React-jsinspector (= 1000.0.0) + - React-perflogger (= 1000.0.0) - React-runtimeexecutor (= 1000.0.0) - React-jsi (1000.0.0): - boost-for-react-native (= 1.63.0) @@ -270,6 +271,7 @@ PODS: - glog - React-cxxreact (= 1000.0.0) - React-jsi (= 1000.0.0) + - React-perflogger (= 1000.0.0) - React-jsinspector (1000.0.0) - React-perflogger (1000.0.0) - React-RCTActionSheet (1000.0.0): @@ -519,9 +521,9 @@ SPEC CHECKSUMS: React-callinvoker: 0dada022d38b73e6e15b33e2a96476153f79bbf6 React-Core: d85e4563acbfbb6e6be7414a813ad55d05d675df React-CoreModules: d13d148c851af5780f864be74bc2165140923dc7 - React-cxxreact: b43a94e679b307660de530a3af872ab4c7d9925d + React-cxxreact: bb64d8c5798d75565870ff1a7a8ac57a09bd9ff8 React-jsi: fe94132da767bfc4801968c2a12abae43e9a833e - React-jsiexecutor: 55eff40b2e0696e7a979016e321793ec8b28a2ac + React-jsiexecutor: 959bb48c75a3bfc1b1d2b991087a6d8df721cbcf React-jsinspector: 7fbf9b42b58b02943a0d89b0ba9fff0070f2de98 React-perflogger: d32d3423e466a825ef2e9934fe9d62b149e5d9f8 React-RCTActionSheet: 51c43beeb74ef41189e87fe9823e53ebf6210359 diff --git a/React/Base/RCTModuleData.mm b/React/Base/RCTModuleData.mm index 4ac10bfa4884..7dd873e7b001 100644 --- a/React/Base/RCTModuleData.mm +++ b/React/Base/RCTModuleData.mm @@ -373,10 +373,22 @@ - (NSString *)name - (void)gatherConstants { + NSString *moduleName = [self name]; + if (_hasConstantsToExport && !_constantsToExport) { RCT_PROFILE_BEGIN_EVENT( RCTProfileTagAlways, ([NSString stringWithFormat:@"[RCTModuleData gatherConstants] %@", _moduleClass]), nil); (void)[self instance]; + + /** + * Why do we instrument moduleJSRequireEndingStart here? + * - NativeModule requires from JS go through ModuleRegistry::getConfig(). + * - ModuleRegistry::getConfig() calls NativeModule::getConstants() first. + * - This delegates to RCTNativeModule::getConstants(), which calls RCTModuleData gatherConstants(). + * - Therefore, this is the first statement that executes after the NativeModule is created/initialized in a JS + * require. + */ + NativeModulePerfLogger::getInstance().moduleJSRequireEndingStart([moduleName UTF8String]); if (_requiresMainQueueSetup) { if (!RCTIsMainQueue()) { RCTLogWarn(@"Required dispatch_sync to load constants for %@. This may lead to deadlocks", _moduleClass); @@ -389,6 +401,12 @@ - (void)gatherConstants _constantsToExport = [_instance constantsToExport] ?: @{}; } RCT_PROFILE_END_EVENT(RCTProfileTagAlways, @""); + } else { + /** + * If a NativeModule doesn't have constants, it isn't eagerly loaded until its methods are first invoked. + * Therefore, we should immediately start JSRequireEnding + */ + NativeModulePerfLogger::getInstance().moduleJSRequireEndingStart([moduleName UTF8String]); } } diff --git a/ReactCommon/cxxreact/Android.mk b/ReactCommon/cxxreact/Android.mk index 32d7e91cae7b..8a3a2e2b945b 100644 --- a/ReactCommon/cxxreact/Android.mk +++ b/ReactCommon/cxxreact/Android.mk @@ -19,7 +19,7 @@ LOCAL_CFLAGS := \ LOCAL_CFLAGS += -fexceptions -frtti -Wno-unused-lambda-capture -LOCAL_STATIC_LIBRARIES := boost jsi callinvoker runtimeexecutor +LOCAL_STATIC_LIBRARIES := boost jsi callinvoker perflogger runtimeexecutor LOCAL_SHARED_LIBRARIES := jsinspector libfolly_json glog include $(BUILD_STATIC_LIBRARY) @@ -27,6 +27,7 @@ include $(BUILD_STATIC_LIBRARY) $(call import-module,fb) $(call import-module,folly) $(call import-module,callinvoker) +$(call import-module,perflogger) $(call import-module,jsc) $(call import-module,glog) $(call import-module,jsi) diff --git a/ReactCommon/cxxreact/BUCK b/ReactCommon/cxxreact/BUCK index d5453556bd6e..e1837d79d096 100644 --- a/ReactCommon/cxxreact/BUCK +++ b/ReactCommon/cxxreact/BUCK @@ -156,6 +156,7 @@ rn_xplat_cxx_library( react_native_xplat_target("microprofiler:microprofiler"), react_native_xplat_target("runtimeexecutor:runtimeexecutor"), "//third-party/glog:glog", + react_native_xplat_target("perflogger:perflogger"), "//xplat/folly:optional", ], ) diff --git a/ReactCommon/cxxreact/ModuleRegistry.cpp b/ReactCommon/cxxreact/ModuleRegistry.cpp index b59dac82f44f..ccffe90c0fcc 100644 --- a/ReactCommon/cxxreact/ModuleRegistry.cpp +++ b/ReactCommon/cxxreact/ModuleRegistry.cpp @@ -7,6 +7,7 @@ #include "ModuleRegistry.h" +#include #include #include "NativeModule.h" @@ -99,14 +100,44 @@ folly::Optional ModuleRegistry::getConfig( if (it == modulesByName_.end()) { if (unknownModules_.find(name) != unknownModules_.end()) { + NativeModulePerfLogger::getInstance().moduleJSRequireBeginningFail( + name.c_str()); + NativeModulePerfLogger::getInstance().moduleJSRequireEndingStart( + name.c_str()); return folly::none; } - if (!moduleNotFoundCallback_ || !moduleNotFoundCallback_(name) || - (it = modulesByName_.find(name)) == modulesByName_.end()) { + + if (!moduleNotFoundCallback_) { unknownModules_.insert(name); + NativeModulePerfLogger::getInstance().moduleJSRequireBeginningFail( + name.c_str()); + NativeModulePerfLogger::getInstance().moduleJSRequireEndingStart( + name.c_str()); return folly::none; } + + NativeModulePerfLogger::getInstance().moduleJSRequireBeginningEnd( + name.c_str()); + + bool wasModuleLazilyLoaded = moduleNotFoundCallback_(name); + it = modulesByName_.find(name); + + bool wasModuleRegisteredWithRegistry = + wasModuleLazilyLoaded && it != modulesByName_.end(); + + if (!wasModuleRegisteredWithRegistry) { + NativeModulePerfLogger::getInstance().moduleJSRequireEndingStart( + name.c_str()); + unknownModules_.insert(name); + return folly::none; + } + } else { + NativeModulePerfLogger::getInstance().moduleJSRequireBeginningEnd( + name.c_str()); } + + // If we've gotten this far, then we've signaled moduleJSRequireBeginningEnd + size_t index = it->second; CHECK(index < modules_.size()); @@ -118,6 +149,12 @@ folly::Optional ModuleRegistry::getConfig( { SystraceSection s_("ModuleRegistry::getConstants", "module", name); + /** + * In the case that there are constants, we'll initialize the NativeModule, + * and signal moduleJSRequireEndingStart. Otherwise, we'll simply signal the + * event. The Module will be initialized when we invoke one of its + * NativeModule methods. + */ config.push_back(module->getConstants()); } diff --git a/ReactCommon/cxxreact/React-cxxreact.podspec b/ReactCommon/cxxreact/React-cxxreact.podspec index 452d817812e8..e1b85a7310b9 100644 --- a/ReactCommon/cxxreact/React-cxxreact.podspec +++ b/ReactCommon/cxxreact/React-cxxreact.podspec @@ -1,3 +1,4 @@ +# coding: utf-8 # Copyright (c) Facebook, Inc. and its affiliates. # # This source code is licensed under the MIT license found in the @@ -42,4 +43,5 @@ Pod::Spec.new do |s| s.dependency "React-jsinspector", version s.dependency "React-callinvoker", version s.dependency "React-runtimeexecutor", version + s.dependency "React-perflogger", version end diff --git a/ReactCommon/jsiexecutor/Android.mk b/ReactCommon/jsiexecutor/Android.mk index c6bb60124a07..bdc55ac9fea2 100644 --- a/ReactCommon/jsiexecutor/Android.mk +++ b/ReactCommon/jsiexecutor/Android.mk @@ -16,7 +16,7 @@ LOCAL_EXPORT_C_INCLUDES := $(LOCAL_C_INCLUDES) LOCAL_CFLAGS := -fexceptions -frtti -O3 -LOCAL_STATIC_LIBRARIES := libjsi reactnative +LOCAL_STATIC_LIBRARIES := libjsi reactnative perflogger LOCAL_SHARED_LIBRARIES := libfolly_json glog include $(BUILD_STATIC_LIBRARY) diff --git a/ReactCommon/jsiexecutor/BUCK b/ReactCommon/jsiexecutor/BUCK index 1edfe366a9ac..0642f81da285 100644 --- a/ReactCommon/jsiexecutor/BUCK +++ b/ReactCommon/jsiexecutor/BUCK @@ -39,5 +39,6 @@ cxx_library( react_native_xplat_dep("jsi:JSIDynamic"), react_native_xplat_target("cxxreact:bridge"), react_native_xplat_target("cxxreact:jsbigstring"), + react_native_xplat_target("perflogger:perflogger"), ], ) diff --git a/ReactCommon/jsiexecutor/React-jsiexecutor.podspec b/ReactCommon/jsiexecutor/React-jsiexecutor.podspec index 77a33c289669..9da009177b61 100644 --- a/ReactCommon/jsiexecutor/React-jsiexecutor.podspec +++ b/ReactCommon/jsiexecutor/React-jsiexecutor.podspec @@ -36,6 +36,7 @@ Pod::Spec.new do |s| s.dependency "React-cxxreact", version s.dependency "React-jsi", version + s.dependency "React-perflogger", version s.dependency "Folly", folly_version s.dependency "DoubleConversion" s.dependency "glog" diff --git a/ReactCommon/jsiexecutor/jsireact/JSINativeModules.cpp b/ReactCommon/jsiexecutor/jsireact/JSINativeModules.cpp index 425152cdac68..757720a97a95 100644 --- a/ReactCommon/jsiexecutor/jsireact/JSINativeModules.cpp +++ b/ReactCommon/jsiexecutor/jsireact/JSINativeModules.cpp @@ -6,6 +6,7 @@ */ #include "jsireact/JSINativeModules.h" +#include #include @@ -31,13 +32,22 @@ Value JSINativeModules::getModule(Runtime &rt, const PropNameID &name) { std::string moduleName = name.utf8(rt); + NativeModulePerfLogger::getInstance().moduleJSRequireBeginningStart( + moduleName.c_str()); + const auto it = m_objects.find(moduleName); if (it != m_objects.end()) { + NativeModulePerfLogger::getInstance().moduleJSRequireBeginningCacheHit( + moduleName.c_str()); + NativeModulePerfLogger::getInstance().moduleJSRequireBeginningEnd( + moduleName.c_str()); return Value(rt, it->second); } auto module = createModule(rt, moduleName); if (!module.hasValue()) { + NativeModulePerfLogger::getInstance().moduleJSRequireEndingFail( + moduleName.c_str()); // Allow lookup to continue in the objects own properties, which allows for // overrides of NativeModules return nullptr; @@ -45,7 +55,11 @@ Value JSINativeModules::getModule(Runtime &rt, const PropNameID &name) { auto result = m_objects.emplace(std::move(moduleName), std::move(*module)).first; - return Value(rt, result->second); + + Value ret = Value(rt, result->second); + NativeModulePerfLogger::getInstance().moduleJSRequireEndingEnd( + moduleName.c_str()); + return ret; } void JSINativeModules::reset() { From 24d96d59fc4f4ef4f943516ab16505c5e3bd86b3 Mon Sep 17 00:00:00 2001 From: Ramanpreet Nara Date: Wed, 13 May 2020 19:18:56 -0700 Subject: [PATCH 6/7] Instrument async method call batch preprocessing Summary: NativeModule async method calls are queued up on the JS side, and flushed to C++ on every Native -> JS call. Before we execute the batch of async NativeModule method calls, we convert it (a JS object) from a `jsi::Value` to a `folly::dynamic` object in `JSIExecutor::callNativeModules`. Then, in `JsToNativeBridge::callNativeModules`, we convert this `folly::dynamic` object into an `std::vector`, before finally looping over these `MethodCall`s and invoking each NativeModule async method call. The markers I'm adding in this diff measure this `jsi::Value -> folly::dynamic -> std::vector` pre-processing. Changelog: [Internal] Differential Revision: D21435455 fbshipit-source-id: 74ee3e913b3cbd7179e1268d261cc9007ec7801b --- ReactCommon/cxxreact/NativeToJsBridge.cpp | 7 ++++++- ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp | 3 +++ 2 files changed, 9 insertions(+), 1 deletion(-) diff --git a/ReactCommon/cxxreact/NativeToJsBridge.cpp b/ReactCommon/cxxreact/NativeToJsBridge.cpp index 64b0673423b8..be11a075f971 100644 --- a/ReactCommon/cxxreact/NativeToJsBridge.cpp +++ b/ReactCommon/cxxreact/NativeToJsBridge.cpp @@ -8,6 +8,7 @@ #include "NativeToJsBridge.h" #include +#include #include #include #include @@ -55,10 +56,14 @@ class JsToNativeBridge : public react::ExecutorDelegate { m_batchHadNativeModuleOrTurboModuleCalls = m_batchHadNativeModuleOrTurboModuleCalls || !calls.empty(); + std::vector methodCalls = parseMethodCalls(std::move(calls)); + NativeModulePerfLogger::getInstance().asyncMethodCallBatchPreprocessEnd( + (int)methodCalls.size()); + // An exception anywhere in here stops processing of the batch. This // was the behavior of the Android bridge, and since exception handling // terminates the whole bridge, there's not much point in continuing. - for (auto &call : parseMethodCalls(std::move(calls))) { + for (auto &call : methodCalls) { m_registry->callNativeMethod( call.moduleId, call.methodId, std::move(call.arguments), call.callId); } diff --git a/ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp b/ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp index fd77eba63e64..42f3eac590fb 100644 --- a/ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp +++ b/ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp @@ -16,6 +16,7 @@ #include #include #include +#include #include #include @@ -383,6 +384,8 @@ void JSIExecutor::callNativeModules(const Value &queue, bool isEndOfBatch) { .getPropertyAsFunction(*runtime_, "stringify").call(*runtime_, queue) .getString(*runtime_).utf8(*runtime_); #endif + NativeModulePerfLogger::getInstance().asyncMethodCallBatchPreprocessStart(); + delegate_->callNativeModules( *this, dynamicFromValue(*runtime_, queue), isEndOfBatch); } From 60edd3bfed62efd22b9f57157d85a2e7316ff392 Mon Sep 17 00:00:00 2001 From: Ramanpreet Nara Date: Wed, 13 May 2020 19:19:31 -0700 Subject: [PATCH 7/7] Instrument sync and async method calls Summary: `JSIExecutor::callSerializableNativeHook` converts the arguments from `JSI::Value` to `folly::dynamic`. Then, `RCTNativeModule` converts the arguments from `folly::dynamic` to ObjC data structures in its `static invokeInner` function. Therefore, I decided to start the sync markers inside `JSIExecutor::callSerializableNativeHook`, which required me to expose these two methode `ModuleRegistry::getModuleName` and `ModuleRegistry::getModuleSyncMethodName`. This shouldn't modify performance because we eagerly generate a NativeModule's methods when it's first required. So, at worst, this is doing a cache lookup. Changelog: [Internal] Reviewed By: PeteTheHeat Differential Revision: D21443610 fbshipit-source-id: 241c96f3f54729ec419d3e121f5bb651add6d3d5 --- React/CxxModule/RCTNativeModule.h | 1 + React/CxxModule/RCTNativeModule.mm | 101 ++++++++++++++++-- .../main/jni/react/jni/JavaModuleWrapper.cpp | 22 ++++ .../main/jni/react/jni/JavaModuleWrapper.h | 1 + .../src/main/jni/react/jni/MethodInvoker.cpp | 6 ++ .../src/main/jni/react/jni/MethodInvoker.h | 4 + ReactCommon/cxxreact/CxxNativeModule.cpp | 12 +++ ReactCommon/cxxreact/CxxNativeModule.h | 1 + ReactCommon/cxxreact/ModuleRegistry.cpp | 20 ++++ ReactCommon/cxxreact/ModuleRegistry.h | 5 + ReactCommon/cxxreact/NativeModule.h | 1 + .../jsiexecutor/jsireact/JSIExecutor.cpp | 51 +++++++-- .../jsiexecutor/jsireact/JSIExecutor.h | 1 + 13 files changed, 211 insertions(+), 15 deletions(-) diff --git a/React/CxxModule/RCTNativeModule.h b/React/CxxModule/RCTNativeModule.h index c73cf5f4ab7e..a59f9ae48181 100644 --- a/React/CxxModule/RCTNativeModule.h +++ b/React/CxxModule/RCTNativeModule.h @@ -16,6 +16,7 @@ class RCTNativeModule : public NativeModule { RCTNativeModule(RCTBridge *bridge, RCTModuleData *moduleData); std::string getName() override; + std::string getSyncMethodName(unsigned int methodId) override; std::vector getMethods() override; folly::dynamic getConstants() override; void invoke(unsigned int methodId, folly::dynamic &¶ms, int callId) diff --git a/React/CxxModule/RCTNativeModule.mm b/React/CxxModule/RCTNativeModule.mm index 00737371518d..e390f4d80238 100644 --- a/React/CxxModule/RCTNativeModule.mm +++ b/React/CxxModule/RCTNativeModule.mm @@ -15,16 +15,26 @@ #import #import #import +#import #ifdef WITH_FBSYSTRACE #include #endif +namespace { +enum SchedulingContext { Sync, Async }; +} + namespace facebook { namespace react { -static MethodCallResult -invokeInner(RCTBridge *bridge, RCTModuleData *moduleData, unsigned int methodId, const folly::dynamic ¶ms); +static MethodCallResult invokeInner( + RCTBridge *bridge, + RCTModuleData *moduleData, + unsigned int methodId, + const folly::dynamic ¶ms, + int callId, + SchedulingContext context); RCTNativeModule::RCTNativeModule(RCTBridge *bridge, RCTModuleData *moduleData) : m_bridge(bridge), m_moduleData(moduleData) @@ -36,6 +46,11 @@ return [m_moduleData.name UTF8String]; } +std::string RCTNativeModule::getSyncMethodName(unsigned int methodId) +{ + return m_moduleData.methods[methodId].JSMethodName; +} + std::vector RCTNativeModule::getMethods() { std::vector descs; @@ -58,13 +73,26 @@ void RCTNativeModule::invoke(unsigned int methodId, folly::dynamic &¶ms, int callId) { + const char *moduleName = [m_moduleData.name UTF8String]; + const char *methodName = m_moduleData.methods[methodId].JSMethodName; + + dispatch_queue_t queue = m_moduleData.methodQueue; + const bool isSyncModule = queue == RCTJSThread; + + if (isSyncModule) { + NativeModulePerfLogger::getInstance().syncMethodCallStart(moduleName, methodName); + NativeModulePerfLogger::getInstance().syncMethodCallArgConversionStart(moduleName, methodName); + } else { + NativeModulePerfLogger::getInstance().asyncMethodCallStart(moduleName, methodName); + } + // capture by weak pointer so that we can safely use these variables in a callback __weak RCTBridge *weakBridge = m_bridge; __weak RCTModuleData *weakModuleData = m_moduleData; // The BatchedBridge version of this buckets all the callbacks by thread, and // queues one block on each. This is much simpler; we'll see how it goes and // iterate. - dispatch_block_t block = [weakBridge, weakModuleData, methodId, params = std::move(params), callId] { + dispatch_block_t block = [weakBridge, weakModuleData, methodId, params = std::move(params), callId, isSyncModule] { #ifdef WITH_FBSYSTRACE if (callId != -1) { fbsystrace_end_async_flow(TRACE_TAG_REACT_APPS, "native", callId); @@ -72,13 +100,14 @@ #else (void)(callId); #endif - invokeInner(weakBridge, weakModuleData, methodId, std::move(params)); + invokeInner(weakBridge, weakModuleData, methodId, std::move(params), callId, isSyncModule ? Sync : Async); }; - dispatch_queue_t queue = m_moduleData.methodQueue; - if (queue == RCTJSThread) { + if (isSyncModule) { block(); + NativeModulePerfLogger::getInstance().syncMethodCallReturnConversionEnd(moduleName, methodName); } else if (queue) { + NativeModulePerfLogger::getInstance().asyncMethodCallDispatch(moduleName, methodName); dispatch_async(queue, block); } @@ -90,17 +119,36 @@ m_moduleData.name); } #endif + + if (isSyncModule) { + NativeModulePerfLogger::getInstance().syncMethodCallEnd(moduleName, methodName); + } else { + NativeModulePerfLogger::getInstance().asyncMethodCallEnd(moduleName, methodName); + } } MethodCallResult RCTNativeModule::callSerializableNativeHook(unsigned int reactMethodId, folly::dynamic &¶ms) { - return invokeInner(m_bridge, m_moduleData, reactMethodId, params); + return invokeInner(m_bridge, m_moduleData, reactMethodId, params, 0, Sync); } -static MethodCallResult -invokeInner(RCTBridge *bridge, RCTModuleData *moduleData, unsigned int methodId, const folly::dynamic ¶ms) +static MethodCallResult invokeInner( + RCTBridge *bridge, + RCTModuleData *moduleData, + unsigned int methodId, + const folly::dynamic ¶ms, + int callId, + SchedulingContext context) { if (!bridge || !bridge.valid || !moduleData) { + if (context == Sync) { + /** + * NOTE: moduleName and methodName are "". This shouldn't be an issue because there can only be one ongoing sync + * call at a time, and when we call syncMethodCallFail, that one call should terminate. This is also an + * exceptional scenario, so it shouldn't occur often. + */ + NativeModulePerfLogger::getInstance().syncMethodCallFail("N/A", "N/A"); + } return folly::none; } @@ -109,11 +157,46 @@ RCTLogError(@"Unknown methodID: %ud for module: %@", methodId, moduleData.name); } + const char *moduleName = [moduleData.name UTF8String]; + const char *methodName = moduleData.methods[methodId].JSMethodName; + + if (context == Async) { + NativeModulePerfLogger::getInstance().asyncMethodCallExecutionStart(moduleName, methodName, (int32_t)callId); + NativeModulePerfLogger::getInstance().asyncMethodCallExecutionArgConversionStart( + moduleName, methodName, (int32_t)callId); + } + NSArray *objcParams = convertFollyDynamicToId(params); + + if (context == Sync) { + NativeModulePerfLogger::getInstance().syncMethodCallArgConversionEnd(moduleName, methodName); + } + @try { + if (context == Sync) { + NativeModulePerfLogger::getInstance().syncMethodCallExecutionStart(moduleName, methodName); + } else { + NativeModulePerfLogger::getInstance().asyncMethodCallExecutionArgConversionEnd( + moduleName, methodName, (int32_t)callId); + } + id result = [method invokeWithBridge:bridge module:moduleData.instance arguments:objcParams]; + + if (context == Sync) { + NativeModulePerfLogger::getInstance().syncMethodCallExecutionEnd(moduleName, methodName); + NativeModulePerfLogger::getInstance().syncMethodCallReturnConversionStart(moduleName, methodName); + } else { + NativeModulePerfLogger::getInstance().asyncMethodCallExecutionEnd(moduleName, methodName, (int32_t)callId); + } + return convertIdToFollyDynamic(result); } @catch (NSException *exception) { + if (context == Sync) { + NativeModulePerfLogger::getInstance().syncMethodCallFail(moduleName, methodName); + } else { + NativeModulePerfLogger::getInstance().asyncMethodCallExecutionFail(moduleName, methodName, (int32_t)callId); + } + // Pass on JS exceptions if ([exception.name hasPrefix:RCTFatalExceptionName]) { @throw exception; diff --git a/ReactAndroid/src/main/jni/react/jni/JavaModuleWrapper.cpp b/ReactAndroid/src/main/jni/react/jni/JavaModuleWrapper.cpp index 0ad1f03b37b9..e8281b8f1cbe 100644 --- a/ReactAndroid/src/main/jni/react/jni/JavaModuleWrapper.cpp +++ b/ReactAndroid/src/main/jni/react/jni/JavaModuleWrapper.cpp @@ -50,6 +50,26 @@ std::string JavaNativeModule::getName() { return getNameMethod(wrapper_)->toStdString(); } +std::string JavaNativeModule::getSyncMethodName(unsigned int reactMethodId) { + if (reactMethodId >= syncMethods_.size()) { + throw std::invalid_argument(folly::to( + "methodId ", + reactMethodId, + " out of range [0..", + syncMethods_.size(), + "]")); + } + + auto &methodInvoker = syncMethods_[reactMethodId]; + + if (!methodInvoker.hasValue()) { + throw std::invalid_argument(folly::to( + "methodId ", reactMethodId, " is not a recognized sync method")); + } + + return methodInvoker->getMethodName(); +} + std::vector JavaNativeModule::getMethods() { std::vector ret; syncMethods_.clear(); @@ -69,6 +89,7 @@ std::vector JavaNativeModule::getMethods() { syncMethods_.begin() + methodIndex, MethodInvoker( desc->getMethod(), + methodName, desc->getSignature(), getName() + "." + methodName, true)); @@ -148,6 +169,7 @@ NewJavaNativeModule::NewJavaNativeModule( auto name = desc->getName(); methods_.emplace_back( desc->getMethod(), + desc->getName(), desc->getSignature(), moduleName + "." + name, type == "syncHook"); diff --git a/ReactAndroid/src/main/jni/react/jni/JavaModuleWrapper.h b/ReactAndroid/src/main/jni/react/jni/JavaModuleWrapper.h index 5c2d7cb9677f..f4b46ce66b4f 100644 --- a/ReactAndroid/src/main/jni/react/jni/JavaModuleWrapper.h +++ b/ReactAndroid/src/main/jni/react/jni/JavaModuleWrapper.h @@ -69,6 +69,7 @@ class JavaNativeModule : public NativeModule { messageQueueThread_(std::move(messageQueueThread)) {} std::string getName() override; + std::string getSyncMethodName(unsigned int reactMethodId) override; folly::dynamic getConstants() override; std::vector getMethods() override; void invoke(unsigned int reactMethodId, folly::dynamic &¶ms, int callId) diff --git a/ReactAndroid/src/main/jni/react/jni/MethodInvoker.cpp b/ReactAndroid/src/main/jni/react/jni/MethodInvoker.cpp index 571495b77232..496a99cdca3a 100644 --- a/ReactAndroid/src/main/jni/react/jni/MethodInvoker.cpp +++ b/ReactAndroid/src/main/jni/react/jni/MethodInvoker.cpp @@ -190,10 +190,12 @@ std::size_t countJsArgs(const std::string &signature) { MethodInvoker::MethodInvoker( alias_ref method, + std::string methodName, std::string signature, std::string traceName, bool isSync) : method_(method->getMethodID()), + methodName_(methodName), signature_(signature), jsArgCount_(countJsArgs(signature) - 2), traceName_(std::move(traceName)), @@ -203,6 +205,10 @@ MethodInvoker::MethodInvoker( << "Non-sync hooks cannot have a non-void return type"; } +std::string MethodInvoker::getMethodName() const { + return methodName_; +} + MethodCallResult MethodInvoker::invoke( std::weak_ptr &instance, alias_ref module, diff --git a/ReactAndroid/src/main/jni/react/jni/MethodInvoker.h b/ReactAndroid/src/main/jni/react/jni/MethodInvoker.h index ee3eb087dddb..67f5fc06d637 100644 --- a/ReactAndroid/src/main/jni/react/jni/MethodInvoker.h +++ b/ReactAndroid/src/main/jni/react/jni/MethodInvoker.h @@ -37,6 +37,7 @@ class MethodInvoker { public: MethodInvoker( jni::alias_ref method, + std::string methodName, std::string signature, std::string traceName, bool isSync); @@ -46,12 +47,15 @@ class MethodInvoker { jni::alias_ref module, const folly::dynamic ¶ms); + std::string getMethodName() const; + bool isSyncHook() const { return isSync_; } private: jmethodID method_; + std::string methodName_; std::string signature_; std::size_t jsArgCount_; std::string traceName_; diff --git a/ReactCommon/cxxreact/CxxNativeModule.cpp b/ReactCommon/cxxreact/CxxNativeModule.cpp index 94ab82bfe0bd..bfbb608553b5 100644 --- a/ReactCommon/cxxreact/CxxNativeModule.cpp +++ b/ReactCommon/cxxreact/CxxNativeModule.cpp @@ -58,6 +58,18 @@ std::string CxxNativeModule::getName() { return name_; } +std::string CxxNativeModule::getSyncMethodName(unsigned int reactMethodId) { + if (reactMethodId >= methods_.size()) { + throw std::invalid_argument(folly::to( + "methodId ", + reactMethodId, + " out of range [0..", + methods_.size(), + "]")); + } + return methods_[reactMethodId].name; +} + std::vector CxxNativeModule::getMethods() { lazyInit(); diff --git a/ReactCommon/cxxreact/CxxNativeModule.h b/ReactCommon/cxxreact/CxxNativeModule.h index 2c2230409d13..9d730ff79424 100644 --- a/ReactCommon/cxxreact/CxxNativeModule.h +++ b/ReactCommon/cxxreact/CxxNativeModule.h @@ -37,6 +37,7 @@ class RN_EXPORT CxxNativeModule : public NativeModule { messageQueueThread_(messageQueueThread) {} std::string getName() override; + std::string getSyncMethodName(unsigned int methodId) override; std::vector getMethods() override; folly::dynamic getConstants() override; void invoke(unsigned int reactMethodId, folly::dynamic &¶ms, int callId) diff --git a/ReactCommon/cxxreact/ModuleRegistry.cpp b/ReactCommon/cxxreact/ModuleRegistry.cpp index ccffe90c0fcc..ac39f9755176 100644 --- a/ReactCommon/cxxreact/ModuleRegistry.cpp +++ b/ReactCommon/cxxreact/ModuleRegistry.cpp @@ -195,6 +195,26 @@ folly::Optional ModuleRegistry::getConfig( } } +std::string ModuleRegistry::getModuleName(unsigned int moduleId) { + if (moduleId >= modules_.size()) { + throw std::runtime_error(folly::to( + "moduleId ", moduleId, " out of range [0..", modules_.size(), ")")); + } + + return modules_[moduleId]->getName(); +} + +std::string ModuleRegistry::getModuleSyncMethodName( + unsigned int moduleId, + unsigned int methodId) { + if (moduleId >= modules_.size()) { + throw std::runtime_error(folly::to( + "moduleId ", moduleId, " out of range [0..", modules_.size(), ")")); + } + + return modules_[moduleId]->getSyncMethodName(methodId); +} + void ModuleRegistry::callNativeMethod( unsigned int moduleId, unsigned int methodId, diff --git a/ReactCommon/cxxreact/ModuleRegistry.h b/ReactCommon/cxxreact/ModuleRegistry.h index b24f5390e30f..fba4496a6217 100644 --- a/ReactCommon/cxxreact/ModuleRegistry.h +++ b/ReactCommon/cxxreact/ModuleRegistry.h @@ -59,6 +59,11 @@ class RN_EXPORT ModuleRegistry { unsigned int methodId, folly::dynamic &&args); + std::string getModuleName(unsigned int moduleId); + std::string getModuleSyncMethodName( + unsigned int moduleId, + unsigned int methodName); + private: // This is always populated std::vector> modules_; diff --git a/ReactCommon/cxxreact/NativeModule.h b/ReactCommon/cxxreact/NativeModule.h index 6e7287cf469c..2441953b4a04 100644 --- a/ReactCommon/cxxreact/NativeModule.h +++ b/ReactCommon/cxxreact/NativeModule.h @@ -31,6 +31,7 @@ class NativeModule { public: virtual ~NativeModule() {} virtual std::string getName() = 0; + virtual std::string getSyncMethodName(unsigned int methodId) = 0; virtual std::vector getMethods() = 0; virtual folly::dynamic getConstants() = 0; virtual void diff --git a/ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp b/ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp index 42f3eac590fb..40655460d271 100644 --- a/ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp +++ b/ReactCommon/jsiexecutor/jsireact/JSIExecutor.cpp @@ -7,6 +7,7 @@ #include "jsireact/JSIExecutor.h" +#include #include #include #include @@ -16,7 +17,6 @@ #include #include #include -#include #include #include @@ -72,6 +72,7 @@ JSIExecutor::JSIExecutor( delegate_(delegate), nativeModules_(std::make_shared( delegate ? delegate->getModuleRegistry() : nullptr)), + moduleRegistry_(delegate ? delegate->getModuleRegistry() : nullptr), scopedTimeoutInvoker_(scopedTimeoutInvoker), runtimeInstaller_(runtimeInstaller) { runtime_->global().setProperty( @@ -443,16 +444,54 @@ Value JSIExecutor::nativeCallSyncHook(const Value *args, size_t count) { folly::to("method parameters should be array")); } + unsigned int moduleId = static_cast(args[0].getNumber()); + unsigned int methodId = static_cast(args[1].getNumber()); + std::string moduleName; + std::string methodName; + + if (moduleRegistry_) { + moduleName = moduleRegistry_->getModuleName(moduleId); + methodName = moduleRegistry_->getModuleSyncMethodName(moduleId, methodId); + + NativeModulePerfLogger::getInstance().syncMethodCallStart( + moduleName.c_str(), methodName.c_str()); + + NativeModulePerfLogger::getInstance().syncMethodCallArgConversionStart( + moduleName.c_str(), methodName.c_str()); + } + MethodCallResult result = delegate_->callSerializableNativeHook( - *this, - static_cast(args[0].getNumber()), // moduleId - static_cast(args[1].getNumber()), // methodId - dynamicFromValue(*runtime_, args[2])); // args + *this, moduleId, methodId, dynamicFromValue(*runtime_, args[2])); + + /** + * Note: + * In RCTNativeModule, folly::none is returned from callSerializableNativeHook + * when executing a NativeModule method fails. Therefore, it's safe to not + * terminate the syncMethodCall when folly::none is returned. + * + * TODO: In JavaNativeModule, folly::none is returned when the synchronous + * NativeModule method has the void return type. Change this to return + * folly::dynamic(nullptr) instead, so that folly::none is reserved for + * exceptional scenarios. + * + * TODO: Investigate CxxModule infra to see if folly::none is used for + * returns in exceptional scenarios. + **/ if (!result.hasValue()) { return Value::undefined(); } - return valueFromDynamic(*runtime_, result.value()); + + Value returnValue = valueFromDynamic(*runtime_, result.value()); + + if (moduleRegistry_) { + NativeModulePerfLogger::getInstance().syncMethodCallReturnConversionEnd( + moduleName.c_str(), methodName.c_str()); + NativeModulePerfLogger::getInstance().syncMethodCallEnd( + moduleName.c_str(), methodName.c_str()); + } + + return returnValue; } #if DEBUG diff --git a/ReactCommon/jsiexecutor/jsireact/JSIExecutor.h b/ReactCommon/jsiexecutor/jsireact/JSIExecutor.h index 2cd3776baf52..615172ed711c 100644 --- a/ReactCommon/jsiexecutor/jsireact/JSIExecutor.h +++ b/ReactCommon/jsiexecutor/jsireact/JSIExecutor.h @@ -123,6 +123,7 @@ class JSIExecutor : public JSExecutor { std::shared_ptr runtime_; std::shared_ptr delegate_; std::shared_ptr nativeModules_; + std::shared_ptr moduleRegistry_; std::once_flag bindFlag_; std::unique_ptr bundleRegistry_; JSIScopedTimeoutInvoker scopedTimeoutInvoker_;