如何创建异步堆栈跟踪?

16
更新: IntelliJ IDEA的最新版本实现了我所寻求的功能。问题是如何在IDE之外实现这一点(以便我可以将异步堆栈跟踪转储到日志文件中),最好不使用插桩代理。

自从我将应用程序从同步模型转换为异步模型以来,我一直在遇到调试故障的问题。

当我使用同步API时,我总是能在异常堆栈跟踪中找到我的类,因此如果出现问题,我知道从哪里开始查找。对于异步API,我得到的堆栈跟踪未引用我的类,也不指示导致故障的请求。

我将给你一个具体的例子,但我对这种问题的通用解决方案感兴趣。

具体例子

我使用Jersey发出HTTP请求:

new Client().target("http://test.com/").request().rx().get(JsonNode.class);

rx()表示请求应该异步进行,返回一个CompletionStage<JsonNode>而不是直接返回一个JsonNode。如果此调用失败,我会得到以下堆栈跟踪信息:

rx()表示请求应该异步进行,返回一个CompletionStage<JsonNode>而不是直接返回一个JsonNode。如果此调用失败,我会得到以下堆栈跟踪信息:

javax.ws.rs.ForbiddenException: HTTP 403 Authentication Failed
    at org.glassfish.jersey.client.JerseyInvocation.convertToException(JerseyInvocation.java:1083)
    at org.glassfish.jersey.client.JerseyInvocation.translate(JerseyInvocation.java:883)
    at org.glassfish.jersey.client.JerseyInvocation.lambda$invoke$1(JerseyInvocation.java:767)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:229)
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:414)
    at org.glassfish.jersey.client.JerseyInvocation.invoke(JerseyInvocation.java:765)
    at org.glassfish.jersey.client.JerseyInvocation$Builder.method(JerseyInvocation.java:456)
    at org.glassfish.jersey.client.JerseyCompletionStageRxInvoker.lambda$method$1(JerseyCompletionStageRxInvoker.java:70)
    at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1590)

注意:

  • 堆栈跟踪未引用用户代码。
  • 异常消息不包含有关触发错误的HTTP请求的上下文信息(HTTP方法、URI等)。

因此,我无法将异常追溯回其源头。

为什么会发生这种情况

如果你深入了解,你会发现Jersey正在调用:

Jersey完成阶段RxInvoker
CompletableFuture.supplyAsync(() -> getSyncInvoker().method(name, entity, responseType))

对于rx()调用。由于供应商是由Jersey构造的,因此没有与用户代码的引用。

我尝试过的

我曾经针对Jetty的一个不相关的异步示例提交了错误报告,但随后基于安全原因被拒绝。

相反,我一直在添加上下文信息,如下所示:

makeHttpRequest().exceptionally(e ->
{
    throw new RuntimeException(e);
});

我的意思是,在我的代码中的每个HTTP请求之后手动添加exceptionally()。 Jersey抛出的任何异常都会被包装在一个引用我的代码的次要异常中。结果堆栈跟踪看起来像这样:

意思是,我在我的代码中每个HTTP请求后手动添加exceptionally()。Jersey抛出的任何异常都被包装在一个次级异常中,该异常引用了我的代码。由此产生的堆栈跟踪如上所示:

java.lang.RuntimeException: javax.ws.rs.ForbiddenException: HTTP 403 Authentication Failed
    at my.user.code.Testcase.lambda$null$1(Testcase.java:25)
    at java.util.concurrent.CompletableFuture.uniExceptionally(CompletableFuture.java:870)
    ... 6 common frames omitted
Caused by: javax.ws.rs.ForbiddenException: HTTP 403 Authentication Failed
    at org.glassfish.jersey.client.JerseyInvocation.convertToException(JerseyInvocation.java:1083)
    at org.glassfish.jersey.client.JerseyInvocation.translate(JerseyInvocation.java:883)
    at org.glassfish.jersey.client.JerseyInvocation.lambda$invoke$1(JerseyInvocation.java:767)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:229)
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:414)
    at org.glassfish.jersey.client.JerseyInvocation.invoke(JerseyInvocation.java:765)
    at org.glassfish.jersey.client.JerseyInvocation$Builder.method(JerseyInvocation.java:456)
    at org.glassfish.jersey.client.JerseyCompletionStageRxInvoker.lambda$method$1(JerseyCompletionStageRxInvoker.java:70)
    at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1590)
    ... 3 common frames omitted

我不喜欢这种方法,因为容易出错并且会降低代码的可读性。如果我无意中在某个HTTP请求中遗漏了它,最终将得到一个模糊的堆栈跟踪,并花费大量时间来跟踪它。

此外,如果我想隐藏这个技巧在实用程序类的背后,那么我必须在CompletionStage之外实例化一个异常;否则,实用程序类将显示在堆栈跟踪中,而不是实际的调用站点。在CompletionStage之外实例化一个异常非常昂贵,因为即使异步调用永远不会抛出异常,此代码也会运行。

我的问题

有没有一种强大、易于维护的方法来为异步调用添加上下文信息?

或者,有没有一种有效的方法来追踪堆栈跟踪返回其源代码,而不需要这些上下文信息?


像往常一样,这是一个好问题。我列出了一个关于异步编程的演示文稿,在那里他们说最难的事情是在需要时进行调试和获取异常信息... - Eugene
Spring的RestTemplate有一个名为setErrorHandler(ResponseErrorHandler)的方法,而ResponseErrorHandler接收HTTP响应。我认为Jersey也有类似的东西,至少谷歌搜索“Jersey错误处理”会给出许多网络参考资料。 - Alexei Kaigorodov
@AlexeiKaigorodov 正如我在问题的开头解释的那样,我正在寻找一个通用解决方案。我给出的具体示例只是更普遍问题的一个特定示例。此外,我认为错误处理程序无法在异步抛出异常时知道调用站点。 - Gili
假设在CompletableFutureCompletionStage的链中,错误信息会返回给异步调用者。这是一个约定。如果没有这个约定,那么某些阶段就会表现不当并将其丢弃,这是一个错误。由于Jersey维护人员拒绝了你的Bug报告,你必须自己找到这个地方。然后你可以修复它并提交一个Pull请求。 - Alexei Kaigorodov
2个回答

6

由于这个问题已经近一个月没有得到任何答案,我将发布迄今为止我找到的最佳解决方案:

DebugCompletableFuture.java:

/**
 * A {@link CompletableFuture} that eases debugging.
 *
 * @param <T> the type of value returned by the future
 */
public final class DebugCompletableFuture<T> extends CompletableFuture<T>
{
    private static RunMode RUN_MODE = RunMode.DEBUG;
    private static final Set<String> CLASS_PREFIXES_TO_REMOVE = ImmutableSet.of(DebugCompletableFuture.class.getName(),
        CompletableFuture.class.getName(), ThreadPoolExecutor.class.getName());
    private static final Set<Class<? extends Throwable>> EXCEPTIONS_TO_UNWRAP = ImmutableSet.of(AsynchronousException.class,
        CompletionException.class, ExecutionException.class);
    private final CompletableFuture<T> delegate;
    private final AsynchronousException asyncStacktrace;

    /**
     * @param delegate the stage to delegate to
     * @throws NullPointerException if any of the arguments are null
     */
    private DebugCompletableFuture(CompletableFuture<T> delegate)
    {
        requireThat("delegate", delegate).isNotNull();
        this.delegate = delegate;
        this.asyncStacktrace = new AsynchronousException();
        delegate.whenComplete((value, exception) ->
        {
            if (exception == null)
            {
                super.complete(value);
                return;
            }
            exception = Exceptions.unwrap(exception, EXCEPTIONS_TO_UNWRAP);
            asyncStacktrace.initCause(exception);
            filterStacktrace(asyncStacktrace, element ->
            {
                String className = element.getClassName();
                for (String prefix : CLASS_PREFIXES_TO_REMOVE)
                    if (className.startsWith(prefix))
                        return true;
                return false;
            });
            Set<String> newMethods = getMethodsInStacktrace(asyncStacktrace);
            if (!newMethods.isEmpty())
            {
                Set<String> oldMethods = getMethodsInStacktrace(exception);
                newMethods.removeAll(oldMethods);
                if (!newMethods.isEmpty())
                {
                    // The async stacktrace introduces something new
                    super.completeExceptionally(asyncStacktrace);
                    return;
                }
            }
            super.completeExceptionally(exception);
        });
    }

    /**
     * @param exception an exception
     * @return the methods referenced by the stacktrace
     * @throws NullPointerException if {@code exception} is null
     */
    private Set<String> getMethodsInStacktrace(Throwable exception)
    {
        requireThat("exception", exception).isNotNull();
        Set<String> result = new HashSet<>();
        for (StackTraceElement element : exception.getStackTrace())
            result.add(element.getClassName() + "." + element.getMethodName());
        for (Throwable suppressed : exception.getSuppressed())
            result.addAll(getMethodsInStacktrace(suppressed));
        return result;
    }

    /**
     * @param <T2>     the type returned by the delegate
     * @param delegate the stage to delegate to
     * @return if {@code RUN_MODE == DEBUG} returns an instance that wraps {@code delegate}; otherwise, returns {@code delegate}
     * unchanged
     * @throws NullPointerException if any of the arguments are null
     */
    public static <T2> CompletableFuture<T2> wrap(CompletableFuture<T2> delegate)
    {
        if (RUN_MODE != RunMode.DEBUG)
            return delegate;
        return new DebugCompletableFuture<>(delegate);
    }

    /**
     * Removes stack trace elements that match a filter. The exception and its descendants are processed recursively.
     * <p>
     * This method can be used to remove lines that hold little value for the end user (such as the implementation of utility functions).
     *
     * @param exception     the exception to process
     * @param elementFilter returns true if the current stack trace element should be removed
     */
    private void filterStacktrace(Throwable exception, Predicate<StackTraceElement> elementFilter)
    {
        Throwable cause = exception.getCause();
        if (cause != null)
            filterStacktrace(cause, elementFilter);
        for (Throwable suppressed : exception.getSuppressed())
            filterStacktrace(suppressed, elementFilter);
        StackTraceElement[] elements = exception.getStackTrace();
        List<StackTraceElement> keep = new ArrayList<>(elements.length);
        for (StackTraceElement element : elements)
        {
            if (!elementFilter.test(element))
                keep.add(element);
        }
        exception.setStackTrace(keep.toArray(new StackTraceElement[0]));
    }

    @Override
    public <U> CompletableFuture<U> thenApply(Function<? super T, ? extends U> fn)
    {
        return wrap(super.thenApply(fn));
    }

    @Override
    public <U> CompletableFuture<U> thenApplyAsync(Function<? super T, ? extends U> fn)
    {
        return wrap(super.thenApplyAsync(fn));
    }

    @Override
    public <U> CompletableFuture<U> thenApplyAsync(Function<? super T, ? extends U> fn, Executor executor)
    {
        return wrap(super.thenApplyAsync(fn, executor));
    }

    @Override
    public CompletableFuture<Void> thenAccept(Consumer<? super T> action)
    {
        return wrap(super.thenAccept(action));
    }

    @Override
    public CompletableFuture<Void> thenAcceptAsync(Consumer<? super T> action)
    {
        return wrap(super.thenAcceptAsync(action));
    }

    @Override
    public CompletableFuture<Void> thenAcceptAsync(Consumer<? super T> action, Executor executor)
    {
        return wrap(super.thenAcceptAsync(action, executor));
    }

    @Override
    public CompletableFuture<Void> thenRun(Runnable action)
    {
        return wrap(super.thenRun(action));
    }

    @Override
    public CompletableFuture<Void> thenRunAsync(Runnable action)
    {
        return wrap(super.thenRunAsync(action));
    }

    @Override
    public CompletableFuture<Void> thenRunAsync(Runnable action, Executor executor)
    {
        return wrap(super.thenRunAsync(action, executor));
    }

    @Override
    public <U, V> CompletableFuture<V> thenCombine(CompletionStage<? extends U> other,
                                                   BiFunction<? super T, ? super U, ? extends V> fn)
    {
        return wrap(super.thenCombine(other, fn));
    }

    @Override
    public <U, V> CompletableFuture<V> thenCombineAsync(CompletionStage<? extends U> other,
                                                        BiFunction<? super T, ? super U, ? extends V> fn)
    {
        return wrap(super.thenCombineAsync(other, fn));
    }

    @Override
    public <U, V> CompletableFuture<V> thenCombineAsync(CompletionStage<? extends U> other,
                                                        BiFunction<? super T, ? super U, ? extends V> fn,
                                                        Executor executor)
    {
        return wrap(super.thenCombineAsync(other, fn, executor));
    }

    @Override
    public <U> CompletableFuture<Void> thenAcceptBoth(CompletionStage<? extends U> other,
                                                      BiConsumer<? super T, ? super U> action)
    {
        return wrap(super.thenAcceptBoth(other, action));
    }

    @Override
    public <U> CompletableFuture<Void> thenAcceptBothAsync(CompletionStage<? extends U> other,
                                                           BiConsumer<? super T, ? super U> action)
    {
        return wrap(super.thenAcceptBothAsync(other, action));
    }

    @Override
    public <U> CompletableFuture<Void> thenAcceptBothAsync(CompletionStage<? extends U> other,
                                                           BiConsumer<? super T, ? super U> action,
                                                           Executor executor)
    {
        return wrap(super.thenAcceptBothAsync(other, action, executor));
    }

    @Override
    public CompletableFuture<Void> runAfterBoth(CompletionStage<?> other, Runnable action)
    {
        return wrap(super.runAfterBoth(other, action));
    }

    @Override
    public CompletableFuture<Void> runAfterBothAsync(CompletionStage<?> other, Runnable action)
    {
        return wrap(super.runAfterBothAsync(other, action));
    }

    @Override
    public CompletableFuture<Void> runAfterBothAsync(CompletionStage<?> other, Runnable action, Executor executor)
    {
        return wrap(super.runAfterBothAsync(other, action, executor));
    }

    @Override
    public <U> CompletableFuture<U> applyToEither(CompletionStage<? extends T> other, Function<? super T, U> fn)
    {
        return wrap(super.applyToEither(other, fn));
    }

    @Override
    public <U> CompletableFuture<U> applyToEitherAsync(CompletionStage<? extends T> other, Function<? super T, U> fn)
    {
        return wrap(super.applyToEitherAsync(other, fn));
    }

    @Override
    public <U> CompletableFuture<U> applyToEitherAsync(CompletionStage<? extends T> other, Function<? super T, U> fn,
                                                       Executor executor)
    {
        return wrap(super.applyToEitherAsync(other, fn, executor));
    }

    @Override
    public CompletableFuture<Void> acceptEither(CompletionStage<? extends T> other, Consumer<? super T> action)
    {
        return wrap(super.acceptEither(other, action));
    }

    @Override
    public CompletableFuture<Void> acceptEitherAsync(CompletionStage<? extends T> other, Consumer<? super T> action)
    {
        return wrap(super.acceptEitherAsync(other, action));
    }

    @Override
    public CompletableFuture<Void> acceptEitherAsync(CompletionStage<? extends T> other, Consumer<? super T> action,
                                                     Executor executor)
    {
        return wrap(super.acceptEitherAsync(other, action, executor));
    }

    @Override
    public CompletableFuture<Void> runAfterEither(CompletionStage<?> other, Runnable action)
    {
        return wrap(super.runAfterEither(other, action));
    }

    @Override
    public CompletableFuture<Void> runAfterEitherAsync(CompletionStage<?> other, Runnable action)
    {
        return wrap(super.runAfterEitherAsync(other, action));
    }

    @Override
    public CompletableFuture<Void> runAfterEitherAsync(CompletionStage<?> other, Runnable action, Executor executor)
    {
        return wrap(super.runAfterEitherAsync(other, action, executor));
    }

    @Override
    public <U> CompletableFuture<U> thenCompose(Function<? super T, ? extends CompletionStage<U>> fn)
    {
        return wrap(super.thenCompose(fn));
    }

    @Override
    public <U> CompletableFuture<U> thenComposeAsync(Function<? super T, ? extends CompletionStage<U>> fn)
    {
        return wrap(super.thenComposeAsync(fn));
    }

    @Override
    public <U> CompletableFuture<U> thenComposeAsync(Function<? super T, ? extends CompletionStage<U>> fn,
                                                     Executor executor)
    {
        return wrap(super.thenComposeAsync(fn, executor));
    }

    @Override
    public CompletableFuture<T> exceptionally(Function<Throwable, ? extends T> fn)
    {
        return wrap(super.exceptionally(fn));
    }

    @Override
    public CompletableFuture<T> whenComplete(BiConsumer<? super T, ? super Throwable> action)
    {
        return wrap(super.whenComplete(action));
    }

    @Override
    public CompletableFuture<T> whenCompleteAsync(BiConsumer<? super T, ? super Throwable> action)
    {
        return wrap(super.whenCompleteAsync(action));
    }

    @Override
    public CompletableFuture<T> whenCompleteAsync(BiConsumer<? super T, ? super Throwable> action,
                                                  Executor executor)
    {
        return wrap(super.whenCompleteAsync(action, executor));
    }

    @Override
    public <U> CompletableFuture<U> handle(BiFunction<? super T, Throwable, ? extends U> fn)
    {
        return wrap(super.handle(fn));
    }

    @Override
    public <U> CompletableFuture<U> handleAsync(BiFunction<? super T, Throwable, ? extends U> fn)
    {
        return wrap(super.handleAsync(fn));
    }

    @Override
    public <U> CompletableFuture<U> handleAsync(BiFunction<? super T, Throwable, ? extends U> fn,
                                                Executor executor)
    {
        return wrap(super.handleAsync(fn, executor));
    }

    @Override
    public boolean complete(T value)
    {
        return delegate.complete(value);
    }

    @Override
    public boolean completeExceptionally(Throwable ex)
    {
        return delegate.completeExceptionally(ex);
    }
}

RunMode.java:

/**
 * Operational modes.
 */
public enum RunMode
{
    /**
     * Optimized for debugging problems (extra runtime checks, logging of the program state).
     */
    DEBUG,
    /**
     * Optimized for maximum performance.
     */
    RELEASE
}

AsynchronousException.java

/**
 * Thrown when an asynchronous operation fails. The stacktrace indicates who triggered the operation.
 */
public final class AsynchronousException extends RuntimeException
{
    private static final long serialVersionUID = 0L;

    public AsynchronousException()
    {
    }
}

使用方法:

DebugCompletableFuture.wrap(CompletableFuture.supplyAsync(this::expensiveOperation));

优点:您将获得相对干净的异步堆栈跟踪。
缺点:每次创建未来时构建新的AsynchronousException非常昂贵。特别是,如果您正在生成大量未来,这会在堆上生成大量垃圾,并且GC开销变得明显。
我仍然希望有人提出更好的执行方法。

1
在类似的情况下,我使用 addSuppressed() 存储上下文信息,这样您的原始异常就会被保留,但在堆栈跟踪中会看到一个 Suppressed:。这避免了在代码中处理 AsynchrounousException 的必要。理想情况下,您应该在执行器中实现它,这样您就不必到处放置它。顺便说一句,使用此解决方案,JVM 是否会很快省略掉 您的 AsynchronousException 堆栈跟踪? - Didier L
@DidierL 看来我每天都会学到新东西 :) 直到今天我才听说JVM可以优化掉堆栈跟踪。谢谢你的分享。我也喜欢你将这段代码移入ExecutorService.submit()的想法。一旦有机会,我会更新这个答案并采用这种方法。 - Gili
1
@DidierL,事实证明按照您的建议在执行器中实现这一点是不可能的。CompletableFuture调用Executor.execute(Runnable)并捕获其提供的Runnable内部的所有异常。执行器从未看到任何异常,因此无法添加所需的上下文。 - Gili
啊,是的,我想那很有道理...... CompletableFuture API似乎还有改进的空间... - Didier L
好主意--这正是我希望不必要的,但你做了找出答案的工作,很好! - Bill Burdick

0

这可能是由于JVM更新,当它发现堆栈已经耗尽并且正在发出相同的日志时,它开始省略它。

解决方案是使用-XX:-OmitStackTraceInFastThrow标志,以防止JVM优化内置异常堆栈跟踪。


不错的尝试,但是不行。这个问题与一遍又一遍地抛出相同的异常无关。它会发生在您启动的任何异步任务中。 - Gili

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接