成功请求后，Mono 获取 OnCancel 而不是 OnSuccessOrError

Posted 2023-02-27

【中文标题】成功请求后，Mono 获取 OnCancel 而不是 OnSuccessOrError

【英文标题】：Mono gets OnCancel instead of OnSuccessOrError after successful request

【发布时间】：2019-11-08 06:08:45

【问题描述】：

我有一个 SpringBoot Webflux 应用程序，它实现了一个 WebFilter 以在 Publisher 完成后记录成功/错误。 我的Webfilter 类似如下：

public class MyFilter implements WebFilter 

private static final Logger LOG = LoggerFactory.getLogger(MyFilter.class);

@Override
public Mono<Void> filter(ServerWebExchange exchange, WebFilterChain chain) 
    return chain.filter(exchange)
            .doOnCancel(() -> 
                LOG.info("Cancelled");
            )
            .doOnSuccess(aVoid -> 
                LOG.info("Success");
            )
            .doOnSuccessOrError((aVoid, throwable) -> 
                if (throwable == null) 
                    LOG.info("Completed successfully");
                 else 
                    LOG.error("An error occurred", throwable);
                
            );

自 SpringBoot 2.1.5 起，WebFilter 不再按预期工作。我现在没有得到doOnSuccessOrError 事件，而是得到doOnCancel。这仅在使用自 0.8.7 版以来的 Netty 时才会发生。使用 Undertow 时，它按预期工作。

在所有情况下，Web 请求都成功完成，将正确的数据返回给客户端。

请参阅下面的 DEBUG/TRACE 日志：

[reactor-http-nio-3] DEBUG o.s.h.codec.json.Jackson2JsonEncoder - [6bfed744] Encoding ["errors":[]]
[reactor-http-nio-3] DEBUG r.n.http.server.HttpServerOperations - [id: 0x6bfed744, L:/0:0:0:0:0:0:0:1:8071 - R:/0:0:0:0:0:0:0:1:55927] Decreasing pending responses, now 0
[reactor-http-nio-3] DEBUG r.n.http.server.HttpServerOperations - [id: 0x6bfed744, L:/0:0:0:0:0:0:0:1:8071 - R:/0:0:0:0:0:0:0:1:55927] Last HTTP packet was sent, terminating the channel
[reactor-http-nio-3] TRACE r.netty.channel.ChannelOperations - [id: 0x6bfed744, L:/0:0:0:0:0:0:0:1:8071 - R:/0:0:0:0:0:0:0:1:55927] Disposing ChannelOperation from a channel
java.lang.Exception: ChannelOperation terminal stack
    at reactor.netty.channel.ChannelOperations.terminate(ChannelOperations.java:391)
    at reactor.netty.http.server.HttpServerOperations.cleanHandlerTerminate(HttpServerOperations.java:519)
    at reactor.netty.http.server.HttpTrafficHandler.operationComplete(HttpTrafficHandler.java:314)
    at reactor.netty.http.server.HttpTrafficHandler.operationComplete(HttpTrafficHandler.java:54)
    at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:502)
    at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:476)
    at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:415)
    at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:540)
    at io.netty.util.concurrent.DefaultPromise.setSuccess0(DefaultPromise.java:529)
    at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:101)
    at io.netty.util.internal.PromiseNotificationUtil.trySuccess(PromiseNotificationUtil.java:48)
    at io.netty.channel.ChannelOutboundBuffer.safeSuccess(ChannelOutboundBuffer.java:715)
    at io.netty.channel.ChannelOutboundBuffer.remove(ChannelOutboundBuffer.java:270)
    at io.netty.channel.ChannelOutboundBuffer.removeBytes(ChannelOutboundBuffer.java:350)
    at io.netty.channel.socket.nio.NiosocketChannel.doWrite(NioSocketChannel.java:411)
    at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:939)
    at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0(AbstractNioChannel.java:360)
    at io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:906)
    at io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1370)
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:749)
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:741)
    at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:727)
    at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.flush(CombinedChannelDuplexHandler.java:533)
    at io.netty.channel.ChannelOutboundHandlerAdapter.flush(ChannelOutboundHandlerAdapter.java:125)
    at io.netty.channel.CombinedChannelDuplexHandler.flush(CombinedChannelDuplexHandler.java:358)
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:749)
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:741)
    at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:727)
    at io.netty.channel.ChannelDuplexHandler.flush(ChannelDuplexHandler.java:127)
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:749)
    at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:764)
    at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:789)
    at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:757)
    at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:812)
    at io.netty.channel.DefaultChannelPipeline.writeAndFlush(DefaultChannelPipeline.java:1036)
    at io.netty.channel.AbstractChannel.writeAndFlush(AbstractChannel.java:305)
     ...
[reactor-http-nio-3] INFO  c.m.d.MyFilter - Cancelled
[reactor-http-nio-3] DEBUG r.n.channel.ChannelOperationsHandler - [id: 0x6bfed744, L:/0:0:0:0:0:0:0:1:8071 - R:/0:0:0:0:0:0:0:1:55927] No ChannelOperation attached. Dropping: EmptyLastHttpContent

【参考方案1】：

这是 Spring Framework 中的一个已知问题（参见 spring-framework#22952），尤其是 Reactor Netty (reactor-netty#741)。目前没有已知的解决方法。