If you’ve ever tried to debug asynchronous code written with Twitter
you may have found that the stack trace isn’t always helpful. The stack trace
at a given point in the program includes the active stack frames and thus shows
the chain of function calls that led up to that point. Since asynchronous
execution causes different parts of a program to have their stack traces chopped
up, the stack trace often shows unexpected internal library calls and is missing
the causality developers are used to from synchronous code. As a result, the
context leading to the current stack frame is lost.
IntelliJ 2017.1 included a feature called Capture Points. This feature lets us stitch together stack frames so that the order of functions in the stack trace respects the order in which they were called.
Our summer intern, Haggai Kaunda, wrote capture
points specific to Twitter
(thanks, Haggai!). Using these can make debugging asynchronous code written
Futures simpler by providing more informative stack traces.
Note that as of November 2017, the capture points are guaranteed to work with only Scala 2.11. We are not working on capture points for 2.12 at this time; if you would like to help make this feature available for more users, you can submit a pull request on util’s GitHub repo.
To start using, you can grab the capture points XML file directly from GitHub, and after our next release it will be available as an artifact published to Maven Central.
The capture points are defined in TwitterFuturesCapturePoints.xml. To import them into IntelliJ,
Set a breakpoint where you wish to see the stack trace, debug your code, and look at the “Frames” tab in the Debugger. Any asynchronous calls in the stack trace will appear in logical order. If you wish to clean up the stack trace, click the funnel icon in the top right, “Hide Frames from Libraries”.
A brief explanation of this test: the test passes a
through three methods and then sets the
Promise’s value in a
The calls are asynchronous, but the logical flow of the test is as follows:
lordBusinessLogicwaits for the
Promise’s value to be set
Promise’s value is set in the test block (this could happen at any time; it is not necessarily step number 5)
4, and the test passes
Suppose we wish to inspect the stack trace from inside
we set a breakpoint at line 47 and then debug the test in IntelliJ with the
capture points disabled, we see the following stack trace:
apply$mcVI$sp:47, Demo$$anonfun$lordBusinessLogic$1 apply:1820, Future$$anonfun$onSuccess$1 apply:205, Promise$Monitored run:532, Promise$$anon$7 run:198, LocalScheduler$Activation submit:157, LocalScheduler$Activation submit:274, LocalScheduler submit:109, Scheduler$ runq:522, Promise updatelfEmpty:880, Promise update:859, Promise setValue:835, Promise apply$mcV$sp:20, Demo$$anonfun$3$$anonfun$apply$1 apply:15, Try$ run:140, ExecutorServiceFuturePool$$anon$4
The library calls in the stack trace do not help us understand our code. If we enable the capture points and again debug the test, we see the following stack trace:
apply$mcVI$sp:47, Demo$$anonfun$lordBusinessLogic$1 apply:1820, Future$$anonfun$onSuccess$1 onSuccess:1819, Future lordBusinessLogic:42, Demo moreBusinessLogic:38, Demo someBusinessLogic:31, Demo apply:17, Demo$$anonfun$3
This is much cleaner and it includes only calls to functions we wrote. It lets
us clearly see that the test block called
moreBusinessLogic, and that