spring-projects / spring-security

Spring Security
http://spring.io/projects/spring-security
Apache License 2.0
8.71k stars 5.85k forks source link

Webservice returns invalid response containing Empty Headers (":") #15384

Closed david0 closed 4 weeks ago

david0 commented 2 months ago

(Follow up of https://github.com/spring-projects/spring-framework/issues/33164)

Our Webservice that uses WebFlux returns sometimes responses like:

...(more requests on same connection)...

POST /foo HTTP/1.1
accept-encoding: gzip
user-agent: ReactorNetty/1.1.16
host: localhost:8080
transfer-encoding: chunked
Accept: application/x-ndjson

HTTP/1.1 200 
Vary: Origin
Vary: Access-Control-Request-Method
Vary: Access-Control-Request-Headers
X-Content-Type-Options: nosniff
: 
X-XSS-Protection: 0
Cache-Control: no-cache, no-store, max-age=0, must-revalidate
Pragma: no-cache
Expires: 0
X-Frame-Options: DENY
Content-Type: application/x-ndjson
Transfer-Encoding: chunked
Date: Mon, 08 Jul 2024 13:28:24 GMT

{"i":0}

As you can see, there is an invalid header :.

The WebClient call (Netty) fails with:

IllegalArgumentException: empty headers are not allowed [] ``` 15:54:26.079 [reactor-http-nio-1] WARN reactor.netty.http.client.HttpClientConnect -- [dd6be3b4-31, L:/127.0.0.1:49185 - R:localhost/127.0.0.1:8080] The connection observed an error java.lang.IllegalArgumentException: empty headers are not allowed [] at io.netty.handler.codec.http.DefaultHttpHeadersFactory$1.validateName(DefaultHttpHeadersFactory.java:34) at io.netty.handler.codec.http.DefaultHttpHeadersFactory$1.validateName(DefaultHttpHeadersFactory.java:30) at io.netty.handler.codec.DefaultHeaders.validateName(DefaultHeaders.java:1012) at io.netty.handler.codec.DefaultHeaders.add(DefaultHeaders.java:329) at io.netty.handler.codec.DefaultHeaders.addObject(DefaultHeaders.java:364) at io.netty.handler.codec.http.DefaultHttpHeaders.add(DefaultHttpHeaders.java:182) at io.netty.handler.codec.http.HttpObjectDecoder.readHeaders(HttpObjectDecoder.java:743) at io.netty.handler.codec.http.HttpObjectDecoder.decode(HttpObjectDecoder.java:362) at io.netty.handler.codec.http.HttpClientCodec$Decoder.decode(HttpClientCodec.java:320) at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:530) at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:469) at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:290) at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918) at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788) at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724) at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:840) empty headers are not allowed [] org.springframework.web.reactive.function.client.WebClientRequestException: empty headers are not allowed [] at org.springframework.web.reactive.function.client.ExchangeFunctions$DefaultExchangeFunction.lambda$wrapException$9(ExchangeFunctions.java:136) Suppressed: The stacktrace has been enhanced by Reactor, refer to additional information below: Error has been observed at the following site(s): *__checkpoint ⇢ Request to POST http://localhost:8080/foo [DefaultWebClient] Original Stack Trace: at org.springframework.web.reactive.function.client.ExchangeFunctions$DefaultExchangeFunction.lambda$wrapException$9(ExchangeFunctions.java:136) at reactor.core.publisher.MonoErrorSupplied.subscribe(MonoErrorSupplied.java:55) at reactor.core.publisher.Mono.subscribe(Mono.java:4568) at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:103) at reactor.core.publisher.FluxPeek$PeekSubscriber.onError(FluxPeek.java:222) at reactor.core.publisher.FluxPeek$PeekSubscriber.onError(FluxPeek.java:222) at reactor.core.publisher.FluxPeek$PeekSubscriber.onError(FluxPeek.java:222) at reactor.core.publisher.MonoNext$NextSubscriber.onError(MonoNext.java:93) at reactor.core.publisher.MonoFlatMapMany$FlatMapManyMain.onError(MonoFlatMapMany.java:205) at reactor.core.publisher.SerializedSubscriber.onError(SerializedSubscriber.java:124) at reactor.core.publisher.FluxRetryWhen$RetryWhenMainSubscriber.whenError(FluxRetryWhen.java:229) at reactor.core.publisher.FluxRetryWhen$RetryWhenOtherSubscriber.onError(FluxRetryWhen.java:279) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onError(FluxContextWrite.java:121) at reactor.core.publisher.FluxConcatMapNoPrefetch$FluxConcatMapNoPrefetchSubscriber.maybeOnError(FluxConcatMapNoPrefetch.java:327) at reactor.core.publisher.FluxConcatMapNoPrefetch$FluxConcatMapNoPrefetchSubscriber.onNext(FluxConcatMapNoPrefetch.java:212) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107) at reactor.core.publisher.SinkManyEmitterProcessor.drain(SinkManyEmitterProcessor.java:476) at reactor.core.publisher.SinkManyEmitterProcessor$EmitterInner.drainParent(SinkManyEmitterProcessor.java:620) at reactor.core.publisher.FluxPublish$PubSubInner.request(FluxPublish.java:874) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.request(FluxContextWrite.java:136) at reactor.core.publisher.FluxConcatMapNoPrefetch$FluxConcatMapNoPrefetchSubscriber.request(FluxConcatMapNoPrefetch.java:337) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.request(FluxContextWrite.java:136) at reactor.core.publisher.Operators$DeferredSubscription.request(Operators.java:1743) at reactor.core.publisher.FluxRetryWhen$RetryWhenMainSubscriber.onError(FluxRetryWhen.java:196) at reactor.core.publisher.MonoCreate$DefaultMonoSink.error(MonoCreate.java:205) at reactor.netty.http.client.HttpClientConnect$HttpObserver.onUncaughtException(HttpClientConnect.java:403) at reactor.netty.ReactorNetty$CompositeConnectionObserver.onUncaughtException(ReactorNetty.java:708) at reactor.netty.resources.DefaultPooledConnectionProvider$DisposableAcquire.onUncaughtException(DefaultPooledConnectionProvider.java:223) at reactor.netty.resources.DefaultPooledConnectionProvider$PooledConnection.onUncaughtException(DefaultPooledConnectionProvider.java:476) at reactor.netty.channel.FluxReceive.drainReceiver(FluxReceive.java:247) at reactor.netty.channel.FluxReceive.onInboundError(FluxReceive.java:468) at reactor.netty.channel.ChannelOperations.onInboundError(ChannelOperations.java:515) at reactor.netty.http.client.HttpClientOperations.onInboundNext(HttpClientOperations.java:688) at reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:114) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436) at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346) at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318) at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918) at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788) at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724) at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:840) Suppressed: java.lang.Exception: #block terminated with an error at reactor.core.publisher.BlockingSingleSubscriber.blockingGet(BlockingSingleSubscriber.java:104) at reactor.core.publisher.Mono.block(Mono.java:1779) at com.github.david0.streamedheaderproblem.FooControllerTest.test(FooControllerTest.java:24) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at java.base/java.util.ArrayList.forEach(ArrayList.java:1511) at java.base/java.util.ArrayList.forEach(ArrayList.java:1511) Caused by: java.lang.IllegalArgumentException: empty headers are not allowed [] at io.netty.handler.codec.http.DefaultHttpHeadersFactory$1.validateName(DefaultHttpHeadersFactory.java:34) at io.netty.handler.codec.http.DefaultHttpHeadersFactory$1.validateName(DefaultHttpHeadersFactory.java:30) at io.netty.handler.codec.DefaultHeaders.validateName(DefaultHeaders.java:1012) at io.netty.handler.codec.DefaultHeaders.add(DefaultHeaders.java:329) at io.netty.handler.codec.DefaultHeaders.addObject(DefaultHeaders.java:364) at io.netty.handler.codec.http.DefaultHttpHeaders.add(DefaultHttpHeaders.java:182) at io.netty.handler.codec.http.HttpObjectDecoder.readHeaders(HttpObjectDecoder.java:743) at io.netty.handler.codec.http.HttpObjectDecoder.decode(HttpObjectDecoder.java:362) at io.netty.handler.codec.http.HttpClientCodec$Decoder.decode(HttpClientCodec.java:320) at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:530) at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:469) at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:290) at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918) at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788) at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724) at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:840 ```

On server side nothing is logged.

Here you can find an example that reproduces that problem (It will not always fail and sometimes fail with other errors that sound related): https://github.com/david0/mre-spring-empty-header/blob/main/src/test/java/com/github/david0/streamedheaderproblem/FooControllerTest.java

pietro-saccani commented 1 month ago

I also have this issue where only sometimes there's that empty header (and by debugging, I see that previously it's a duplicate X-Content-Type-Options: nosniff header), but for the life of me I can't understand "who" exactly is adding the extra headers after the ones explicitly set by the application in the ResponseEntity.
By the way I have this in a non-reactive web application, when I use a StreamingResponseBody to handle the response body as a stream since it's a file.

batabatelic commented 1 month ago

Hi, I just wanted to share here that I'm also experiencing this issue in a non-reactive web application returning StreamingResponseBody.

The headers that the app returned can be seen in the screenshot: image

The : header is among them. I also noticed that some headers are duplicated (Pragma, Expires). This happens occasionally. I made multiple WebClient (Netty) calls (in a loop) from another spring boot application to reproduce this.

jzheaux commented 1 month ago

Hi, @david0, thanks for your patience while I researched this.

I was able to reproduce it with a simpler scenario that excludes Spring Security, and I've submitted a PR to your project that demonstrates this. Can you confirm that you are able to reproduce without Spring Security?

david0 commented 1 month ago

Hi, @jzheaux, thanks for your effort.

Yes, I can reproduce the problem even with your simplification.
Does that mean that this issue should go back to spring-framework?

jzheaux commented 4 weeks ago

Yes, @david0, since there isn't anything specific that Spring Security is doing to cause this, it would be worth it to update the Spring Framework ticket and go from there.

You may also see what else you can take out of the sample application. For example, perhaps a controller is not necessary and you can write a response directly with a filter and still see the error.

I'm going to close this issue at this point, but I'll continue watching it in case something else related to Spring Security resurfaces.

david0 commented 2 weeks ago

@jzheaux could you please take a look at @bclozel's response on the spring-framework issue and consider reopening this ticket?