Add instrumentation for tracking how long it takes barback to start.

sdk/lib/_internal/pub/lib/src/progress.dart

 // Copyright (c) 2012, the Dart project authors.  Please see the AUTHORS file
 // for details. All rights reserved. Use of this source code is governed by a
 // BSD-style license that can be found in the LICENSE file.
 
 library pub.progress;
 
 import 'dart:async';
 import 'dart:io';
 
 import 'log.dart' as log;
 import 'utils.dart';
 
 /// A live-updating progress indicator for long-running log entries.
 class Progress {
   /// The timer used to write "..." during a progress log.
   Timer _timer;
 
   /// The [Stopwatch] used to track how long a progress log has been running.
   final _stopwatch = new Stopwatch();
 
   /// The progress message as it's being incrementally appended. When the
   /// progress is done, a single entry will be added to the log for it.
   final String _message;
 
-  Progress(this._message) {
+  /// Whether this should log messages at [log.Level.FINE] rather than
+  /// [log.Level.MESSAGE].
+  final bool _fine;
+
+  /// Gets the current progress time as a parenthesized, formatted string.
+  String get _time => "(${niceDuration(_stopwatch.elapsed)})";
+
+  Progress(this._message, {bool fine: false})
+      : _fine = fine {
     _stopwatch.start();
 
-    if (log.json.enabled) return;
+    bool animate = !log.isLevelVisible(log.Level.FINE) &&

[Bob Nystrom, 2014/06/05 20:18:16]

Document this.

[nweiz, 2014/06/05 21:58:19]

Done.

[nweiz, 2014/06/05 21:58:19]

Done.

+        stdioType(stdout) == StdioType.TERMINAL;
+    (animate || _fine ? log.fine : log.message)("$_message...");
 
-    // Only animate if we're writing to a TTY in human format.
-    if (stdioType(stdout) == StdioType.TERMINAL) {
+    if (!animate || log.json.enabled) return;
+
+    _update();
+    _timer = new Timer.periodic(new Duration(milliseconds: 100), (_) {
       _update();
-      _timer = new Timer.periodic(new Duration(milliseconds: 100), (_) {
-        _update();
-      });
-    } else {
-      stdout.write("$_message... ");
-    }
+    });
   }
 
   /// Stops the progress indicator.
   ///
   /// Returns the complete final progress message.

[Bob Nystrom, 2014/06/05 20:18:16]

Delete this.

[nweiz, 2014/06/05 21:58:19]

Done.

-  String stop() {
+  void stop() {
     _stopwatch.stop();
 
-    // If we aren't animating, just log the final time.
-    if (log.json.enabled) {
-      // Do nothing.
-    } else if (_timer == null) {
-      stdout.writeln(_time);
-    } else {
-      _timer.cancel();
+    // If we aren't animating, just log the final time. This is always

[Bob Nystrom, 2014/06/05 20:18:16]

Won't this get logged even if we are animating?

[nweiz, 2014/06/05 21:58:19]

Yes, it's a little confusingly written. I'll reword it.

+    // [log.fine] because for the most part normal users don't care about the
+    // precise time information beyond what's shown in the animation.
+    log.fine("$_message finished $_time.");
 
-      // Show one final update.
-      _update();
-      stdout.writeln();
-    }
+    if (_timer == null) return;
+    _timer.cancel();
 
-    return "$_message... ${_time}";
+    // Show one final update.
+    _update();
+    stdout.writeln();
   }
 
-  /// Gets the current progress time as a parenthesized, formatted string.
-  String get _time => "(${niceDuration(_stopwatch.elapsed)})";
+  /// Stop animating the progress indicator.
+  ///
+  /// This will continue running the stopwatch so that the full time can be
+  /// logged in [stop].
+  void stopAnimating() {
+    if (_timer == null) return;
+    stdout.writeln("\r$_message...");

[Bob Nystrom, 2014/06/05 20:18:16]

What's this for?

[nweiz, 2014/06/05 21:58:19]

It prevents there being an old, inaccurate time being left on the console.

[Bob Nystrom, 2014/06/06 20:18:53]

OK, document that.

It's confusing because the code in log calls stopAnimating() on all of the
existing progresses, but this code assumes there will only be one currently
animating progress. If there were more than one, their output would step on each
other.

How about changing log so that it distinguishes between the one currently
visible progress and the pool of other non-printing but still running ones?

[nweiz, 2014/06/09 19:55:34]

Done.
Done.

+    _timer.cancel();
+    _timer = null;
+  }
 
   /// Refreshes the progress line.
   void _update() {
     stdout.write("\r$_message... ");
 
     // Show the time only once it gets noticeably long.
     if (_stopwatch.elapsed.inSeconds > 0) {
       stdout.write(log.gray(_time));
     }
   }
 }