Use dispatch_async instead of lock

Summary: public

The initial implementation used a lock to manage the stored profile information,
blocking the caller thread for longer than it should. Replace it with a private
queue, since the only thing we need to from the caller is to record the immediate
call time and the caller thread/queue, all the rest has absolutely no priority.

Use macros to also defer work done when generate the name of the events.

Reviewed By: nicklockwood

Differential Revision: D2603120

fb-gh-sync-id: e3e36160c893e7ae9ed3558f07c854ea76396661
This commit is contained in:
Tadeu Zagallo 2015-11-04 09:00:01 -08:00 committed by facebook-github-bot-3
parent 02a8c38361
commit 0c74804427
3 changed files with 140 additions and 84 deletions

View File

@ -868,9 +868,10 @@ RCT_NOT_IMPLEMENTED(- (instancetype)initWithBundleURL:(__unused NSURL *)bundleUR
RCTAssertMainThread();
[_javaScriptExecutor executeBlockOnJavaScriptQueue:^{
NSString *log = RCTProfileEnd(self);
NSData *logData = [log dataUsingEncoding:NSUTF8StringEncoding];
callback(logData);
RCTProfileEnd(self, ^(NSString *log) {
NSData *logData = [log dataUsingEncoding:NSUTF8StringEncoding];
callback(logData);
});
}];
}

View File

@ -36,6 +36,8 @@ _Pragma("clang diagnostic pop")
#define RCTProfileEndFlowEvent() \
_RCTProfileEndFlowEvent(__rct_profile_flow_id)
RCT_EXTERN dispatch_queue_t RCTProfileGetQueue(void);
RCT_EXTERN NSNumber *_RCTProfileBeginFlowEvent(void);
RCT_EXTERN void _RCTProfileEndFlowEvent(NSNumber *);
@ -54,23 +56,44 @@ RCT_EXTERN void RCTProfileInit(RCTBridge *);
* returned is compliant with google's trace event format - the format used
* as input to trace-viewer
*/
RCT_EXTERN NSString *RCTProfileEnd(RCTBridge *);
RCT_EXTERN void RCTProfileEnd(RCTBridge *, void (^)(NSString *));
/**
* Collects the initial event information for the event and returns a reference ID
*/
RCT_EXTERN void RCTProfileBeginEvent(uint64_t tag,
NSString *name,
NSDictionary *args);
RCT_EXTERN void _RCTProfileBeginEvent(NSThread *calleeThread,
NSTimeInterval time,
uint64_t tag,
NSString *name,
NSDictionary *args);
#define RCTProfileBeginEvent(...) { \
NSThread *calleeThread = [NSThread currentThread]; \
NSTimeInterval time = CACurrentMediaTime(); \
dispatch_async(RCTProfileGetQueue(), ^{ \
_RCTProfileBeginEvent(calleeThread, time, __VA_ARGS__); \
}); \
}
/**
* The ID returned by BeginEvent should then be passed into EndEvent, with the
* rest of the event information. Just at this point the event will actually be
* registered
*/
RCT_EXTERN void RCTProfileEndEvent(uint64_t tag,
NSString *category,
NSDictionary *args);
RCT_EXTERN void _RCTProfileEndEvent(NSThread *calleeThread,
NSString *threadName,
NSTimeInterval time,
uint64_t tag,
NSString *category,
NSDictionary *args);
#define RCTProfileEndEvent(...) { \
NSThread *calleeThread = [NSThread currentThread]; \
NSString *threadName = RCTCurrentThreadName(); \
NSTimeInterval time = CACurrentMediaTime(); \
dispatch_async(RCTProfileGetQueue(), ^{ \
_RCTProfileEndEvent(calleeThread, threadName, time, __VA_ARGS__); \
}); \
}
/**
* Collects the initial event information for the event and returns a reference ID
@ -89,6 +112,7 @@ RCT_EXTERN void RCTProfileEndAsyncEvent(uint64_t tag,
int cookie,
NSString *name,
NSDictionary *args);
/**
* An event that doesn't have a duration (i.e. Notification, VSync, etc)
*/
@ -123,7 +147,7 @@ RCT_EXTERN void RCTProfileUnhookModules(RCTBridge *);
* Send systrace or cpu profiling information to the packager
* to present to the user
*/
RCT_EXTERN void RCTProfileSendResult(RCTBridge *bridge, NSString *route, NSData *profielData);
RCT_EXTERN void RCTProfileSendResult(RCTBridge *bridge, NSString *route, NSData *profileData);
/**
* Systrace gluecode

View File

@ -11,6 +11,7 @@
#import <dlfcn.h>
#import <libkern/OSAtomic.h>
#import <mach/mach.h>
#import <objc/message.h>
#import <objc/runtime.h>
@ -37,7 +38,7 @@ NSString *const RCTProfilePrefix = @"rct_profile_";
#pragma mark - Variables
static BOOL RCTProfileProfiling;
static volatile uint32_t RCTProfileProfiling;
static NSDictionary *RCTProfileInfo;
static NSMutableDictionary *RCTProfileOngoingEvents;
static NSTimeInterval RCTProfileStartTime;
@ -48,7 +49,6 @@ static NSUInteger RCTProfileEventID = 0;
#define RCTProfileAddEvent(type, props...) \
[RCTProfileInfo[type] addObject:@{ \
@"pid": @([[NSProcessInfo processInfo] processIdentifier]), \
@"tid": RCTCurrentThreadName(), \
props \
}];
@ -57,11 +57,6 @@ if (!RCTProfileIsProfiling()) { \
return __VA_ARGS__; \
}
#define RCTProfileLock(...) \
[_RCTProfileLock() lock]; \
__VA_ARGS__ \
[_RCTProfileLock() unlock]
#pragma mark - systrace glue code
static RCTProfileCallbacks *callbacks;
@ -95,18 +90,6 @@ void RCTProfileRegisterCallbacks(RCTProfileCallbacks *cb)
#pragma mark - Private Helpers
static NSLock *_RCTProfileLock()
{
static dispatch_once_t token;
static NSLock *lock;
dispatch_once(&token, ^{
lock = [NSLock new];
lock.name = @"RCTProfileLock";
});
return lock;
}
static NSNumber *RCTProfileTimestamp(NSTimeInterval timestamp)
{
return @((timestamp - RCTProfileStartTime) * 1e6);
@ -276,109 +259,136 @@ void RCTProfileUnhookModules(RCTBridge *bridge)
#pragma mark - Public Functions
dispatch_queue_t RCTProfileGetQueue(void)
{
static dispatch_queue_t queue;
static dispatch_once_t onceToken;
dispatch_once(&onceToken, ^{
queue = dispatch_queue_create("com.facebook.react.Profiler", DISPATCH_QUEUE_SERIAL);
});
return queue;
}
BOOL RCTProfileIsProfiling(void)
{
return RCTProfileProfiling;
return (BOOL)OSAtomicAnd32(1, &RCTProfileProfiling);
}
void RCTProfileInit(RCTBridge *bridge)
{
RCTProfileHookModules(bridge);
RCTProfileProfiling = YES;
// TODO: enable assert JS thread from any file (and assert here)
OSAtomicOr32(1, &RCTProfileProfiling);
if (callbacks != NULL) {
size_t buffer_size = 1 << 22;
systrace_buffer = calloc(1, buffer_size);
callbacks->start(~((uint64_t)0), systrace_buffer, buffer_size);
} else {
RCTProfileLock(
RCTProfileStartTime = CACurrentMediaTime();
NSTimeInterval time = CACurrentMediaTime();
dispatch_async(RCTProfileGetQueue(), ^{
RCTProfileStartTime = time;
RCTProfileOngoingEvents = [NSMutableDictionary new];
RCTProfileInfo = @{
RCTProfileTraceEvents: [NSMutableArray new],
RCTProfileSamples: [NSMutableArray new],
};
);
});
}
RCTProfileHookModules(bridge);
[[NSNotificationCenter defaultCenter] postNotificationName:RCTProfileDidStartProfiling
object:nil];
}
NSString *RCTProfileEnd(RCTBridge *bridge)
void RCTProfileEnd(RCTBridge *bridge, void (^callback)(NSString *))
{
// assert JavaScript thread here again
if (!RCTProfileIsProfiling()) {
return nil;
return;
}
OSAtomicAnd32(0, &RCTProfileProfiling);
[[NSNotificationCenter defaultCenter] postNotificationName:RCTProfileDidEndProfiling
object:nil];
RCTProfileProfiling = NO;
RCTProfileLock(
RCTProfileUnhookModules(bridge);
);
RCTProfileUnhookModules(bridge);
if (callbacks != NULL) {
callbacks->stop();
return @(systrace_buffer);
callback(@(systrace_buffer));
} else {
RCTProfileLock(
dispatch_async(RCTProfileGetQueue(), ^{
NSString *log = RCTJSONStringify(RCTProfileInfo, NULL);
RCTProfileEventID = 0;
RCTProfileInfo = nil;
RCTProfileOngoingEvents = nil;
);
return log;
callback(log);
});
}
}
static NSMutableArray<NSArray *> *RCTProfileGetThreadEvents(void)
static NSMutableArray<NSArray *> *RCTProfileGetThreadEvents(NSThread *thread)
{
static NSString *const RCTProfileThreadEventsKey = @"RCTProfileThreadEventsKey";
NSMutableArray<NSArray *> *threadEvents =
[NSThread currentThread].threadDictionary[RCTProfileThreadEventsKey];
thread.threadDictionary[RCTProfileThreadEventsKey];
if (!threadEvents) {
threadEvents = [NSMutableArray new];
[NSThread currentThread].threadDictionary[RCTProfileThreadEventsKey] = threadEvents;
thread.threadDictionary[RCTProfileThreadEventsKey] = threadEvents;
}
return threadEvents;
}
void RCTProfileBeginEvent(uint64_t tag, NSString *name, NSDictionary *args)
{
void _RCTProfileBeginEvent(
NSThread *calleeThread,
NSTimeInterval time,
uint64_t tag,
NSString *name,
NSDictionary *args
) {
CHECK();
RCTAssertThread(RCTProfileGetQueue(), @"Must be called RCTProfile queue");;
if (callbacks != NULL) {
callbacks->begin_section(tag, name.UTF8String, args.count, RCTProfileSystraceArgsFromNSDictionary(args));
return;
}
NSMutableArray *events = RCTProfileGetThreadEvents();
NSMutableArray *events = RCTProfileGetThreadEvents(calleeThread);
[events addObject:@[
RCTProfileTimestamp(CACurrentMediaTime()),
RCTProfileTimestamp(time),
@(tag),
name,
RCTNullIfNil(args),
]];
}
void RCTProfileEndEvent(
void _RCTProfileEndEvent(
NSThread *calleeThread,
NSString *threadName,
NSTimeInterval time,
uint64_t tag,
NSString *category,
NSDictionary *args
) {
CHECK();
RCTAssertThread(RCTProfileGetQueue(), @"Must be called RCTProfile queue");;
if (callbacks != NULL) {
callbacks->end_section(tag, args.count, RCTProfileSystraceArgsFromNSDictionary(args));
return;
}
NSMutableArray<NSArray *> *events = RCTProfileGetThreadEvents();
NSMutableArray<NSArray *> *events = RCTProfileGetThreadEvents(calleeThread);
NSArray *event = events.lastObject;
[events removeLastObject];
@ -388,15 +398,14 @@ void RCTProfileEndEvent(
NSNumber *start = event[0];
RCTProfileLock(
RCTProfileAddEvent(RCTProfileTraceEvents,
@"name": event[2],
@"cat": category,
@"ph": @"X",
@"ts": start,
@"dur": @(RCTProfileTimestamp(CACurrentMediaTime()).doubleValue - start.doubleValue),
@"args": RCTProfileMergeArgs(event[3], args),
);
RCTProfileAddEvent(RCTProfileTraceEvents,
@"tid": threadName,
@"name": event[2],
@"cat": category,
@"ph": @"X",
@"ts": start,
@"dur": @(RCTProfileTimestamp(time).doubleValue - start.doubleValue),
@"args": RCTProfileMergeArgs(event[3], args),
);
}
@ -409,19 +418,22 @@ int RCTProfileBeginAsyncEvent(
static int eventID = 0;
NSTimeInterval time = CACurrentMediaTime();
int currentEventID = ++eventID;
if (callbacks != NULL) {
callbacks->begin_async_section(tag, name.UTF8String, eventID, args.count, RCTProfileSystraceArgsFromNSDictionary(args));
} else {
RCTProfileLock(
RCTProfileOngoingEvents[@(eventID)] = @[
RCTProfileTimestamp(CACurrentMediaTime()),
dispatch_async(RCTProfileGetQueue(), ^{
RCTProfileOngoingEvents[@(currentEventID)] = @[
RCTProfileTimestamp(time),
name,
RCTNullIfNil(args),
];
);
});
}
return eventID++;
return currentEventID;
}
void RCTProfileEndAsyncEvent(
@ -438,12 +450,17 @@ void RCTProfileEndAsyncEvent(
return;
}
RCTProfileLock(
NSTimeInterval time = CACurrentMediaTime();
NSString *threadName = RCTCurrentThreadName();
dispatch_async(RCTProfileGetQueue(), ^{
NSArray *event = RCTProfileOngoingEvents[@(cookie)];
if (event) {
NSNumber *endTimestamp = RCTProfileTimestamp(CACurrentMediaTime());
NSNumber *endTimestamp = RCTProfileTimestamp(time);
RCTProfileAddEvent(RCTProfileTraceEvents,
@"tid": threadName,
@"name": event[1],
@"cat": category,
@"ph": @"X",
@ -453,7 +470,7 @@ void RCTProfileEndAsyncEvent(
);
[RCTProfileOngoingEvents removeObjectForKey:@(cookie)];
}
);
});
}
void RCTProfileImmediateEvent(
@ -468,15 +485,19 @@ void RCTProfileImmediateEvent(
return;
}
RCTProfileLock(
NSTimeInterval time = CACurrentMediaTime();
NSString *threadName = RCTCurrentThreadName();
dispatch_async(RCTProfileGetQueue(), ^{
RCTProfileAddEvent(RCTProfileTraceEvents,
@"tid": threadName,
@"name": name,
@"ts": RCTProfileTimestamp(CACurrentMediaTime()),
@"ts": RCTProfileTimestamp(time),
@"scope": @(scope),
@"ph": @"i",
@"args": RCTProfileGetMemoryUsage(),
);
);
});
}
NSNumber *_RCTProfileBeginFlowEvent(void)
@ -490,17 +511,23 @@ NSNumber *_RCTProfileBeginFlowEvent(void)
return @0;
}
RCTProfileLock(
NSTimeInterval time = CACurrentMediaTime();
NSNumber *currentID = @(++flowID);
NSString *threadName = RCTCurrentThreadName();
dispatch_async(RCTProfileGetQueue(), ^{
RCTProfileAddEvent(RCTProfileTraceEvents,
@"tid": threadName,
@"name": @"flow",
@"id": @(++flowID),
@"id": currentID,
@"cat": @"flow",
@"ph": @"s",
@"ts": RCTProfileTimestamp(CACurrentMediaTime()),
@"ts": RCTProfileTimestamp(time),
);
);
return @(flowID);
});
return currentID;
}
void _RCTProfileEndFlowEvent(NSNumber *flowID)
@ -511,15 +538,19 @@ void _RCTProfileEndFlowEvent(NSNumber *flowID)
return;
}
RCTProfileLock(
NSTimeInterval time = CACurrentMediaTime();
NSString *threadName = RCTCurrentThreadName();
dispatch_async(RCTProfileGetQueue(), ^{
RCTProfileAddEvent(RCTProfileTraceEvents,
@"tid": threadName,
@"name": @"flow",
@"id": flowID,
@"cat": @"flow",
@"ph": @"f",
@"ts": RCTProfileTimestamp(CACurrentMediaTime()),
@"ts": RCTProfileTimestamp(time),
);
);
});
}
void RCTProfileSendResult(RCTBridge *bridge, NSString *route, NSData *data)