From 7860b4c770aa03009737a37e0cac7b22a97db3e9 Mon Sep 17 00:00:00 2001 From: Bryan Klimt Date: Sun, 4 May 2014 16:34:27 -0700 Subject: [PATCH] Add a basic stack-tracking mechanism for easier debugging. --- Bolts/src/bolts/Task.java | 150 ++++++++++++- BoltsTest/src/bolts/TaskTest.java | 346 +++++++++++++++++++++++++++++- 2 files changed, 486 insertions(+), 10 deletions(-) diff --git a/Bolts/src/bolts/Task.java b/Bolts/src/bolts/Task.java index d53f379..8c8269a 100644 --- a/Bolts/src/bolts/Task.java +++ b/Bolts/src/bolts/Task.java @@ -13,6 +13,7 @@ import android.os.Looper; import java.util.ArrayList; +import java.util.Arrays; import java.util.Collection; import java.util.List; import java.util.concurrent.Callable; @@ -45,6 +46,19 @@ public class Task { */ public static final Executor UI_THREAD_EXECUTOR = new UIThreadExecutor(); + /** + * A thread-local copy of the current "logical stack trace" for each thread. A logical stack trace + * is different from the regular stack trace because it links across task boundaries such as + * continueWith. + */ + private static final ThreadLocal> stackTrace = + new ThreadLocal>(); + + /** + * Whether to track logical stack traces across continuations. + */ + private static final AtomicBoolean isStackTrackingEnabled = new AtomicBoolean(false); + private final Object lock = new Object(); private boolean complete; private boolean cancelled; @@ -191,14 +205,18 @@ public static Task callInBackground(Callable callabl */ public static Task call(final Callable callable, Executor executor) { final Task.TaskCompletionSource tcs = Task. create(); + final ArrayList currentStack = getCurrentStack(); executor.execute(new Runnable() { @Override public void run() { + final ArrayList previousStack = stackTrace.get(); + stackTrace.set(currentStack); try { tcs.setResult(callable.call()); } catch (Exception e) { tcs.setError(e); } + stackTrace.set(previousStack); } }); return tcs.getTask(); @@ -244,9 +262,9 @@ public Void then(Task task) { if (count.decrementAndGet() == 0) { if (errors.size() != 0) { if (errors.size() == 1) { - allFinished.setError(errors.get(0)); + allFinished.setError(errors.get(0), false); } else { - allFinished.setError(new AggregateException(errors)); + allFinished.setError(new AggregateException(errors), false); } } else if (isCancelled.get()) { allFinished.setCancelled(); @@ -292,6 +310,74 @@ public Task then(Task task) throws Exception { return makeVoid().continueWithTask(predicateContinuation.get(), executor); } + /** + * Returns true if the task framework should keep track of the logical stack. + */ + private static boolean isStackTrackingEnabled() { + return isStackTrackingEnabled.get(); + } + + /** + * Enables tracking the "logical stack" across multiple continuations. If this is enabled, the + * stack trace for any exception that a task errors with will be modified. Its stack trace will be + * augmented by adding in the stacks of previous continuations that led to the current code. This + * makes debugging async code much easier, but also has a significant negative impact on overall + * performance. This should only be used when debugging, and never in production code. + */ + public static void enableStackTracking(boolean newValue) { + isStackTrackingEnabled.set(newValue); + } + + /** + * Returns the current logical stack for this thread. It combines the current actual stack with + * the stack that has been tracked across continuations. + */ + private static ArrayList getCurrentStack() { + if (!isStackTrackingEnabled()) { + return null; + } + + List newStack = Arrays.asList(Thread.currentThread().getStackTrace()); + // Trim out the garbage on the stack trace just from getting the stack trace. + while (newStack.size() > 0 + && ("dalvik.system.VMStack".equals(newStack.get(0).getClassName()) && "getThreadStackTrace" + .equals(newStack.get(0).getMethodName())) + || ("java.lang.Thread".equals(newStack.get(0).getClassName()) && "getStackTrace" + .equals(newStack.get(0).getMethodName())) + || ("bolts.Task".equals(newStack.get(0).getClassName()) && "getCurrentStack" + .equals(newStack.get(0).getMethodName()))) { + newStack = newStack.subList(1, newStack.size()); + } + + return getCurrentStack(newStack); + } + + /** + * Returns the current logical stack. It combines the given stack with the stack that has been + * tracked across continuations. + * + * @param newStack + * The current local stack to be combined with the stack from previous continuations. For + * example, when handling an exception, the stack for the exception should be passed in + * here. + */ + private static ArrayList getCurrentStack(List newStack) { + if (!isStackTrackingEnabled()) { + return null; + } + + // If stack-tracking is enabled, capture the stack here. + final ArrayList currentStack = new ArrayList(); + currentStack.addAll(newStack); + + // And add in the previously captured stack. + final ArrayList previousStack = stackTrace.get(); + if (previousStack != null) { + currentStack.addAll(previousStack); + } + return currentStack; + } + /** * Adds a continuation that will be scheduled using the executor, returning a new task that * completes after the continuation has finished running. This allows the continuation to be @@ -299,6 +385,8 @@ public Task then(Task task) throws Exception { */ public Task continueWith( final Continuation continuation, final Executor executor) { + final ArrayList currentStack = getCurrentStack(); + boolean completed = false; final Task.TaskCompletionSource tcs = Task. create(); synchronized (lock) { @@ -307,14 +395,14 @@ public Task continueWith( this.continuations.add(new Continuation() { @Override public Void then(Task task) { - completeImmediately(tcs, continuation, task, executor); + completeImmediately(tcs, continuation, task, executor, currentStack); return null; } }); } } if (completed) { - completeImmediately(tcs, continuation, this, executor); + completeImmediately(tcs, continuation, this, executor, currentStack); } return tcs.getTask(); } @@ -334,6 +422,8 @@ public Task continueWith( */ public Task continueWithTask( final Continuation> continuation, final Executor executor) { + final ArrayList currentStack = getCurrentStack(); + boolean completed = false; final Task.TaskCompletionSource tcs = Task. create(); synchronized (lock) { @@ -342,14 +432,14 @@ public Task continueWithTask( this.continuations.add(new Continuation() { @Override public Void then(Task task) { - completeAfterTask(tcs, continuation, task, executor); + completeAfterTask(tcs, continuation, task, executor, currentStack); return null; } }); } } if (completed) { - completeAfterTask(tcs, continuation, this, executor); + completeAfterTask(tcs, continuation, this, executor, currentStack); } return tcs.getTask(); } @@ -435,20 +525,25 @@ public Task onSuccessTask( * @param executor * The executor to use when running the continuation (allowing the continuation to be * scheduled on a different thread). + * @param currentStack + * If stack-tracking is enabled, the current logical stack for this continuation. */ private static void completeImmediately( final Task.TaskCompletionSource tcs, final Continuation continuation, final Task task, - Executor executor) { + Executor executor, final ArrayList currentStack) { executor.execute(new Runnable() { @Override public void run() { + final ArrayList previousStack = stackTrace.get(); + stackTrace.set(currentStack); try { TContinuationResult result = continuation.then(task); tcs.setResult(result); } catch (Exception e) { tcs.setError(e); } + stackTrace.set(previousStack); } }); } @@ -472,10 +567,13 @@ public void run() { private static void completeAfterTask( final Task.TaskCompletionSource tcs, final Continuation> continuation, - final Task task, final Executor executor) { + final Task task, final Executor executor, + final ArrayList currentStack) { executor.execute(new Runnable() { @Override public void run() { + final ArrayList previousStack = stackTrace.get(); + stackTrace.set(currentStack); try { Task result = continuation.then(task); if (result == null) { @@ -487,7 +585,7 @@ public Void then(Task task) { if (task.isCancelled()) { tcs.setCancelled(); } else if (task.isFaulted()) { - tcs.setError(task.getError()); + tcs.setError(task.getError(), false); } else { tcs.setResult(task.getResult()); } @@ -498,6 +596,7 @@ public Void then(Task task) { } catch (Exception e) { tcs.setError(e); } + stackTrace.set(previousStack); } }); } @@ -506,6 +605,10 @@ private void runContinuations() { synchronized (lock) { for (Continuation continuation : continuations) { try { + /* + * We don't have to set the current stack trace here because it's already been captured + * and added to the continuation in continueWith or continueWithTask. + */ continuation.then(this); } catch (RuntimeException e) { throw e; @@ -570,6 +673,23 @@ public boolean trySetResult(TResult result) { * Sets the error on the Task if the Task hasn't already been completed. */ public boolean trySetError(Exception error) { + return trySetError(error, isStackTrackingEnabled()); + } + + /** + * Sets the error on the Task if the Task hasn't already been completed. + * + * @param rewriteStackTrace + * Whether to rewrite the stack trace with the logical stack trace that was tracked. + */ + private boolean trySetError(Exception error, boolean rewriteStackTrace) { + if (rewriteStackTrace) { + // Override the stack trace in the exception with the current continuation stack trace. + List newStack = Arrays.asList(error.getStackTrace()); + List currentStack = getCurrentStack(newStack); + error.setStackTrace(currentStack.toArray(new StackTraceElement[0])); + } + synchronized (lock) { if (complete) { return false; @@ -608,6 +728,18 @@ public void setError(Exception error) { throw new IllegalStateException("Cannot set the error on a completed task."); } } + + /** + * Sets the error of the Task, throwing if the Task has already been completed. + * + * @param rewriteStackTrace + * Whether to rewrite the stack trace with the logical stack trace that was tracked. + */ + private void setError(Exception error, boolean rewriteStackTrace) { + if (!trySetError(error, rewriteStackTrace)) { + throw new IllegalStateException("Cannot set the error on a completed task."); + } + } } /** diff --git a/BoltsTest/src/bolts/TaskTest.java b/BoltsTest/src/bolts/TaskTest.java index d0b4ac4..b6fbc98 100644 --- a/BoltsTest/src/bolts/TaskTest.java +++ b/BoltsTest/src/bolts/TaskTest.java @@ -39,6 +39,7 @@ private void runTaskTest(Callable> callable) { } catch (Exception e) { throw new RuntimeException(e); } + Task.enableStackTracking(false); } public void testPrimitives() { @@ -511,4 +512,347 @@ public Void then(Task task) throws Exception { } }); } -} + + public void testStackTrackerWithContinueWithTaskSetError() { + Task.enableStackTracking(true); + + /* + * Add a set of function to track on the stack across multiple continuations. + */ + class Funcs { + public Task fooInBackground() { + return Task. forResult(null).continueWithTask(new Continuation>() { + @Override + public Task then(Task task) throws Exception { + return barInBackground(); + } + }, Task.BACKGROUND_EXECUTOR); + } + + public Task barInBackground() { + return Task. forResult(null).continueWithTask(new Continuation>() { + @Override + public Task then(Task task) throws Exception { + return bazInBackground(); + } + }, Task.BACKGROUND_EXECUTOR); + } + + public Task bazInBackground() { + return Task.forError(new RuntimeException("An error to track.")); + } + }; + final Funcs funcs = new Funcs(); + + runTaskTest(new Callable>() { + public Task call() throws Exception { + return funcs.fooInBackground().continueWith(new Continuation() { + @Override + public Void then(Task task) throws Exception { + assertTrue(task.isFaulted()); + assertTrue(task.getError() instanceof RuntimeException); + RuntimeException error = (RuntimeException) task.getError(); + StackTraceElement[] stackTrace = error.getStackTrace(); + assertTrue(stackTrace.length > 0); + boolean fooFound = false; + boolean barFound = false; + boolean bazFound = false; + for (StackTraceElement line : stackTrace) { + if ("fooInBackground".equals(line.getMethodName())) { + fooFound = true; + } + if ("barInBackground".equals(line.getMethodName())) { + barFound = true; + } + if ("bazInBackground".equals(line.getMethodName())) { + bazFound = true; + } + } + assertTrue(fooFound); + assertTrue(barFound); + assertTrue(bazFound); + return null; + } + }); + } + }); + } + + public void testStackTrackerWithContinueWithTaskThrows() { + Task.enableStackTracking(true); + + /* + * Add a set of function to track on the stack across multiple continuations. + */ + class Funcs { + public Task fooInBackground() { + return Task. forResult(null).continueWithTask(new Continuation>() { + @Override + public Task then(Task task) throws Exception { + return barInBackground(); + } + }, Task.BACKGROUND_EXECUTOR); + } + + public Task barInBackground() { + return Task. forResult(null).continueWithTask(new Continuation>() { + @Override + public Task then(Task task) throws Exception { + return bazInBackground(); + } + }, Task.BACKGROUND_EXECUTOR); + } + + public Task bazInBackground() { + throw new RuntimeException("An error to track."); + } + }; + final Funcs funcs = new Funcs(); + + runTaskTest(new Callable>() { + public Task call() throws Exception { + return funcs.fooInBackground().continueWith(new Continuation() { + @Override + public Void then(Task task) throws Exception { + assertTrue(task.isFaulted()); + assertTrue(task.getError() instanceof RuntimeException); + RuntimeException error = (RuntimeException) task.getError(); + StackTraceElement[] stackTrace = error.getStackTrace(); + assertTrue(stackTrace.length > 0); + boolean fooFound = false; + boolean barFound = false; + boolean bazFound = false; + for (StackTraceElement line : stackTrace) { + if ("fooInBackground".equals(line.getMethodName())) { + fooFound = true; + } + if ("barInBackground".equals(line.getMethodName())) { + barFound = true; + } + if ("bazInBackground".equals(line.getMethodName())) { + bazFound = true; + } + } + assertTrue(fooFound); + assertTrue(barFound); + assertTrue(bazFound); + return null; + } + }); + } + }); + } + + public void testStackTrackerWithContinueWithThrows() { + Task.enableStackTracking(true); + + /* + * Add a set of function to track on the stack across multiple continuations. + */ + class Funcs { + public Task fooInBackground() { + return Task. forResult(null).continueWithTask(new Continuation>() { + @Override + public Task then(Task task) throws Exception { + return barInBackground(); + } + }, Task.BACKGROUND_EXECUTOR); + } + + public Task barInBackground() { + return Task. forResult(null).continueWithTask(new Continuation>() { + @Override + public Task then(Task task) throws Exception { + return bazInBackground(); + } + }, Task.BACKGROUND_EXECUTOR); + } + + public Task bazInBackground() { + return Task. forResult(null).continueWith(new Continuation() { + @Override + public Void then(Task task) throws Exception { + throw new RuntimeException("An error to track."); + } + }, Task.BACKGROUND_EXECUTOR); + } + }; + final Funcs funcs = new Funcs(); + + runTaskTest(new Callable>() { + public Task call() throws Exception { + return funcs.fooInBackground().continueWith(new Continuation() { + @Override + public Void then(Task task) throws Exception { + assertTrue(task.isFaulted()); + assertTrue(task.getError() instanceof RuntimeException); + RuntimeException error = (RuntimeException) task.getError(); + StackTraceElement[] stackTrace = error.getStackTrace(); + assertTrue(stackTrace.length > 0); + boolean fooFound = false; + boolean barFound = false; + boolean bazFound = false; + for (StackTraceElement line : stackTrace) { + if ("fooInBackground".equals(line.getMethodName())) { + fooFound = true; + } + if ("barInBackground".equals(line.getMethodName())) { + barFound = true; + } + if ("bazInBackground".equals(line.getMethodName())) { + bazFound = true; + } + } + assertTrue(fooFound); + assertTrue(barFound); + assertTrue(bazFound); + return null; + } + }); + } + }); + } + + public void testStackTrackerWithCallInBackgroundSetError() { + Task.enableStackTracking(true); + + /* + * Add a set of function to track on the stack across multiple continuations. + */ + class Funcs { + public Task fooInBackground() { + return Task. forResult(null).continueWithTask(new Continuation>() { + @Override + public Task then(Task task) throws Exception { + return barInBackground(); + } + }, Task.BACKGROUND_EXECUTOR); + } + + public Task barInBackground() { + return Task. forResult(null).continueWithTask(new Continuation>() { + @Override + public Task then(Task task) throws Exception { + return bazInBackground(); + } + }, Task.BACKGROUND_EXECUTOR); + } + + public Task bazInBackground() { + return Task.callInBackground(new Callable() { + @Override + public Void call() throws Exception { + return null; + } + }).continueWithTask(new Continuation>() { + @Override + public Task then(Task task) throws Exception { + return Task.forError(new RuntimeException("An error to track.")); } + }); + } + }; + final Funcs funcs = new Funcs(); + + runTaskTest(new Callable>() { + public Task call() throws Exception { + return funcs.fooInBackground().continueWith(new Continuation() { + @Override + public Void then(Task task) throws Exception { + assertTrue(task.isFaulted()); + assertTrue(task.getError() instanceof RuntimeException); + RuntimeException error = (RuntimeException) task.getError(); + StackTraceElement[] stackTrace = error.getStackTrace(); + assertTrue(stackTrace.length > 0); + boolean fooFound = false; + boolean barFound = false; + boolean bazFound = false; + for (StackTraceElement line : stackTrace) { + if ("fooInBackground".equals(line.getMethodName())) { + fooFound = true; + } + if ("barInBackground".equals(line.getMethodName())) { + barFound = true; + } + if ("bazInBackground".equals(line.getMethodName())) { + bazFound = true; + } + } + assertTrue(fooFound); + assertTrue(barFound); + assertTrue(bazFound); + return null; + } + }); + } + }); + } + + public void testStackTrackerWithCallInBackgroundThrows() { + Task.enableStackTracking(true); + + /* + * Add a set of function to track on the stack across multiple continuations. + */ + class Funcs { + public Task fooInBackground() { + return Task. forResult(null).continueWithTask(new Continuation>() { + @Override + public Task then(Task task) throws Exception { + return barInBackground(); + } + }, Task.BACKGROUND_EXECUTOR); + } + + public Task barInBackground() { + return Task. forResult(null).continueWithTask(new Continuation>() { + @Override + public Task then(Task task) throws Exception { + return bazInBackground(); + } + }, Task.BACKGROUND_EXECUTOR); + } + + public Task bazInBackground() { + return Task.callInBackground(new Callable() { + @Override + public Void call() throws Exception { + throw new RuntimeException("An error to track."); + } + }); + } + }; + final Funcs funcs = new Funcs(); + + runTaskTest(new Callable>() { + public Task call() throws Exception { + return funcs.fooInBackground().continueWith(new Continuation() { + @Override + public Void then(Task task) throws Exception { + assertTrue(task.isFaulted()); + assertTrue(task.getError() instanceof RuntimeException); + RuntimeException error = (RuntimeException) task.getError(); + StackTraceElement[] stackTrace = error.getStackTrace(); + assertTrue(stackTrace.length > 0); + boolean fooFound = false; + boolean barFound = false; + boolean bazFound = false; + for (StackTraceElement line : stackTrace) { + if ("fooInBackground".equals(line.getMethodName())) { + fooFound = true; + } + if ("barInBackground".equals(line.getMethodName())) { + barFound = true; + } + if ("bazInBackground".equals(line.getMethodName())) { + bazFound = true; + } + } + assertTrue(fooFound); + assertTrue(barFound); + assertTrue(bazFound); + return null; + } + }); + } + }); + }}