Clean up our timeline events. (#3504)

This adds in particular the ability to track the time at which the
framework boots up, and the time at which we are confident we have
completed the first useful frame.

packages/flutter/lib/src/foundation/binding.dart

@@ -45,6 +45,8 @@ abstract class BindingBase {
   /// [initServiceExtensions] to have bindings initialize their
   /// observatory service extensions, if any.
   BindingBase() {
+    developer.Timeline.startSync('Framework initialization');
+
     assert(!_debugInitialized);
     initInstances();
     assert(_debugInitialized);
@@ -52,6 +54,8 @@ abstract class BindingBase {
     assert(!_debugServiceExtensionsRegistered);
     initServiceExtensions();
     assert(_debugServiceExtensionsRegistered);
+
+    developer.Timeline.finishSync();
   }
 
   static bool _debugInitialized = false;
@@ -116,7 +120,7 @@ abstract class BindingBase {
   ///
   /// Invokes the `callback` callback when the service extension is
   /// invoked.
-  void registerSignalServiceExtension({ 
+  void registerSignalServiceExtension({
     @required String name,
     @required VoidCallback callback
   }) {
@@ -143,7 +147,7 @@ abstract class BindingBase {
   ///
   /// Invokes the `setter` callback with the new value when the
   /// service extension method is invoked with a new value.
-  void registerBoolServiceExtension({ 
+  void registerBoolServiceExtension({
     String name,
     @required ValueGetter<bool> getter,
     @required ValueSetter<bool> setter
@@ -152,7 +156,7 @@ abstract class BindingBase {
     assert(getter != null);
     assert(setter != null);
     registerServiceExtension(
-      name: name, 
+      name: name,
       callback: (Map<String, String> parameters) async {
         if (parameters.containsKey('enabled'))
           setter(parameters['enabled'] == 'true');
@@ -172,7 +176,7 @@ abstract class BindingBase {
   ///
   /// Invokes the `setter` callback with the new value when the
   /// service extension method is invoked with a new value.
-  void registerNumericServiceExtension({ 
+  void registerNumericServiceExtension({
     @required String name,
     @required ValueGetter<double> getter,
     @required ValueSetter<double> setter
@@ -200,7 +204,7 @@ abstract class BindingBase {
   /// logs.
   ///
   /// The returned map will be mutated.
-  void registerServiceExtension({ 
+  void registerServiceExtension({
     @required String name,
     @required ServiceExtensionCallback callback
   }) {

packages/flutter/lib/src/rendering/object.dart

@@ -739,7 +739,7 @@ class PipelineOwner {
   /// Called as part of the rendering pipeline after [flushLayout] and before
   /// [flushPaint].
   void flushCompositingBits() {
-    Timeline.startSync('Compositing Bits');
+    Timeline.startSync('Compositing bits');
     _nodesNeedingCompositingBitsUpdate.sort((RenderObject a, RenderObject b) => a.depth - b.depth);
     for (RenderObject node in _nodesNeedingCompositingBitsUpdate) {
       if (node._needsCompositingBitsUpdate && node.owner == this)
@@ -797,7 +797,7 @@ class PipelineOwner {
       Timeline.finishSync();
     }
   }
- 
+
   /// Cause the entire subtree rooted at the given [RenderObject] to
   /// be entirely reprocessed. This is used by development tools when
   /// the application code has changed, to cause the rendering tree to
@@ -1196,7 +1196,7 @@ abstract class RenderObject extends AbstractNode implements HitTestTarget {
         }
         if (targetFrame != null && targetFrame < stack.length) {
           information.writeln(
-            'These invalid constraints were provided to $runtimeType\'s method() ' 
+            'These invalid constraints were provided to $runtimeType\'s method() '
             'function by the following function, which probably computed the '
             'invalid constraints in question:'
           );

packages/flutter/lib/src/rendering/view.dart

@@ -125,7 +125,7 @@ class RenderView extends RenderObject with RenderObjectWithChildMixin<RenderBox>
   ///
   /// Actually causes the output of the rendering pipeline to appear on screen.
   void compositeFrame() {
-    Timeline.startSync('Composite');
+    Timeline.startSync('Compositing');
     try {
       final TransformLayer transformLayer = layer;
       transformLayer.transform = _logicalToDeviceTransform;

packages/flutter/lib/src/scheduler/binding.dart

@@ -341,7 +341,7 @@ abstract class SchedulerBinding extends BindingBase {
   /// typically drive the rendering pipeline, and finally calls the
   /// callbacks registered by [addPostFrameCallback].
   void handleBeginFrame(Duration rawTimeStamp) {
-    Timeline.startSync('Begin frame');
+    Timeline.startSync('Frame');
     assert(!_debugInFrame);
     assert(() { _debugInFrame = true; return true; });
     Duration timeStamp = new Duration(

packages/flutter/lib/src/widgets/app.dart

@@ -164,6 +164,9 @@ class WidgetsAppState<T extends WidgetsApp> extends State<T> implements WidgetsB
       return new Container();
     }
 
+    // TODO(ianh): The following line should not be included in release mode, only in profile and debug modes.
+    WidgetsBinding.instance.didFirstFrame();
+
     Widget result = new MediaQuery(
       data: new MediaQueryData.fromWindow(ui.window),
       child: new LocaleQuery(

packages/flutter/lib/src/widgets/binding.dart

@@ -2,6 +2,7 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
+import 'dart:developer' as developer;
 import 'dart:ui' as ui show window;
 import 'dart:ui' show AppLifecycleState, Locale;
 
@@ -171,11 +172,27 @@ abstract class WidgetsBinding extends BindingBase implements GestureBinding, Ren
       observer.didChangeAppLifecycleState(state);
   }
 
+  bool _didFirstFrame = false;
+  bool _reportFirstFrame = true;
+
+  /// Tell the framework that the first useful frame has been completed.
+  ///
+  /// This is used by [WidgetsApp] to report the first frame.
+  // remove this once we've fixed https://github.com/flutter/flutter/issues/1865
+  void didFirstFrame() {
+    _didFirstFrame = true;
+  }
+
   @override
   void beginFrame() {
     buildOwner.buildDirtyElements();
     super.beginFrame();
     buildOwner.finalizeTree();
+    // TODO(ianh): Following code should not be included in release mode, only profile and debug mode
+    if (_reportFirstFrame && _didFirstFrame) {
+      developer.Timeline.instantSync('Widgets completed first useful frame');
+      _reportFirstFrame = false;
+    }
   }
 
   /// The [Element] that is at the root of the hierarchy (and which wraps the

packages/flutter/lib/src/widgets/framework.dart

@@ -788,13 +788,15 @@ class BuildOwner {
   /// After the current call stack unwinds, a microtask that notifies listeners
   /// about changes to global keys will run.
   void finalizeTree() {
+    Timeline.startSync('Finalize tree');
     lockState(() {
       _inactiveElements._unmountAll();
     }, context: 'while finalizing the widget tree');
     assert(GlobalKey._debugCheckForDuplicates);
     scheduleMicrotask(GlobalKey._notifyListeners);
+    Timeline.finishSync();
   }
- 
+
   /// Cause the entire subtree rooted at the given [Element] to
   /// be entirely rebuilt. This is used by development tools when
   /// the application code has changed, to cause the widget tree to