Skip to content
This repository has been archived by the owner on Sep 2, 2020. It is now read-only.

Add a basic stack-tracking mechanism for easier debugging. #11

Open
wants to merge 1 commit into
base: master
Choose a base branch
from
Open

Add a basic stack-tracking mechanism for easier debugging. #11

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
150 changes: 141 additions & 9 deletions Bolts/src/bolts/Task.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -45,6 +46,19 @@ public class Task<TResult> {
*/
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<ArrayList<StackTraceElement>> stackTrace =
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It would be really great to be able to get to the logical stack trace for a task, regardless of whether the task has an error.

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could we rename this member "logicalStackTrace" or something along those lines? My brain is having a hard time keeping this separate from the real stack trace when I see it mixed into the code ;)

new ThreadLocal<ArrayList<StackTraceElement>>();

/**
* 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;
Expand Down Expand Up @@ -191,14 +205,18 @@ public static <TResult> Task<TResult> callInBackground(Callable<TResult> callabl
*/
public static <TResult> Task<TResult> call(final Callable<TResult> callable, Executor executor) {
final Task<TResult>.TaskCompletionSource tcs = Task.<TResult> create();
final ArrayList<StackTraceElement> currentStack = getCurrentStack();
executor.execute(new Runnable() {
@Override
public void run() {
final ArrayList<StackTraceElement> previousStack = stackTrace.get();
stackTrace.set(currentStack);
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you add a comment about the impact of setting the threadlocal here/what it's intended to do?

try {
tcs.setResult(callable.call());
} catch (Exception e) {
tcs.setError(e);
}
stackTrace.set(previousStack);
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Each of these should be in a finally block. You're pretty much guaranteed to be ok since you completely own the TCS, but in case we ever add code to the catch here the could throw, it's probably safer this way.

}
});
return tcs.getTask();
Expand Down Expand Up @@ -244,9 +262,9 @@ public Void then(Task<Object> 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();
Expand Down Expand Up @@ -292,13 +310,83 @@ public Task<Void> then(Task<Void> 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<StackTraceElement> getCurrentStack() {
if (!isStackTrackingEnabled()) {
return null;
}

List<StackTraceElement> newStack = Arrays.asList(Thread.currentThread().getStackTrace());
// Trim out the garbage on the stack trace just from getting the stack trace.
while (newStack.size() > 0
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmm... can we trim the garbage by just looking for this method (i.e. trim until we find Task.getCurrentStack())? That seems like it'll be a little more future-proof and will work regardless of whether we're in Android or Java.

&& ("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<StackTraceElement> getCurrentStack(List<StackTraceElement> newStack) {
if (!isStackTrackingEnabled()) {
return null;
}

// If stack-tracking is enabled, capture the stack here.
final ArrayList<StackTraceElement> currentStack = new ArrayList<StackTraceElement>();
currentStack.addAll(newStack);

// And add in the previously captured stack.
final ArrayList<StackTraceElement> previousStack = stackTrace.get();
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could we put a divider/dummy StackTraceElement in between these sections? Then you'd be able to see the task/thread boundaries more easily at a glance.

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
* scheduled on different thread.
*/
public <TContinuationResult> Task<TContinuationResult> continueWith(
final Continuation<TResult, TContinuationResult> continuation, final Executor executor) {
final ArrayList<StackTraceElement> currentStack = getCurrentStack();

boolean completed = false;
final Task<TContinuationResult>.TaskCompletionSource tcs = Task.<TContinuationResult> create();
synchronized (lock) {
Expand All @@ -307,14 +395,14 @@ public <TContinuationResult> Task<TContinuationResult> continueWith(
this.continuations.add(new Continuation<TResult, Void>() {
@Override
public Void then(Task<TResult> 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();
}
Expand All @@ -334,6 +422,8 @@ public <TContinuationResult> Task<TContinuationResult> continueWith(
*/
public <TContinuationResult> Task<TContinuationResult> continueWithTask(
final Continuation<TResult, Task<TContinuationResult>> continuation, final Executor executor) {
final ArrayList<StackTraceElement> currentStack = getCurrentStack();

boolean completed = false;
final Task<TContinuationResult>.TaskCompletionSource tcs = Task.<TContinuationResult> create();
synchronized (lock) {
Expand All @@ -342,14 +432,14 @@ public <TContinuationResult> Task<TContinuationResult> continueWithTask(
this.continuations.add(new Continuation<TResult, Void>() {
@Override
public Void then(Task<TResult> 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();
}
Expand Down Expand Up @@ -435,20 +525,25 @@ public <TContinuationResult> Task<TContinuationResult> 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 <TContinuationResult, TResult> void completeImmediately(
final Task<TContinuationResult>.TaskCompletionSource tcs,
final Continuation<TResult, TContinuationResult> continuation, final Task<TResult> task,
Executor executor) {
Executor executor, final ArrayList<StackTraceElement> currentStack) {
executor.execute(new Runnable() {
@Override
public void run() {
final ArrayList<StackTraceElement> previousStack = stackTrace.get();
stackTrace.set(currentStack);
try {
TContinuationResult result = continuation.then(task);
tcs.setResult(result);
} catch (Exception e) {
tcs.setError(e);
}
stackTrace.set(previousStack);
}
});
}
Expand All @@ -472,10 +567,13 @@ public void run() {
private static <TContinuationResult, TResult> void completeAfterTask(
final Task<TContinuationResult>.TaskCompletionSource tcs,
final Continuation<TResult, Task<TContinuationResult>> continuation,
final Task<TResult> task, final Executor executor) {
final Task<TResult> task, final Executor executor,
final ArrayList<StackTraceElement> currentStack) {
executor.execute(new Runnable() {
@Override
public void run() {
final ArrayList<StackTraceElement> previousStack = stackTrace.get();
stackTrace.set(currentStack);
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Similarly, comments here about what this actually causes to happen would be helpful.

try {
Task<TContinuationResult> result = continuation.then(task);
if (result == null) {
Expand All @@ -487,7 +585,7 @@ public Void then(Task<TContinuationResult> task) {
if (task.isCancelled()) {
tcs.setCancelled();
} else if (task.isFaulted()) {
tcs.setError(task.getError());
tcs.setError(task.getError(), false);
} else {
tcs.setResult(task.getResult());
}
Expand All @@ -498,6 +596,7 @@ public Void then(Task<TContinuationResult> task) {
} catch (Exception e) {
tcs.setError(e);
}
stackTrace.set(previousStack);
}
});
}
Expand All @@ -506,6 +605,10 @@ private void runContinuations() {
synchronized (lock) {
for (Continuation<TResult, ?> 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;
Expand Down Expand Up @@ -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<StackTraceElement> newStack = Arrays.asList(error.getStackTrace());
List<StackTraceElement> currentStack = getCurrentStack(newStack);
error.setStackTrace(currentStack.toArray(new StackTraceElement[0]));
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What happens if the executor was executing things immediately? Will the error now have a duplicated stack trace?

Also, it would be helpful to put a divider/dummy StackTraceElement in between the real stack and the logical stack, just to make it obvious where the split is.

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is there a way to prevent double-tracking in the case of passing along errors? For example (pseudocoding):

fooAsync().continueWithTask((Task t) -> {
  if (t.getError() != null) {
    return Task.fromError(t.getError());
  }
  return Task.fromResult(doSomething(t.getResult()));
}

In the case of an error, it seems like this will get the logical stack twice.

}

synchronized (lock) {
if (complete) {
return false;
Expand Down Expand Up @@ -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.");
}
}
}

/**
Expand Down
Loading