"Status and headers already sent" ISE exception from Reactor Netty on WebSocket upgrade #24475

Vity01 · 2020-02-04T07:58:17Z

Spring Boot 2.2.4.RELEASE + webflux

From the server log I quite often see this nasty exception. We are mixing Weblux + Websockets

java.lang.IllegalStateException: Status and headers already sent
	at reactor.netty.http.server.HttpServerOperations.addHeader(HttpServerOperations.java:192) ~[reactor-netty-0.9.4.RELEASE.jar:0.9.4.RELEASE]
	at org.springframework.http.server.reactive.ReactorServerHttpResponse.applyCookies(ReactorServerHttpResponse.java:97) ~[spring-web-5.2.3.RELEASE.jar:5.2.3.RELEASE]
	at org.springframework.http.server.reactive.AbstractServerHttpResponse.lambda$doCommit$11(AbstractServerHttpResponse.java:238) ~[spring-web-5.2.3.RELEASE.jar:5.2.3.RELEASE]
	at reactor.core.publisher.MonoRunnable.subscribe(MonoRunnable.java:49) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.Mono.subscribe(Mono.java:4105) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxConcatArray$ConcatArraySubscriber.onComplete(FluxConcatArray.java:207) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxConcatArray.subscribe(FluxConcatArray.java:80) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFromFluxOperator.subscribe(MonoFromFluxOperator.java:72) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:52) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.drain(MonoIgnoreThen.java:153) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.ignoreDone(MonoIgnoreThen.java:190) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreInner.onComplete(MonoIgnoreThen.java:240) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:1871) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onComplete(MonoPeekTerminal.java:292) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:1871) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:1871) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:1871) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:1871) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:395) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:189) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFlatMap$FlatMapInner.onComplete(MonoFlatMap.java:260) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:395) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxContextStart$ContextStartSubscriber.onComplete(FluxContextStart.java:122) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:395) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:395) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxContextStart$ContextStartSubscriber.onComplete(FluxContextStart.java:122) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:395) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.onComplete(MonoFlatMap.java:174) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onComplete(FluxSwitchIfEmpty.java:78) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.drain(MonoIgnoreThen.java:144) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.ignoreDone(MonoIgnoreThen.java:190) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreInner.onComplete(MonoIgnoreThen.java:240) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:395) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:189) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFlatMap$FlatMapInner.onComplete(MonoFlatMap.java:260) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxContextStart$ContextStartSubscriber.onComplete(FluxContextStart.java:122) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:395) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:395) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:189) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFlatMap$FlatMapInner.onComplete(MonoFlatMap.java:260) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:395) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.onComplete(MonoFlatMap.java:174) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.onComplete(MonoFlatMap.java:174) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxMap$MapSubscriber.onComplete(FluxMap.java:136) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onComplete(FluxSwitchIfEmpty.java:78) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.drain(MonoIgnoreThen.java:144) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.ignoreDone(MonoIgnoreThen.java:190) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreInner.onComplete(MonoIgnoreThen.java:240) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:395) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:1871) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:395) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onComplete(FluxSwitchIfEmpty.java:78) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.onComplete(MonoFlatMap.java:174) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:189) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoFlatMap$FlatMapInner.onComplete(MonoFlatMap.java:260) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.drain(MonoIgnoreThen.java:144) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.ignoreDone(MonoIgnoreThen.java:190) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreInner.onComplete(MonoIgnoreThen.java:240) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxHide$SuppressFuseableSubscriber.onComplete(FluxHide.java:137) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.core.publisher.FluxDoOnEach$DoOnEachSubscriber.onComplete(FluxDoOnEach.java:209) ~[reactor-core-3.3.2.RELEASE.jar:3.3.2.RELEASE]
	at reactor.netty.FutureMono$FutureSubscription.operationComplete(FutureMono.java:188) ~[reactor-netty-0.9.4.RELEASE.jar:0.9.4.RELEASE]
	at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:577) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:570) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:549) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:490) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:615) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.DefaultPromise.setSuccess0(DefaultPromise.java:604) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.DefaultPromise.setSuccess(DefaultPromise.java:96) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.DefaultChannelPromise.setSuccess(DefaultChannelPromise.java:78) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.DefaultChannelPromise.setSuccess(DefaultChannelPromise.java:73) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.handler.codec.http.websocketx.WebSocketServerHandshaker$1.operationComplete(WebSocketServerHandshaker.java:227) ~[netty-codec-http-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.handler.codec.http.websocketx.WebSocketServerHandshaker$1.operationComplete(WebSocketServerHandshaker.java:221) ~[netty-codec-http-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:577) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:551) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:490) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:615) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.DefaultPromise.setSuccess0(DefaultPromise.java:604) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:104) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.internal.PromiseNotificationUtil.trySuccess(PromiseNotificationUtil.java:48) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.ChannelOutboundBuffer.safeSuccess(ChannelOutboundBuffer.java:717) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.ChannelOutboundBuffer.remove(ChannelOutboundBuffer.java:272) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.ChannelOutboundBuffer.removeBytes(ChannelOutboundBuffer.java:352) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.epoll.AbstractEpollChannel.doWriteBytes(AbstractEpollChannel.java:363) ~[netty-transport-native-epoll-4.1.45.Final-linux-x86_64.jar:4.1.45.Final]
	at io.netty.channel.epoll.AbstractEpollStreamChannel.writeBytes(AbstractEpollStreamChannel.java:260) ~[netty-transport-native-epoll-4.1.45.Final-linux-x86_64.jar:4.1.45.Final]
	at io.netty.channel.epoll.AbstractEpollStreamChannel.doWriteSingle(AbstractEpollStreamChannel.java:471) ~[netty-transport-native-epoll-4.1.45.Final-linux-x86_64.jar:4.1.45.Final]
	at io.netty.channel.epoll.AbstractEpollStreamChannel.doWrite(AbstractEpollStreamChannel.java:429) ~[netty-transport-native-epoll-4.1.45.Final-linux-x86_64.jar:4.1.45.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:930) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.flush0(AbstractEpollChannel.java:519) ~[netty-transport-native-epoll-4.1.45.Final-linux-x86_64.jar:4.1.45.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:897) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1372) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:748) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:740) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:726) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.flush(CombinedChannelDuplexHandler.java:531) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.ChannelOutboundHandlerAdapter.flush(ChannelOutboundHandlerAdapter.java:125) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.CombinedChannelDuplexHandler.flush(CombinedChannelDuplexHandler.java:356) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:748) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:763) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.AbstractChannelHandlerContext$WriteTask.run(AbstractChannelHandlerContext.java:1089) ~[netty-transport-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384) ~[netty-transport-native-epoll-4.1.45.Final-linux-x86_64.jar:4.1.45.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.45.Final.jar:4.1.45.Final]
	at java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]```

My websocket configuration:

@Configuration
public class ReactiveWebSocketConfiguration {

    private final WebSocketHandler webSocketHandler;

    public ReactiveWebSocketConfiguration(@Qualifier("ReactiveWebSocketHandler") WebSocketHandler webSocketHandler) {
        this.webSocketHandler = webSocketHandler;
    }

    @Bean
    public HandlerMapping webSocketHandlerMapping() {
        Map<String, WebSocketHandler> map = new HashMap<>();
        map.put("/event-emitter", webSocketHandler);

        SimpleUrlHandlerMapping handlerMapping = new SimpleUrlHandlerMapping();
        handlerMapping.setOrder(1);
        handlerMapping.setUrlMap(map);
        return handlerMapping;
    }

    @Bean
    public WebSocketHandlerAdapter handlerAdapter() {
        return new WebSocketHandlerAdapter();
    }
}

@Component("ReactiveWebSocketHandler")
public class ReactiveWebSocketHandler implements WebSocketHandler {

    final DataService dataService;

    public ReactiveWebSocketHandler(DataService dataService) {
        this.dataService = dataService;
    }

    @Override
    public Mono<Void> handle(WebSocketSession webSocketSession) {
        return webSocketSession.send(dataService.getEventFlux()
          .map(webSocketSession::textMessage))
          .and(webSocketSession.receive()
            .map(WebSocketMessage::getPayloadAsText).log());
    }
}

DataService is providing text String.

Browser side:

function connectEvents() {

    function createWebSocket(path) {
        var protocolPrefix = (window.location.protocol === 'https:') ? 'wss:' : 'ws:';
        return new WebSocket(protocolPrefix + '//' + location.host + path);
    }

    var clientWebSocket = createWebSocket(location.pathname + 'event-emitter');

    clientWebSocket.onopen = function () {
        console.log("clientWebSocket.onopen", clientWebSocket);
        console.log("clientWebSocket.readyState", "websocketstatus");
        clientWebSocket.send("event-me-from-browser");
    };
    clientWebSocket.onclose = function (event) {
        console.log("clientWebSocket.onclose", clientWebSocket, event);

        console.log('Socket is closed. Reconnect will be attempted in 10 seconds.', event ? event.reason: '');
        setTimeout(function() {
            console.log('10s websocket reconnecting');
            connectEvents();
        }, 10000);
    };
    clientWebSocket.onerror = function (event) {
        console.log("clientWebSocket.onerror", clientWebSocket, event);
    };
    clientWebSocket.onmessage = function (event) {
        console.log("clientWebSocket.onmessage", clientWebSocket, event);
        processEvents(JSON.parse(event.data));
    };

}

$(function () {
    connectEvents();
});

It's difficult to debug - maybe it's related to cookies somehow(last 2 methods in the exception).
Let me know If I can provide more information.

The text was updated successfully, but these errors were encountered:

bclozel · 2020-02-04T08:19:06Z

Yes, we'll need more information: an application that reproduces the issue would definitely help here, as we can't guess the exact code path/use case triggering this behavior. Are you sure this is happening when requesting the websocket endpoint and not some other endpoint?

Do you have filters or other pieces of infrastructure trying to write to the response?

Starting from a blank app from start.spring.io and adding pieces to it until this is reproducing the problem is I think the best course of action here.

Vity01 · 2020-02-04T09:23:38Z

I forgot to mention we are using Spring Security.
According to the stacktrace it's going through the WebSocketServerHandshaker - so I suppose it has something to do with the websockets.
I was not able to reproduce it locally, I just see the problem from the server logs. App is is deployed on K8S cluster behind proxies...

I know this kind of problem is pretty hard to solve. I wanted to report it and to get some hint.
I will try to disable the security layer.

Eg. this similar one had to do with Chrome requests:
spring-cloud/spring-cloud-gateway#242
Yet another spring-cloud/spring-cloud-gateway#340

It would be nice to have better logging support for these exceptions.

bclozel · 2020-02-04T09:49:37Z

Are you using Spring Cloud Gateway? If not, the issue is only similar in a wway that gateway had a filter that was trying to modify the headers while the response was already committed.

Please let us know if you find additional information.

Vity01 · 2020-02-04T10:17:19Z

No, I am not using Spring Cloud Gateway. I was just googling stacktrace , it might help you to identify the problem as well.

rstoyanchev · 2020-02-04T12:38:44Z

I think we do have an issue. For WebSocket the request is handled through ReactorUpgradeStrategy which calls sendWebsocket which marks headers sent within Reactor Netty. Our own AbstractServerHttpResponse however wasn't involved and so when HttpWebHandlerAdapter calls setComplete on it, it proceeds to apply commit actions. I'm guessing Spring Security attempts to send cookies but at that point it is too late.

The WebFlux response should probably be committed prior the upgrade in order to cause commit actions to take place. A call to setComplete() from HandshakeWebSocketService might be all it takes but will have to try.

Vity01 · 2020-02-04T12:45:33Z

@rstoyanchev Thanks for the analysis. You might be right. I disabled Spring Security for the websocket endpoint and so far I don't see the exception in the log again.

Even thought Tomcat and Jetty, which commit the response more lazily, were not impacted by this issue, it still makes sense for them to complete the WebFlux response (and pre-commit actions) at the same time as for other servers for consistent behavior. See gh-24475

spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged or decided on label Feb 4, 2020

bclozel added the status: waiting-for-feedback We need additional information before we can continue label Feb 4, 2020

spring-projects-issues added status: feedback-provided Feedback has been provided and removed status: waiting-for-feedback We need additional information before we can continue labels Feb 4, 2020

bclozel added status: waiting-for-feedback We need additional information before we can continue and removed status: feedback-provided Feedback has been provided labels Feb 4, 2020

spring-projects-issues added status: feedback-provided Feedback has been provided and removed status: waiting-for-feedback We need additional information before we can continue labels Feb 4, 2020

bclozel added status: waiting-for-feedback We need additional information before we can continue and removed status: feedback-provided Feedback has been provided labels Feb 4, 2020

rstoyanchev added in: web Issues in web modules (web, webmvc, webflux, websocket) type: bug A general bug and removed status: waiting-for-feedback We need additional information before we can continue status: waiting-for-triage An issue we've not yet triaged or decided on labels Feb 4, 2020

rstoyanchev added this to the 5.2.4 milestone Feb 4, 2020

rstoyanchev changed the title ~~"Status and headers already sent" exception when using websockets~~ "Status and headers already sent" ISE exception from Reactor Netty on WebSocket upgrade Feb 4, 2020

bclozel self-assigned this Feb 4, 2020

bclozel closed this as completed in 13f23dc Feb 13, 2020

dependabot bot mentioned this issue Mar 15, 2021

Bump spring-webmvc from 5.2.1.RELEASE to 5.2.4.RELEASE in /!_ServersExpExamples/z_H2_DataBase_Examples/+userManagThym_xmlConfig_andTrash MartyMcAir/-WebApps-Experimental-#48

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

"Status and headers already sent" ISE exception from Reactor Netty on WebSocket upgrade #24475

"Status and headers already sent" ISE exception from Reactor Netty on WebSocket upgrade #24475

Vity01 commented Feb 4, 2020 •

edited by rstoyanchev

bclozel commented Feb 4, 2020

Vity01 commented Feb 4, 2020

bclozel commented Feb 4, 2020

Vity01 commented Feb 4, 2020

rstoyanchev commented Feb 4, 2020

Vity01 commented Feb 4, 2020

"Status and headers already sent" ISE exception from Reactor Netty on WebSocket upgrade #24475

"Status and headers already sent" ISE exception from Reactor Netty on WebSocket upgrade #24475

Comments

Vity01 commented Feb 4, 2020 • edited by rstoyanchev

bclozel commented Feb 4, 2020

Vity01 commented Feb 4, 2020

bclozel commented Feb 4, 2020

Vity01 commented Feb 4, 2020

rstoyanchev commented Feb 4, 2020

Vity01 commented Feb 4, 2020

Vity01 commented Feb 4, 2020 •

edited by rstoyanchev