diff --git a/tns-core-modules/application/application-common.ts b/tns-core-modules/application/application-common.ts index 58c6f0ae2..dd3a64e21 100644 --- a/tns-core-modules/application/application-common.ts +++ b/tns-core-modules/application/application-common.ts @@ -2,6 +2,12 @@ require("globals"); import { Observable, EventData } from "../data/observable"; +import { + trace as profilingTrace, + time, + uptime, + level as profilingLevel, +} from "../profiling"; const events = new Observable(); let launched = false; @@ -11,6 +17,15 @@ function setLaunched() { } events.on("launch", setLaunched); +if (profilingLevel() > 0) { + events.on("displayed", () => { + const duration = uptime(); + const end = time(); + const start = end - duration; + profilingTrace(`Displayed in ${duration.toFixed(2)}ms`, start, end); + }); +} + export function hasLaunched(): boolean { return launched; } diff --git a/tns-core-modules/application/application.ios.ts b/tns-core-modules/application/application.ios.ts index 4fb251b9a..889a7aca8 100644 --- a/tns-core-modules/application/application.ios.ts +++ b/tns-core-modules/application/application.ios.ts @@ -20,14 +20,12 @@ import { ios as iosView, View } from "../ui/core/view"; import { Frame, NavigationEntry } from "../ui/frame"; import { ios } from "../ui/utils"; import * as utils from "../utils/utils"; -import { profile } from "../profiling"; +import { profile, level as profilingLevel, Level } from "../profiling"; class Responder extends UIResponder { // } -let displayedOnce = false; - class NotificationObserver extends NSObject { private _onReceiveCallback: (notification: NSNotification) => void; @@ -46,6 +44,24 @@ class NotificationObserver extends NSObject { }; } +let displayedOnce = false; +let displayedLinkTarget; +let displayedLink; +class CADisplayLinkTarget extends NSObject { + onDisplayed(link: CADisplayLink) { + link.invalidate(); + const ios = utils.ios.getter(UIApplication, UIApplication.sharedApplication); + const object = iosApp; + displayedOnce = true; + notify({ eventName: displayedEvent, object, ios }); + displayedLinkTarget = null; + displayedLink = null; + } + public static ObjCExposedMethods = { + "onDisplayed": { returns: interop.types.void, params: [CADisplayLink] } + } +} + class IOSApplication implements IOSApplicationDefinition { private _delegate: typeof UIApplicationDelegate; private _currentOrientation = utils.ios.getter(UIDevice, UIDevice.currentDevice).orientation; @@ -101,6 +117,13 @@ class IOSApplication implements IOSApplicationDefinition { @profile private didFinishLaunchingWithOptions(notification: NSNotification) { + if (!displayedOnce && profilingLevel() >= Level.lifecycle) { + displayedLinkTarget = CADisplayLinkTarget.new(); + displayedLink = CADisplayLink.displayLinkWithTargetSelector(displayedLinkTarget, "onDisplayed"); + displayedLink.addToRunLoopForMode(NSRunLoop.mainRunLoop, NSDefaultRunLoopMode); + displayedLink.addToRunLoopForMode(NSRunLoop.mainRunLoop, UITrackingRunLoopMode); + } + this._window = UIWindow.alloc().initWithFrame(utils.ios.getter(UIScreen, UIScreen.mainScreen).bounds); // TODO: Expose Window module so that it can we styled from XML & CSS this._window.backgroundColor = utils.ios.getter(UIColor, UIColor.whiteColor); @@ -126,11 +149,6 @@ class IOSApplication implements IOSApplicationDefinition { if (rootView && !rootView.isLoaded) { rootView.callLoaded(); } - - if (!displayedOnce) { - notify({ eventName: displayedEvent, object, ios }); - displayedOnce = true; - } } private didEnterBackground(notification: NSNotification) { diff --git a/tns-core-modules/profiling/profiling.d.ts b/tns-core-modules/profiling/profiling.d.ts index 350e86a8e..e10b4ae3c 100644 --- a/tns-core-modules/profiling/profiling.d.ts +++ b/tns-core-modules/profiling/profiling.d.ts @@ -11,10 +11,25 @@ interface TimerInfo { /** * Profiling mode to use. - * - `counters` Accumulates method call counts and times until dumpProfiles is called and then prints agregated statistic in the console. This is the default. + * - `counters` Accumulates method call counts and times until dumpProfiles is called and then prints aggregated statistic in the console. This is the default. * - `timeline` Outputs method names along start/end timestamps in the console on the go. + * - `lifecycle` Outputs basic non-verbose times for startup, navigation, etc. */ -type InstrumentationMode = "counters" | "timeline"; +type InstrumentationMode = "counters" | "timeline" | "lifecycle"; + +/** + * Logging levels in order of verbosity. + */ +export enum Level { + none, + lifecycle, + timeline, +} + +/** + * Get the current logging level. + */ +export function level(): Level; /** * Enables profiling. @@ -32,8 +47,9 @@ type InstrumentationMode = "counters" | "timeline"; * ``` * * @param type Profiling mode to use. - * - "counters" - Accumulates method call counts and times until dumpProfiles is called and then prints agregated statistic in the console. This is the default. + * - "counters" - Accumulates method call counts and times until dumpProfiles is called and then prints aggregated statistic in the console. This is the default. * - "timeline" - Outputs method names along start/end timestamps in the console on the go. + * - "lifecycle" - Outputs basic non-verbose times for startup, navigation, etc. */ export declare function enable(type?: InstrumentationMode): void; @@ -132,4 +148,14 @@ export function uptime(): number; /** * Logs important messages. Contrary to console.log's behavior, the profiling log should output even for release builds. */ -export function log(message: string): void; \ No newline at end of file +export function log(message: string): void; + +/** + * Manually output profiling messages. The `@profile` decorator is useful when measuring times that function calls take on the stack + * but when measuring times between longer periods (startup times, times between the navigatingTo - navigatedTo events etc.) + * you can call this method and provide manually the times to be logged. + * @param message A string message + * @param start The start time (see `time()`) + * @param end The end time (see `time()`) + */ +export function trace(message: string, start: number, end: number): void; \ No newline at end of file diff --git a/tns-core-modules/profiling/profiling.ts b/tns-core-modules/profiling/profiling.ts index b787c9582..9d767e8fa 100644 --- a/tns-core-modules/profiling/profiling.ts +++ b/tns-core-modules/profiling/profiling.ts @@ -10,9 +10,8 @@ export function uptime() { export function log(message: string): void { if ((global).__nslog) { (global).__nslog("CONSOLE LOG: " + message); - } else { - console.log(message); } + console.log(message); } interface TimerInfo extends TimerInfoDefinition { @@ -130,12 +129,24 @@ const enum MemberType { Instance } +export enum Level { + none, + lifecycle, + timeline, +} +let tracingLevel: Level = Level.none; + let profileFunctionFactory: (fn: F, name: string, type?: MemberType) => F; export function enable(mode: InstrumentationMode = "counters") { profileFunctionFactory = mode && { counters: countersProfileFunctionFactory, timeline: timelineProfileFunctionFactory }[mode]; + + tracingLevel = { + lifecycle: Level.lifecycle, + timeline: Level.timeline, + }[mode] || Level.none; } try { @@ -294,3 +305,11 @@ export function stopCPUProfile(name: string) { __stopCPUProfiler(name); } } + +export function level(): Level { + return tracingLevel; +} + +export function trace(message: string, start: number, end: number): void { + log(`Timeline: Modules: ${message} (${start}ms. - ${end}ms.)`); +}