[iOS] output render timeline on iOS

Author: jianhan-he

ios/sdk/WeexSDK.xcodeproj/project.pbxproj

@@ -272,8 +272,6 @@
 		74FD6E041C7C0E9600DBEB6D /* WXScrollerProtocol.h in Headers */ = {isa = PBXBuildFile; fileRef = 74FD6E031C7C0E9600DBEB6D /* WXScrollerProtocol.h */; settings = {ATTRIBUTES = (Public, ); }; };
 		7704894822AA358500E7606F /* WXConsoleLogModule.h in Headers */ = {isa = PBXBuildFile; fileRef = 7704894622AA358400E7606F /* WXConsoleLogModule.h */; };
 		7704894922AA358500E7606F /* WXConsoleLogModule.h in Headers */ = {isa = PBXBuildFile; fileRef = 7704894622AA358400E7606F /* WXConsoleLogModule.h */; };
-		7704894A22AA358500E7606F /* WXConsoleLogModule.m in Sources */ = {isa = PBXBuildFile; fileRef = 7704894722AA358400E7606F /* WXConsoleLogModule.m */; };
-		7704894B22AA358500E7606F /* WXConsoleLogModule.m in Sources */ = {isa = PBXBuildFile; fileRef = 7704894722AA358400E7606F /* WXConsoleLogModule.m */; };
 		7715EB6221A69DD9001F1108 /* WXRichText.h in Headers */ = {isa = PBXBuildFile; fileRef = 7715EB6021A69DD8001F1108 /* WXRichText.h */; settings = {ATTRIBUTES = (Public, ); }; };
 		7715EB6321A69DD9001F1108 /* WXRichText.h in Headers */ = {isa = PBXBuildFile; fileRef = 7715EB6021A69DD8001F1108 /* WXRichText.h */; settings = {ATTRIBUTES = (Public, ); }; };
 		7715EB6421A69DD9001F1108 /* WXRichText.mm in Sources */ = {isa = PBXBuildFile; fileRef = 7715EB6121A69DD9001F1108 /* WXRichText.mm */; };
@@ -551,6 +549,8 @@
 		BA5F00F21FC5AFFE00F76B5C /* WXLocaleModule.m in Sources */ = {isa = PBXBuildFile; fileRef = BA5F00F01FC5AFFE00F76B5C /* WXLocaleModule.m */; };
 		BA5F00F31FC6834900F76B5C /* WXLocaleModule.h in Headers */ = {isa = PBXBuildFile; fileRef = BA5F00EF1FC5AFFE00F76B5C /* WXLocaleModule.h */; };
 		BA5F00F41FC6834C00F76B5C /* WXLocaleModule.m in Sources */ = {isa = PBXBuildFile; fileRef = BA5F00F01FC5AFFE00F76B5C /* WXLocaleModule.m */; };
+		BD35ADEA2303BEA60050ED82 /* WXConsoleLogModule.mm in Sources */ = {isa = PBXBuildFile; fileRef = BD35ADE92303BEA60050ED82 /* WXConsoleLogModule.mm */; };
+		BD35ADEB2303BEA60050ED82 /* WXConsoleLogModule.mm in Sources */ = {isa = PBXBuildFile; fileRef = BD35ADE92303BEA60050ED82 /* WXConsoleLogModule.mm */; };
 		BD88C13722F02101004467AA /* render_action_add_child_to_richtext.cpp in Sources */ = {isa = PBXBuildFile; fileRef = BD88C13522F02101004467AA /* render_action_add_child_to_richtext.cpp */; };
 		BD88C13822F02101004467AA /* render_action_add_child_to_richtext.cpp in Sources */ = {isa = PBXBuildFile; fileRef = BD88C13522F02101004467AA /* render_action_add_child_to_richtext.cpp */; };
 		BD88C13922F02101004467AA /* render_action_add_child_to_richtext.h in Headers */ = {isa = PBXBuildFile; fileRef = BD88C13622F02101004467AA /* render_action_add_child_to_richtext.h */; };
@@ -1142,7 +1142,6 @@
 		74F7BFF41DC782EC004D0871 /* testRootView.js */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.javascript; path = testRootView.js; sourceTree = "<group>"; };
 		74FD6E031C7C0E9600DBEB6D /* WXScrollerProtocol.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = WXScrollerProtocol.h; sourceTree = "<group>"; };
 		7704894622AA358400E7606F /* WXConsoleLogModule.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = WXConsoleLogModule.h; sourceTree = "<group>"; };
-		7704894722AA358400E7606F /* WXConsoleLogModule.m */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.objc; path = WXConsoleLogModule.m; sourceTree = "<group>"; };
 		7715EB6021A69DD8001F1108 /* WXRichText.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = WXRichText.h; sourceTree = "<group>"; };
 		7715EB6121A69DD9001F1108 /* WXRichText.mm */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.objcpp; path = WXRichText.mm; sourceTree = "<group>"; };
 		773CB1D6227F0C92005C758A /* JsonPage.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = JsonPage.h; sourceTree = "<group>"; };
@@ -1299,6 +1298,7 @@
 		B8F3323B2141A4C500701BA0 /* string_util.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = string_util.h; sourceTree = "<group>"; };
 		BA5F00EF1FC5AFFE00F76B5C /* WXLocaleModule.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; path = WXLocaleModule.h; sourceTree = "<group>"; };
 		BA5F00F01FC5AFFE00F76B5C /* WXLocaleModule.m */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.objc; path = WXLocaleModule.m; sourceTree = "<group>"; };
+		BD35ADE92303BEA60050ED82 /* WXConsoleLogModule.mm */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.objcpp; path = WXConsoleLogModule.mm; sourceTree = "<group>"; };
 		BD88C13522F02101004467AA /* render_action_add_child_to_richtext.cpp */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.cpp; path = render_action_add_child_to_richtext.cpp; sourceTree = "<group>"; };
 		BD88C13622F02101004467AA /* render_action_add_child_to_richtext.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = render_action_add_child_to_richtext.h; sourceTree = "<group>"; };
 		BD88C13B22F02111004467AA /* render_action_remove_child_from_richtext.cpp */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.cpp; path = render_action_remove_child_from_richtext.cpp; sourceTree = "<group>"; };
@@ -1938,7 +1938,7 @@
 			isa = PBXGroup;
 			children = (
 				7704894622AA358400E7606F /* WXConsoleLogModule.h */,
-				7704894722AA358400E7606F /* WXConsoleLogModule.m */,
+				BD35ADE92303BEA60050ED82 /* WXConsoleLogModule.mm */,
 				BA5F00EF1FC5AFFE00F76B5C /* WXLocaleModule.h */,
 				BA5F00F01FC5AFFE00F76B5C /* WXLocaleModule.m */,
 				DCE2CF981F46D4220021BDC4 /* WXVoiceOverModule.m */,
@@ -3150,7 +3150,6 @@
 				742AD7321DF98C45007DC46C /* WXResourceRequestHandlerDefaultImpl.m in Sources */,
 				74CFDD421F45941E007A1A66 /* WXRecycleListTemplateManager.m in Sources */,
 				747DF6831E31AEE4005C53A8 /* WXLength.m in Sources */,
-				7704894A22AA358500E7606F /* WXConsoleLogModule.m in Sources */,
 				17E5ACE2209211BD00EE81F1 /* WXTransition.mm in Sources */,
 				77E65A0E1C155E99008B8775 /* WXDivComponent.m in Sources */,
 				B8D66CAB21255730003960BD /* wson_util.cpp in Sources */,
@@ -3246,6 +3245,7 @@
 				74EF31AE1DE58BE200667A07 /* WXURLRewriteDefaultImpl.m in Sources */,
 				17B122262090AAB000387E33 /* WXSDKError.m in Sources */,
 				B8D66C1F21255730003960BD /* layout.cpp in Sources */,
+				BD35ADEA2303BEA60050ED82 /* WXConsoleLogModule.mm in Sources */,
 				B8D66C2B21255730003960BD /* render_manager.cpp in Sources */,
 				453F374E219A76A600A03F1D /* WXConvertUtility.mm in Sources */,
 				C4B3D6D51E6954300013F38D /* WXEditComponent.mm in Sources */,
@@ -3367,7 +3367,6 @@
 				B8D66C4C21255730003960BD /* render_action_remove_event.cpp in Sources */,
 				74B81AE41F73C3E500D3A61D /* WXRecycleListComponent.mm in Sources */,
 				B8D66C6421255730003960BD /* render_text.cpp in Sources */,
-				7704894B22AA358500E7606F /* WXConsoleLogModule.m in Sources */,
 				DC7764951F3C685200B5727E /* WXRecyclerDragController.m in Sources */,
 				B89543F420EB18B5006EAD63 /* WXCoreBridge.mm in Sources */,
 				DCA4453D1EFA55B300D0CFA8 /* WXRootView.m in Sources */,
@@ -3437,6 +3436,7 @@
 				DCA445651EFA55B300D0CFA8 /* WXClipboardModule.m in Sources */,
 				B8D66C4421255730003960BD /* render_action_remove_element.cpp in Sources */,
 				B8D66BFC2125572F003960BD /* render_performance.cpp in Sources */,
+				BD35ADEB2303BEA60050ED82 /* WXConsoleLogModule.mm in Sources */,
 				DCA445661EFA55B300D0CFA8 /* WXNavigatorModule.m in Sources */,
 				DCA445671EFA55B300D0CFA8 /* WXStorageModule.m in Sources */,
 				B8D66C2021255730003960BD /* layout.cpp in Sources */,

ios/sdk/WeexSDK/Sources/Bridge/WXBridgeContext.m

@@ -147,7 +147,11 @@ - (void)registerGlobalFunctions
     [_jsBridge registerCallUpdateComponentData:^NSInteger(NSString *instanceId, NSString *componentId, NSString *jsonData) {
         if (_dataRenderHandler) {
             WXPerformBlockOnComponentThread(^{
+                long start = [WXUtility getUnixFixTimeMillis];
+                WXSDKInstance *instance = [WXSDKManager instanceForID:instanceId];
+                [instance.apmInstance addUpdateComponentDataTimestamp:start];
                 [_dataRenderHandler callUpdateComponentData:instanceId componentId:componentId jsonData:jsonData];
+                [instance.apmInstance addUpdateComponentDataTime:[WXUtility getUnixFixTimeMillis] - start];
             });
         }
         else {
@@ -529,15 +533,12 @@ - (void)createInstance:(NSString *)instanceIdString
         }
         if ([WXDebugTool isDevToolDebug]) {
             [self callJSMethod:@"createInstanceContext" args:@[instanceIdString, newOptions, data?:@[],raxAPIScript?:@""]];
-            [sdkInstance.apmInstance onStage:KEY_PAGE_STAGES_LOAD_BUNDLE_END];
 
             if ([NSURL URLWithString:sdkInstance.pageName]) {
                 [sdkInstance.instanceJavaScriptContext executeJavascript:jsBundleString withSourceURL:[NSURL URLWithString:sdkInstance.pageName]];
             } else {
                 [sdkInstance.instanceJavaScriptContext executeJavascript:jsBundleString];
             }
-            WX_MONITOR_INSTANCE_PERF_END(WXPTJSCreateInstance, [WXSDKManager instanceForID:instanceIdString]);
-            [sdkInstance.apmInstance onStage:KEY_PAGE_STAGES_EXECUTE_BUNDLE_END];
         } else {
             NSDictionary* immutableOptions = [newOptions copy];
             sdkInstance.callCreateInstanceContext = [NSString stringWithFormat:@"instanceId:%@\noptions:%@\ndata:%@", instanceIdString, immutableOptions, data];
@@ -548,6 +549,7 @@ - (void)createInstance:(NSString *)instanceIdString
                                                                  @"instanceId":sdkInstance.instanceId?:@"unknownId"
                                                                 };
             __weak typeof(self) weakSelf = self;
+            [sdkInstance.apmInstance onStage:KEY_PAGE_STAGES_LOAD_BUNDLE_END];
             [self callJSMethod:@"createInstanceContext" args:@[instanceIdString, immutableOptions, data?:@[]] onContext:nil completion:^(JSValue *instanceContextEnvironment) {
                 if (sdkInstance.pageName) {
                     [sdkInstance.instanceJavaScriptContext.javaScriptContext setName:sdkInstance.pageName];
@@ -578,14 +580,13 @@ - (void)createInstance:(NSString *)instanceIdString
                         }];
                     }
                 }
-                
+
                 if (raxAPIScript) {
                     [sdkInstance.instanceJavaScriptContext executeJavascript:raxAPIScript withSourceURL:[NSURL URLWithString:raxAPIScriptPath]];
                     NSArray* allKeys = [WXUtility extractPropertyNamesOfJSValueObject:sdkInstance.instanceJavaScriptContext.javaScriptContext.globalObject];
                     sdkInstance.executeRaxApiResult = [NSString stringWithFormat:@"%@", allKeys];
                 }
 
-                [sdkInstance.apmInstance onStage:KEY_PAGE_STAGES_LOAD_BUNDLE_END];
                 NSDictionary* funcInfo = @{
                                            @"func":@"createInstance",
                                            @"arg":@"start",

ios/sdk/WeexSDK/Sources/Bridge/WXCoreBridge.h

@@ -232,6 +232,8 @@ namespace WeexCore
 
 + (void)layoutPage:(NSString*)pageId forced:(BOOL)forced;
 
++ (double)getLayoutTime:(NSString*)pageId;
+
 + (void)closePage:(NSString*)pageId;
 
 + (BOOL)reloadPageLayout:(NSString*)pageId;

ios/sdk/WeexSDK/Sources/Bridge/WXCoreBridge.mm

@@ -1639,6 +1639,14 @@ + (void)layoutPage:(NSString*)pageId forced:(BOOL)forced
     }
 }
 
++ (double)getLayoutTime:(NSString*)pageId {
+    if (platformBridge) {
+        const char* page = [pageId UTF8String] ?: "";
+        return platformBridge->core_side()->GetLayoutTime(page);
+    }
+    return 0;
+}
+
 + (void)closePage:(NSString*)pageId
 {
     if (platformBridge) {

ios/sdk/WeexSDK/Sources/Manager/WXComponentManager.mm

@@ -316,8 +316,8 @@ - (void)addComponent:(NSString*)ref
     if (supercomponent.ignoreInteraction) {
         component.ignoreInteraction = YES;
     } else {
-        if ([[attributes objectForKey:@"ignoreInteraction"] boolValue]) {
-            component.ignoreInteraction = YES;
+        if ([attributes objectForKey:@"ignoreInteraction"]) {
+            component.ignoreInteraction = [[attributes objectForKey:@"ignoreInteraction"] boolValue];
         } else {
             if (component->_positionType == WXPositionTypeFixed) {
                 component.ignoreInteraction = YES;

ios/sdk/WeexSDK/Sources/Model/WXComponent.mm

@@ -455,13 +455,12 @@ - (UIView *)view
         [self setNeedsDisplay];
         [[NSNotificationCenter defaultCenter] postNotificationName:WX_COMPONENT_NOTIFICATION_VIEW_LOADED object:self];
         [self viewDidLoad];
+        double diffTime = CACurrentMediaTime()*1000 - startCreateViewTime;
+        [self.weexInstance.performance recordViewCreatePerformance:diffTime];
 
         if (_lazyCreateView) {
             [self _buildViewHierarchyLazily];
         }
-
-        double diffTime = CACurrentMediaTime()*1000 - startCreateViewTime;
-        [self.weexInstance.performance recordViewCreatePerformance:diffTime];
         [self _handleFirstScreenTime];
 
         [self.weexInstance.performance onViewLoad:self];

ios/sdk/WeexSDK/Sources/Model/WXSDKInstance_performance.m

@@ -28,6 +28,7 @@
 #import "WXImageComponent.h"
 #import "WXUtility.h"
 #import "WXAnalyzerCenter+Transfer.h"
+#import "WXCoreBridge.h"
 
 @interface WXPerformance()
 @property (nonatomic, assign) bool hasRecordFsRenderTimeByPosition;
@@ -112,7 +113,7 @@ - (void) _handleRenderTime:(WXComponent*)targetComponent withModifyTime:(double)
     if ([targetComponent.type isEqualToString:@"videoplus"]) {
         return;
     }
-    
+
     bool inScreen = CGRectIntersectsRect(rootFrame, absoluteFrame);
     if (!inScreen) {
         return;
@@ -131,6 +132,7 @@ - (void) _handleRenderTime:(WXComponent*)targetComponent withModifyTime:(double)
     [targetComponent.weexInstance.apmInstance updateMaxStats:KEY_PAGE_STATS_EXECUTE_JS_TIME curMaxValue:self.callJsTime];
     [targetComponent.weexInstance.apmInstance updateMaxStats:KEY_PAGE_STATS_CREATE_COMPONENT_TIME curMaxValue:self.componentCreateTime];
     [targetComponent.weexInstance.apmInstance updateMaxStats:KEY_PAGE_STATS_CREATE_VIEW_TIME curMaxValue:self.viewCreateTime];
+    [targetComponent.weexInstance.apmInstance updateMaxStats:KEY_PAGE_STATS_LAYOUT_TIME curMaxValue:[WXCoreBridge getLayoutTime:targetComponent.weexInstance.instanceId]];
 
     self.interactionTime = self.interactionTime < diff ? diff :self.interactionTime;
 }

ios/sdk/WeexSDK/Sources/Module/WXConsoleLogModule.m renamed to ios/sdk/WeexSDK/Sources/Module/WXConsoleLogModule.mm

@@ -19,6 +19,7 @@
 
 #import "WXConsoleLogModule.h"
 #import "WXLog.h"
+#include "base/log_defines.h"
 
 #if !TARGET_OS_WATCH
 #import <asl.h>
@@ -91,21 +92,26 @@ - (void)switchLogLevel:(NSString*)logLevel callback:(WXKeepAliveCallback)callbac
     }
 
     if ([logLevel isEqualToString:@"off"]) {
+        weex::base::LogImplement::getLog()->setPrintLevel(WeexCore::LogLevel::Off);
         [WXLog registerExternalLog:OriginalLogger];
     }
     else if ([logLevel isEqualToString:@"error"]) {
+        weex::base::LogImplement::getLog()->setPrintLevel(WeexCore::LogLevel::Error);
         [WXConsoleLogHandler sharedInstance].logLevel = WXLogLevelError;
         [WXLog registerExternalLog:[WXConsoleLogHandler sharedInstance]];
     }
     else if ([logLevel isEqualToString:@"warning"]) {
+        weex::base::LogImplement::getLog()->setPrintLevel(WeexCore::LogLevel::Warn);
         [WXConsoleLogHandler sharedInstance].logLevel = WXLogLevelWarning;
         [WXLog registerExternalLog:[WXConsoleLogHandler sharedInstance]];
     }
     else if ([logLevel isEqualToString:@"info"]) {
+        weex::base::LogImplement::getLog()->setPrintLevel(WeexCore::LogLevel::Info);
         [WXConsoleLogHandler sharedInstance].logLevel = WXLogLevelInfo;
         [WXLog registerExternalLog:[WXConsoleLogHandler sharedInstance]];
     }
     else if ([logLevel isEqualToString:@"debug"]) {
+        weex::base::LogImplement::getLog()->setPrintLevel(WeexCore::LogLevel::Debug);
         [WXConsoleLogHandler sharedInstance].logLevel = WXLogLevelDebug;
         [WXLog registerExternalLog:[WXConsoleLogHandler sharedInstance]];
     }

ios/sdk/WeexSDK/Sources/Performance/WXApmForInstance.h

@@ -45,6 +45,8 @@ extern NSString* const KEY_PAGE_PROPERTIES_UIKIT_TYPE;
 extern NSString* const KEY_PAGE_STAGES_START;
 extern NSString* const KEY_PAGE_STAGES_DOWN_BUNDLE_START;
 extern NSString* const KEY_PAGE_STAGES_DOWN_BUNDLE_END;
+extern NSString* const KEY_PAGE_STAGES_DOWN_JS_START;
+extern NSString* const KEY_PAGE_STAGES_DOWN_JS_END;
 extern NSString* const KEY_PAGE_STAGES_CUSTOM_PREPROCESS_START;
 extern NSString* const KEY_PAGE_STAGES_CUSTOM_PREPROCESS_END;
 extern NSString* const KEY_PAGE_STAGES_RENDER_ORGIGIN;
@@ -66,6 +68,7 @@ extern NSString* const KEY_PAGE_STATS_FS_CALL_JS_NUM;
 extern NSString* const KEY_PAGE_STATS_EXECUTE_JS_TIME;
 extern NSString* const KEY_PAGE_STATS_CREATE_COMPONENT_TIME;
 extern NSString* const KEY_PAGE_STATS_CREATE_VIEW_TIME;
+extern NSString* const KEY_PAGE_STATS_LAYOUT_TIME;
 extern NSString* const KEY_PAGE_STATS_FS_TIMER_NUM;
 extern NSString* const KEY_PAGE_STATS_FS_CALL_NATIVE_TIME;
 extern NSString* const KEY_PAGE_STATS_FS_CALL_NATIVE_NUM;
@@ -137,6 +140,8 @@ extern NSString* const VALUE_ERROR_CODE_DEFAULT;
 - (void) updateMaxStats:(NSString *)name curMaxValue:(double)maxValue;
 - (void) updateExtInfoFromResponseHeader:(NSDictionary*) extInfo;
 - (void) forceSetInteractionTime:(long) unixTime;
+- (void) addUpdateComponentDataTimestamp:(long)unixTime;
+- (void) addUpdateComponentDataTime:(long)unixTime;
 
 
 #pragma mark - called by IWXHttpAdapter implementer