diff --git a/React/Base/RCTBridge.m b/React/Base/RCTBridge.m index f122611cd..70868f721 100644 --- a/React/Base/RCTBridge.m +++ b/React/Base/RCTBridge.m @@ -1339,8 +1339,11 @@ RCT_INNER_BRIDGE_ONLY(_invokeAndProcessModule:(NSString *)module method:(NSStrin * AnyThread */ + RCTProfileBeginFlowEvent(); + __weak RCTBatchedBridge *weakSelf = self; [_javaScriptExecutor executeBlockOnJavaScriptQueue:^{ + RCTProfileEndFlowEvent(); RCTProfileBeginEvent(); RCTBatchedBridge *strongSelf = weakSelf; @@ -1348,13 +1351,17 @@ RCT_INNER_BRIDGE_ONLY(_invokeAndProcessModule:(NSString *)module method:(NSStrin return; } - id call = @{ - @"module": module, - @"method": method, - @"args": args, - @"context": context ?: @0, - }; + RCT_IF_DEV(NSNumber *callID = _RCTProfileBeginFlowEvent();) + id call = @{ + @"js_args": @{ + @"module": module, + @"method": method, + @"args": args, + }, + @"context": context ?: @0, + RCT_IF_DEV(@"call_id": callID,) + }; if ([method isEqualToString:@"invokeCallbackAndReturnFlushedQueue"]) { strongSelf->_scheduledCallbacks[args[0]] = call; } else { @@ -1490,8 +1497,10 @@ RCT_INNER_BRIDGE_ONLY(_invokeAndProcessModule:(NSString *)module method:(NSStrin return NO; } + RCTProfileBeginFlowEvent(); __weak RCTBatchedBridge *weakSelf = self; [self dispatchBlock:^{ + RCTProfileEndFlowEvent(); RCTProfileBeginEvent(); RCTBatchedBridge *strongSelf = weakSelf; @@ -1525,16 +1534,18 @@ RCT_INNER_BRIDGE_ONLY(_invokeAndProcessModule:(NSString *)module method:(NSStrin - (void)_jsThreadUpdate:(CADisplayLink *)displayLink { RCTAssertJSThread(); - - RCTProfileImmediateEvent(@"JS Thread Tick", displayLink.timestamp, @"g"); - RCTProfileBeginEvent(); RCTFrameUpdate *frameUpdate = [[RCTFrameUpdate alloc] initWithDisplayLink:displayLink]; for (id observer in _frameUpdateObservers) { if (![observer respondsToSelector:@selector(isPaused)] || ![observer isPaused]) { + RCT_IF_DEV(NSString *name = [NSString stringWithFormat:@"[%@ didUpdateFrame:%f]", observer, displayLink.timestamp];) + RCTProfileBeginFlowEvent(); [self dispatchBlock:^{ + RCTProfileEndFlowEvent(); + RCTProfileBeginEvent(); [observer didUpdateFrame:frameUpdate]; + RCTProfileEndEvent(name, @"objc_call,fps", nil); } forModule:RCTModuleIDsByName[RCTBridgeModuleNameForClass([observer class])]]; } } @@ -1544,12 +1555,21 @@ RCT_INNER_BRIDGE_ONLY(_invokeAndProcessModule:(NSString *)module method:(NSStrin calls = [calls filteredArrayUsingPredicate:[NSPredicate predicateWithBlock:^BOOL(NSDictionary *call, NSDictionary *bindings) { return [call[@"context"] isEqualToNumber:currentExecutorID]; }]]; + + RCT_IF_DEV( + RCTProfileImmediateEvent(@"JS Thread Tick", displayLink.timestamp, @"g"); + + for (NSDictionary *call in calls) { + _RCTProfileEndFlowEvent(call[@"call_id"]); + } + ) + if (calls.count > 0) { _scheduledCalls = [[NSMutableArray alloc] init]; _scheduledCallbacks = [[RCTSparseArray alloc] init]; [self _actuallyInvokeAndProcessModule:@"BatchedBridge" method:@"processBatch" - arguments:@[calls] + arguments:@[[calls valueForKey:@"js_args"]] context:RCTGetExecutorID(_javaScriptExecutor)]; } diff --git a/React/Base/RCTDefines.h b/React/Base/RCTDefines.h index 71550a30d..0d985db8a 100644 --- a/React/Base/RCTDefines.h +++ b/React/Base/RCTDefines.h @@ -42,6 +42,12 @@ #endif #endif +#if RCT_DEV +#define RCT_IF_DEV(...) __VA_ARGS__ +#else +#define RCT_IF_DEV(...) +#endif + /** * By default, only raise an NSAssertion in debug mode * (custom assert functions will still be called). diff --git a/React/Base/RCTProfile.h b/React/Base/RCTProfile.h index 6ac9d1c0f..f722b0a02 100644 --- a/React/Base/RCTProfile.h +++ b/React/Base/RCTProfile.h @@ -25,6 +25,18 @@ NSString *const RCTProfileDidEndProfiling; #if RCT_DEV +#define RCTProfileBeginFlowEvent() \ +_Pragma("clang diagnostic push") \ +_Pragma("clang diagnostic ignored \"-Wshadow\"") \ +NSNumber *__rct_profile_flow_id = _RCTProfileBeginFlowEvent(); \ +_Pragma("clang diagnostic pop") + +#define RCTProfileEndFlowEvent() \ +_RCTProfileEndFlowEvent(__rct_profile_flow_id) + +RCT_EXTERN NSNumber *_RCTProfileBeginFlowEvent(void); +RCT_EXTERN void _RCTProfileEndFlowEvent(NSNumber *); + /** * Returns YES if the profiling information is currently being collected */ @@ -91,6 +103,12 @@ RCT_EXTERN void RCTProfileImmediateEvent(NSString *, NSTimeInterval , NSString * #else +#define RCTProfileBeginFlowEvent() +#define _RCTProfileBeginFlowEvent() @0 + +#define RCTProfileEndFlowEvent() +#define _RCTProfileEndFlowEvent() + #define RCTProfileIsProfiling(...) NO #define RCTProfileInit(...) #define RCTProfileEnd(...) @"" diff --git a/React/Base/RCTProfile.m b/React/Base/RCTProfile.m index 9b7743494..09989d1cb 100644 --- a/React/Base/RCTProfile.m +++ b/React/Base/RCTProfile.m @@ -180,4 +180,32 @@ void RCTProfileImmediateEvent(NSString *name, NSTimeInterval timestamp, NSString ); } +NSNumber *_RCTProfileBeginFlowEvent(void) +{ + static NSUInteger flowID = 0; + + CHECK(@0); + RCTProfileAddEvent(RCTProfileTraceEvents, + @"name": @"flow", + @"id": @(++flowID), + @"cat": @"flow", + @"ph": @"s", + @"ts": RCTProfileTimestamp(CACurrentMediaTime()), + ); + + return @(flowID); +} + +void _RCTProfileEndFlowEvent(NSNumber *flowID) +{ + CHECK(); + RCTProfileAddEvent(RCTProfileTraceEvents, + @"name": @"flow", + @"id": flowID, + @"cat": @"flow", + @"ph": @"f", + @"ts": RCTProfileTimestamp(CACurrentMediaTime()), + ); +} + #endif