diff --git a/examples/flutter_gallery/lib/main.dart b/examples/flutter_gallery/lib/main.dart index 9630907cfb..ca06e7acfb 100644 --- a/examples/flutter_gallery/lib/main.dart +++ b/examples/flutter_gallery/lib/main.dart @@ -5,11 +5,15 @@ // Thanks for checking out Flutter! // Like what you see? Tweet us @flutterio +import 'package:flutter/foundation.dart'; import 'package:flutter/material.dart'; import 'gallery/app.dart'; void main() { + // Temporary debugging hook for https://github.com/flutter/flutter/issues/17956 + debugInstrumentationEnabled = true; + // Overriding https://github.com/flutter/flutter/issues/13736 for better // visual effect at the cost of performance. MaterialPageRoute.debugEnableFadingRoutes = true; // ignore: deprecated_member_use diff --git a/packages/flutter/lib/src/foundation/binding.dart b/packages/flutter/lib/src/foundation/binding.dart index f5c3345977..e9bbb58e0c 100644 --- a/packages/flutter/lib/src/foundation/binding.dart +++ b/packages/flutter/lib/src/foundation/binding.dart @@ -11,7 +11,9 @@ import 'package:meta/meta.dart'; import 'assertions.dart'; import 'basic_types.dart'; +import 'debug.dart'; import 'platform.dart'; +import 'print.dart'; /// Signature for service extensions. /// @@ -363,6 +365,11 @@ abstract class BindingBase { final String methodName = 'ext.flutter.$name'; developer.registerExtension(methodName, (String method, Map parameters) async { assert(method == methodName); + assert(() { + if (debugInstrumentationEnabled) + debugPrint('service extension method received: $method($parameters)'); + return true; + }()); // VM service extensions are handled as "out of band" messages by the VM, // which means they are handled at various times, generally ASAP. @@ -374,7 +381,9 @@ abstract class BindingBase { // the possibility that they're handled in the middle of a frame, which // breaks many assertions. As such, we ensure they we run the callbacks // on the outer event loop here. - await new Future.delayed(Duration.zero); + await debugInstrumentAction('Wait for outer event loop', () { + return new Future.delayed(Duration.zero); + }); dynamic caughtException; StackTrace caughtStack; diff --git a/packages/flutter/lib/src/foundation/debug.dart b/packages/flutter/lib/src/foundation/debug.dart index 43c4c870dd..eb13f69a6f 100644 --- a/packages/flutter/lib/src/foundation/debug.dart +++ b/packages/flutter/lib/src/foundation/debug.dart @@ -2,6 +2,8 @@ // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. +import 'dart:async'; + import 'assertions.dart'; import 'platform.dart'; import 'print.dart'; @@ -29,6 +31,51 @@ bool debugAssertAllFoundationVarsUnset(String reason, { DebugPrintCallback debug return true; } +/// Boolean value indicating whether [debugInstrumentAction] will instrument +/// actions in debug builds. +bool debugInstrumentationEnabled = false; + +/// Runs the specified [action], timing how long the action takes in debug +/// builds when [debugInstrumentationEnabled] is true. +/// +/// The instrumentation will be printed to the logs using [debugPrint]. In +/// non-debug builds, or when [debugInstrumentationEnabled] is false, this will +/// run [action] without any instrumentation. +/// +/// Returns the result of running [action], wrapped in a `Future` if the action +/// was synchronous. +Future debugInstrumentAction(String description, FutureOr action()) { + if (!debugInstrumentationEnabled) + return new Future.value(action()); + + Stopwatch stopwatch; + assert(() { + stopwatch = new Stopwatch()..start(); + return true; + } ()); + void stopStopwatchAndPrintElapsed() { + assert(() { + stopwatch.stop(); + debugPrint('Action "$description" took ${stopwatch.elapsed}'); + return true; + }()); + } + + Future returnResult; + FutureOr actionResult; + try { + actionResult = action(); + } finally { + if (actionResult is Future) { + returnResult = actionResult.whenComplete(stopStopwatchAndPrintElapsed); + } else { + stopStopwatchAndPrintElapsed(); + returnResult = new Future.value(actionResult); + } + } + return returnResult; +} + /// Arguments to whitelist [Timeline] events in order to be shown in the /// developer centric version of the Observatory Timeline. const Map timelineWhitelistArguments = const { diff --git a/packages/flutter/test/foundation/debug_test.dart b/packages/flutter/test/foundation/debug_test.dart new file mode 100644 index 0000000000..3be82e651c --- /dev/null +++ b/packages/flutter/test/foundation/debug_test.dart @@ -0,0 +1,74 @@ +// Copyright 2017 The Chromium Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +import 'package:flutter/foundation.dart'; +import 'package:flutter_test/flutter_test.dart'; + +void main() { + group('debugInstrumentAction', () { + DebugPrintCallback originalDebugPrintCallback; + StringBuffer printBuffer; + + setUp(() { + debugInstrumentationEnabled = true; + printBuffer = new StringBuffer(); + originalDebugPrintCallback = debugPrint; + debugPrint = (String message, {int wrapWidth}) { + printBuffer.writeln(message); + }; + }); + + tearDown(() { + debugInstrumentationEnabled = false; + debugPrint = originalDebugPrintCallback; + }); + + test('works with sync actions', () async { + final int result = await debugInstrumentAction('no-op', () { + debugPrint('action()'); + return 1; + }); + expect(result, 1); + expect( + printBuffer.toString(), + matches(new RegExp('^action\\(\\)\nAction "no-op" took .+\$', multiLine: true)), + ); + }); + + test('works with async actions', () async { + final int result = await debugInstrumentAction('no-op', () async { + debugPrint('action()'); + return 1; + }); + expect(result, 1); + expect( + printBuffer.toString(), + matches(new RegExp('^action\\(\\)\nAction "no-op" took .+\$', multiLine: true)), + ); + }); + + test('throws if sync action throws', () { + try { + debugInstrumentAction('throws', () => throw 'Error'); + fail('Error expected but not thrown'); + } on String catch (error) { + expect(error, 'Error'); + expect(printBuffer.toString(), matches(r'^Action "throws" took .+')); + } + }); + + test('returns failing future if async action throws', () async { + try { + await debugInstrumentAction('throws', () async { + await new Future.delayed(Duration.zero); + throw 'Error'; + }); + fail('Error expected but not thrown'); + } on String catch (error) { + expect(error, 'Error'); + expect(printBuffer.toString(), matches(r'^Action "throws" took .+')); + } + }); + }); +}