Tuesday, January 12, 2016

Unboxing Packages: stack_trace

Editor's note: This is the first post in a new series by Natalie going in-depth on Dart packages and how they're used.

If you’ve written any Dart code at all, you’ve definitely used tools that use the stack_trace package. It was originally written for use in pub, and the test package uses it for all the stack traces that tests generate. But you don’t just have to rely on other tools to use it for you—you can use it yourself!

The package has three main use-cases, all of which are important and useful. Originally, it was just designed to make existing stack traces prettier and easier to read. A big part of that was parsing stack traces into a data structure, so its secondary purpose became programmatically manipulating stack traces. Then once zones were created, it added support for tracking stacks across asynchronous calls.

Making Traces Pretty

Let’s face it: the Dart VM’s built-in stack traces aren’t nice to look at, and they don’t present information in a way that’s easy for humans to read. Let’s take a look:

#0      Object.noSuchMethod (dart:core-patch:1884:25)
#1      Trace.terse.<anonymous closure> (file:///usr/local/google-old/home/goog/dart/dart/pkg/stack_trace/lib/src/trace.dart:47:21)
#2      IterableMixinWorkaround.reduce (dart:collection:29:29)
#3      List.reduce (dart:core-patch:1247:42)
#4      Trace.terse (file:///usr/local/google-old/home/goog/dart/dart/pkg/stack_trace/lib/src/trace.dart:40:35)
#5      format (file:///usr/local/google-old/home/goog/dart/dart/pkg/stack_trace/lib/stack_trace.dart:24:28)
#6      main.<anonymous closure> (file:///usr/local/google-old/home/goog/dart/dart/test.dart:21:29)
#7      _CatchErrorFuture._sendError (dart:async:525:24)
#8      _FutureImpl._setErrorWithoutAsyncTrace (dart:async:393:26)
#9      _FutureImpl._setError (dart:async:378:31)
#10     _ThenFuture._sendValue (dart:async:490:16)
#11     _FutureImpl._handleValue.<anonymous closure> (dart:async:349:28)
#12     Timer.run.<anonymous closure> (dart:async:2402:21)
#13     Timer.Timer.<anonymous closure> (dart:async-patch:15:15)

Look at those numbers that don’t add any information. Look at all those lines of internal SDK calls that the user doesn’t care about. Look at those gargantuan absolute file: URLs where relative paths would do. Look how little alignment there is across lines. This is messy. And it’s even worse if you’re compiling to JavaScript; then you have to deal with a bunch of different messy formats!

The initial motivation for the stack_trace package was just to print stack traces in a way Bob and I liked to read while we were writing Pub. And it made a huge difference just by aligning columns and making paths relative:

dart:core-patch 1884:25                     Object.noSuchMethod
pkg/stack_trace/lib/src/trace.dart 47:21    Trace.terse.<fn>
dart:collection 29:29                       IterableMixinWorkaround.reduce
dart:core-patch 1247:42                     List.reduce
pkg/stack_trace/lib/src/trace.dart 40:35    Trace.terse
pkg/stack_trace/lib/stack_trace.dart 24:28  format
test.dart 21:29                             main.<fn>
dart:async 525:24                           _CatchErrorFuture._sendError
dart:async 393:26                           _FutureImpl._setErrorWithoutAsyncTrace
dart:async 378:31                           _FutureImpl._setError
dart:async 490:16                           _ThenFuture._sendValue
dart:async 349:28                           _FutureImpl._handleValue.<fn>
dart:async 2402:21                          Timer.run.<fn>
dart:async-patch 15:15                      Timer.Timer.<fn>

Let’s take this opportunity to jump into some code. The Trace class is how the package represents a full stack trace. It can be parsed from any supported platform’s stack trace using new Trace.parse()stack_trace knows how to parse its own format, the Dart VM’s, and that of every browser Dart supports. If you know the platform you’re parsing for, you can also use platform-specific constructors like new Trace.parseFirefox(). Once you have a Trace, all you need to do is call toString() to get the nice, clean stack format.

import "package:stack_trace/stack_trace.dart";

void main() {
  // Throw an error so we have a stack trace to work with.
  try {
    throw '';
  } catch (error, stackTrace) {
    // Parse the trace from the StackTrace object. This works on the VM and on
    // any supported browser.
    var trace = new Trace.parse(stackTrace);

    // Print the stack trace in its pretty format.

Once you have a Trace, there’s even more you can do to clean it up. Most of the time, users only care about the internal workings of packages that they’re actually responsible for—they don’t care that List.reduce() called IterableMixinWorkaround.reduce(), they just care that somehow dart:core got from List.reduce() to their callback.

To address this, stack_trace has a notion of “folding” a Trace. This removes most of the stack frames that are considered irrelevant. It leaves only the ones immediately after relevant frames, since the user does care that their function called List.reduce() even if they don’t care what that called. Call Trace.foldFrames() to return a folded Trace, passing in a predicate that returns whether or not a line is relevant:

// Fold all the core library frames and frames from the test package.
trace = trace.foldFrames((frame) => frame.isCore || frame.package == 'test');

There’s also a built-in Trace.terse getter that folds together frames from the core libraries and the stack_trace package itself. It also does some bonus cleanup: it’ll clean up core library frames by getting rid of individual library names and line numbers, and it’ll remove the initial chunk of core frames that represent internal event loop junk. You can also get those bonuses by passing terse: true to foldFrames().

Here’s the terse version of the stack trace above:

dart:core                                   Object.noSuchMethod
pkg/stack_trace/lib/src/trace.dart 47:21    Trace.terse.<fn>
dart:core                                   List.reduce
pkg/stack_trace/lib/src/trace.dart 40:35    Trace.terse
pkg/stack_trace/lib/stack_trace.dart 24:28  format
test.dart 21:29                             main.<fn>

Gorgeous! Removing all of that extra text lets the user focus only on their code and the code it calls.

Parsing and Manipulating Traces

There’s more to stack traces than just printing them out nicely, though. A Trace, and the Frames it contains, makes it possible to inspect all the data encoded in a stack trace. You can get at all the information that’s directly included in the original trace via getters like Frame.uri, Frame.member, Frame.line, and Frame.column.

There are also derived getters that build in some logic for extracting common information. Frame.package, for example, returns the name of the package for package: URI frames, and returns null for any other frame. Frame.isCore is true for core library frames. Frame.library is a more human-readable version of Frame.uri, and Frame.location is a human-readable combination of the URI, line, and column.

You can also create your own stack traces from scratch using the new Frame() and new Trace() constructors. This ability is put to good use by the source_map_stack_trace package, which uses a source map produced by dart2js to convert a browser’s stack trace into one that has Dart files and line numbers. Here’s an excerpt of how it uses stack_trace:

return new Trace(trace.frames.map((frame) {
  // ...

  return new Frame(
      span.start.line + 1,
      span.start.column + 1,
          ? (span.isIdentifier ? span.text : frame.member)
          : _prettifyMember(frame.member));
}).where((frame) => frame != null));

Asynchronous Stack Chains

Writing asynchronous code is tough. Lots of stuff is happening in disconnected bursts without strong guarantees about ordering, and it can be really hard to figure out what’s happening where and why. You may have to think in four dimensions to understand your program flow in its entirely, but at least the stack_trace package can help you out with the Chain class.

Whether you’re running on the Dart VM or on a browser, the implementation’s notion of a stack isn’t all that useful in heavily-asynchronous code. It just includes frames from somewhere inside the DOM or dart:async to your callback, without any further context. In order to know what’s really going on, you’d need to know what the stack was when the callback was registered. And if it was registered in another callback, you’d need the stack before that, and so on.

That’s what a stack chain describes: a list of stack traces that, together, shows how you got from main() to wherever the stack was captured. And as you’d expect, a Chain object simply contains a list of Traces. The real magic is in how you get these chains: The Chain.capture() static method.

import 'package:stack_trace/stack_trace.dart';

void main() {
  Chain.capture(() {
    // Your program goes here.

That’s the easiest way to use Chain.capture(): just wrap it around your entire program. Any errors that cause your program to exit will have their entire stack chains printed. Here’s an example of what that looks like (with Chain.terse called, of course):

test.dart 17:3       runAsync
test.dart 13:28      scheduleAsync.<fn>
===== asynchronous gap ===========================
dart:async           _Future.then
test.dart 13:12      scheduleAsync
test.dart 7:18       main.<fn>
package:stack_trace  Chain.capture
test.dart 6:16       main

That “asynchronous gap” is where one stack trace ends and the next begins. Here’s how you read it: main() called a bunch of stuff that eventually terminated in a call to Future.then(). Then once that future fired, it ran the callback in scheduleAsync() that called runAsync(). If the future had fired synchronously, the stack would look the same, just without the gap.

I called this “magic” earlier, but it’s actually possible to understand how it works. It’s based on Dart’s notion of zones, which you can read about in detail elsewhere. For our purposes, you just need to know that a custom zone lets us add extra behavior to async stuff, and that it’s active in its callback, any callbacks its callback registers, and so forth. Let’s call the zone Chain.capture() creates the capture zone.

The capture zone keeps track of a tree of stack traces. Each callback is associated with a particular node on that tree, and when that callback runs, the zone remembers its node. If the current callback registers a new callback, a new node—containing the current stack trace—is added as a child of the current node and associated with the new callback. And when an error occurs, we just add its stack trace to the current node’s stack chain to get a Chain object, which we associate with the trace that produced it.

This scheme lets us provide two important APIs. Because we have a chain associated with every trace, we can get the chain for a specific trace with new Chain.forTrace() constructor. This returns a full chain for any stack trace created in the capture zone, and for consistency it will even wrap stack traces in a Chain outside the zone (although it won’t provide any extra information).

Also, because we always know the current node in the tree of traces, we can get the current stack chain with new Chain.current(). This is useful for simple tasks like printing the current chain while debugging, but it also lets packages like scheduled_test store stack chains for use in future debugging. To suit the latter use case, you can pass in a number of frames to cut off from the bottom so users don’t see the library’s capturing function in their nice pristine stacks.

Since the stack chain capture zone stores a node for every registered callback, you might be thinking that it’s pretty performance-intensive. In practice, it’s less of a drag than it seems like it would be—partly because it’s set up so that nodes that can’t possibly be used are garbage-collected—but it’s definitely not something you want to leave on in production. That’s why Chain.capture() has a when parameter: just pass in false when you’re running in production mode, and all capturing is disabled.

Trace Your Stacks

Whether you go off and build a powerful stack trace processor or just start wrapping your main()s in Chain.capture(), you should be using stack_trace. No matter how good of a programmer someone might be, errors do happen, and stack traces are the most straightforward tool we have for understanding what’s going on. You’ll have to work with them one way or another—do yourself a favor and do it in comfort and style.