Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Reactor Netty Hangs on Response 304 #465

Closed
ahmedyarub opened this issue Oct 16, 2018 · 3 comments
Closed

Reactor Netty Hangs on Response 304 #465

ahmedyarub opened this issue Oct 16, 2018 · 3 comments
Labels
type/bug A general bug
Milestone
0.7.11.RELEASE

Comments

@ahmedyarub
Copy link

ahmedyarub commented Oct 16, 2018 •
edited
Loading

I have a Spring Cloud Gateway based API Gateway which points to a back-end service implemented in an older version of Spring Boot (blocking). When I send a PUT request that would return a status 204 response, it works both when sending the request directly to the back-end and to the API Gateway as expected. However, when I send a PUT request that would return a 304, it would work normally on the back-end but on the API Gateway it would give me a partial result and time-out after hanging.
Here is the result for the 204 responses:

D:\>http --form PUT http://localhost:8093/services/np/v1/topup/service/102/transaction/123451/authorize x-api-key:RRRRRRRR-BBBB-1111-2222-CCCCCCCCCCCC msisdn=21912345678 amount=100
HTTP/1.1 204 No Content
Cache-Control: no-cache, no-store, max-age=0, must-revalidate
Date: Tue, 16 Oct 2018 00:11:18 GMT
Expires: 0
Pragma: no-cache
Server: Apache-Coyote/1.1
X-Application-Context: pltrec-tgv:dev:8093
X-Content-Type-Options: nosniff
X-Frame-Options: DENY
X-XSS-Protection: 1; mode=block

And the ones for 304:

D:\>http --form PUT http://localhost:8093/services/np/v1/topup/service/102/transaction/123451/authorize x-api-key:RRRRRRRR-BBBB-1111-2222-CCCCCCCCCCCC msisdn=21912345678 amount=100
HTTP/1.1 304 Not Modified
Cache-Control: no-cache, no-store, max-age=0, must-revalidate
Date: Tue, 16 Oct 2018 00:11:31 GMT
Expires: 0
Pragma: no-cache
Server: Apache-Coyote/1.1
X-Application-Context: pltrec-tgv:dev:8093
X-Content-Type-Options: nosniff
X-Frame-Options: DENY
X-XSS-Protection: 1; mode=block
transfer-encoding: chunked

The trace log for both Spring Cloud Gateway and Reactor-Netty looks like this

2018-10-15 21:26:20.192 DEBUG 33892 --- [ctor-http-nio-3] .b.a.e.w.r.WebFluxEndpointHandlerMapping : Looking up handler method for path /services/np/v1/topup/service/102/transaction/123452/authorize
2018-10-15 21:26:20.193 DEBUG 33892 --- [ctor-http-nio-3] .b.a.e.w.r.WebFluxEndpointHandlerMapping : Did not find handler method for [/services/np/v1/topup/service/102/transaction/123452/authorize]
2018-10-15 21:26:20.193 DEBUG 33892 --- [ctor-http-nio-3] a.e.w.r.ControllerEndpointHandlerMapping : Looking up handler method for path /services/np/v1/topup/service/102/transaction/123452/authorize
2018-10-15 21:26:20.193 DEBUG 33892 --- [ctor-http-nio-3] a.e.w.r.ControllerEndpointHandlerMapping : Did not find handler method for [/services/np/v1/topup/service/102/transaction/123452/authorize]
2018-10-15 21:26:20.193 TRACE 33892 --- [ctor-http-nio-3] o.s.c.g.h.p.RoutePredicateFactory        : Pattern "/services/np/v1/topup/service/{service_id}/**" matches against value "[path='/services/np/v1/topup/service/102/transaction/123452/authorize']"
2018-10-15 21:26:20.193 DEBUG 33892 --- [ctor-http-nio-3] o.s.c.g.h.RoutePredicateHandlerMapping   : Route matched: recarga
2018-10-15 21:26:20.193 DEBUG 33892 --- [ctor-http-nio-3] o.s.c.g.h.RoutePredicateHandlerMapping   : Mapping [Exchange: PUT http://localhost:8097/services/np/v1/topup/service/102/transaction/123452/authorize] to Route{id='recarga', uri=lb://SAMPLELOADTARGET, order=0, predicate=org.springframework.cloud.gateway.support.ServerWebExchangeUtils$$Lambda$748/1179054411@6edb5e04, gatewayFilters=[OrderedGatewayFilter{delegate=org.springframework.cloud.gateway.filter.factory.RequestRateLimiterGatewayFilterFactory$$Lambda$751/1401442652@74cac071, order=2}, OrderedGatewayFilter{delegate=org.springframework.cloud.gateway.filter.factory.AbstractChangeRequestUriGatewayFilterFactory$$Lambda$750/1211767358@49802e5d, order=10001}]}
2018-10-15 21:26:20.195 DEBUG 33892 --- [ctor-http-nio-3] o.s.c.g.handler.FilteringWebHandler      : Sorted gatewayFilterFactories: [OrderedGatewayFilter{delegate=GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.AdaptCachedBodyGlobalFilter@7aaad0}, order=-2147482648}, OrderedGatewayFilter{delegate=GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.NettyWriteResponseFilter@5b8572df}, order=-1}, OrderedGatewayFilter{delegate=GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.ForwardPathFilter@6097fca9}, order=0}, OrderedGatewayFilter{delegate=GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.GatewayMetricsFilter@5729b410}, order=0}, OrderedGatewayFilter{delegate=org.springframework.cloud.gateway.filter.factory.RequestRateLimiterGatewayFilterFactory$$Lambda$751/1401442652@74cac071, order=2}, OrderedGatewayFilter{delegate=GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.RouteToRequestUrlFilter@eed890d}, order=10000}, OrderedGatewayFilter{delegate=org.springframework.cloud.gateway.filter.factory.AbstractChangeRequestUriGatewayFilterFactory$$Lambda$750/1211767358@49802e5d, order=10001}, OrderedGatewayFilter{delegate=GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.LoadBalancerClientFilter@794eeaf8}, order=10100}, OrderedGatewayFilter{delegate=GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.WebsocketRoutingFilter@35eee641}, order=2147483646}, OrderedGatewayFilter{delegate=GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.NettyRoutingFilter@37c5284a}, order=2147483647}, OrderedGatewayFilter{delegate=GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.ForwardRoutingFilter@10f477e2}, order=2147483647}]
2018-10-15 21:26:20.197 TRACE 33892 --- [ioEventLoop-4-1] o.s.c.g.filter.RouteToRequestUrlFilter   : RouteToRequestUrlFilter start
2018-10-15 21:26:20.214 TRACE 33892 --- [ctor-http-nio-1] o.s.c.g.filter.NettyWriteResponseFilter  : NettyWriteResponseFilter start
2018-10-15 21:26:20.216 DEBUG 33892 --- [ctor-http-nio-3] o.s.h.s.r.ReactorHttpHandlerAdapter      : Handling completed with success

A trace log for the whole application is too big to be attached to this message, but the most important part is this at the end:

2018-10-15 21:28:33.169 DEBUG 10468 --- [ctor-http-nio-2] r.ipc.netty.http.server.HttpServer       : [id: 0x6a3c9772, L:/127.0.0.1:8097 - R:/127.0.0.1:27541] WRITE: 329B
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 48 54 54 50 2f 31 2e 31 20 33 30 34 20 4e 6f 74 |HTTP/1.1 304 Not|
|00000010| 20 4d 6f 64 69 66 69 65 64 0d 0a 74 72 61 6e 73 | Modified..trans|
|00000020| 66 65 72 2d 65 6e 63 6f 64 69 6e 67 3a 20 63 68 |fer-encoding: ch|
|00000030| 75 6e 6b 65 64 0d 0a 58 2d 52 61 74 65 4c 69 6d |unked..X-RateLim|
|00000040| 69 74 2d 52 65 6d 61 69 6e 69 6e 67 3a 20 31 0d |it-Remaining: 1.|
|00000050| 0a 53 65 72 76 65 72 3a 20 41 70 61 63 68 65 2d |.Server: Apache-|
|00000060| 43 6f 79 6f 74 65 2f 31 2e 31 0d 0a 43 61 63 68 |Coyote/1.1..Cach|
|00000070| 65 2d 43 6f 6e 74 72 6f 6c 3a 20 6e 6f 2d 63 61 |e-Control: no-ca|
|00000080| 63 68 65 2c 20 6e 6f 2d 73 74 6f 72 65 2c 20 6d |che, no-store, m|
|00000090| 61 78 2d 61 67 65 3d 30 2c 20 6d 75 73 74 2d 72 |ax-age=0, must-r|
|000000a0| 65 76 61 6c 69 64 61 74 65 0d 0a 50 72 61 67 6d |evalidate..Pragm|
|000000b0| 61 3a 20 6e 6f 2d 63 61 63 68 65 0d 0a 45 78 70 |a: no-cache..Exp|
|000000c0| 69 72 65 73 3a 20 30 0d 0a 58 2d 58 53 53 2d 50 |ires: 0..X-XSS-P|
|000000d0| 72 6f 74 65 63 74 69 6f 6e 3a 20 31 3b 20 6d 6f |rotection: 1; mo|
|000000e0| 64 65 3d 62 6c 6f 63 6b 0d 0a 58 2d 46 72 61 6d |de=block..X-Fram|
|000000f0| 65 2d 4f 70 74 69 6f 6e 73 3a 20 44 45 4e 59 0d |e-Options: DENY.|
|00000100| 0a 58 2d 43 6f 6e 74 65 6e 74 2d 54 79 70 65 2d |.X-Content-Type-|
|00000110| 4f 70 74 69 6f 6e 73 3a 20 6e 6f 73 6e 69 66 66 |Options: nosniff|
|00000120| 0d 0a 44 61 74 65 3a 20 54 75 65 2c 20 31 36 20 |..Date: Tue, 16 |
|00000130| 4f 63 74 20 32 30 31 38 20 30 30 3a 32 38 3a 33 |Oct 2018 00:28:3|
|00000140| 33 20 47 4d 54 0d 0a 0d 0a                      |3 GMT....       |
+--------+-------------------------------------------------+----------------+
2018-10-15 21:28:33.169 DEBUG 10468 --- [ctor-http-nio-2] r.ipc.netty.http.server.HttpServer       : [id: 0x6a3c9772, L:/127.0.0.1:8097 - R:/127.0.0.1:27541] FLUSH
2018-10-15 21:28:33.170 DEBUG 10468 --- [ctor-http-nio-2] r.i.n.channel.ChannelOperationsHandler   : [id: 0x6a3c9772, L:/127.0.0.1:8097 - R:/127.0.0.1:27541] Writing object 
2018-10-15 21:28:33.171 DEBUG 10468 --- [ctor-http-nio-2] o.s.h.s.r.ReactorHttpHandlerAdapter      : Handling completed with success
2018-10-15 21:28:33.171 DEBUG 10468 --- [ctor-http-nio-2] r.i.n.http.server.HttpServerOperations   : Last HTTP response frame
2018-10-15 21:28:33.171 DEBUG 10468 --- [ctor-http-nio-2] r.i.n.channel.ChannelOperationsHandler   : [id: 0x6a3c9772, L:/127.0.0.1:8097 - R:/127.0.0.1:27541] Writing object EmptyLastHttpContent
2018-10-15 21:28:33.171 DEBUG 10468 --- [ctor-http-nio-2] r.ipc.netty.http.server.HttpServer       : [id: 0x6a3c9772, L:/127.0.0.1:8097 - R:/127.0.0.1:27541] WRITE: 0B
2018-10-15 21:28:33.171 DEBUG 10468 --- [ctor-http-nio-2] r.i.n.http.server.HttpServerOperations   : Decreasing pending responses, now 0
2018-10-15 21:28:33.171 DEBUG 10468 --- [ctor-http-nio-2] r.ipc.netty.http.server.HttpServer       : [id: 0x6a3c9772, L:/127.0.0.1:8097 - R:/127.0.0.1:27541] FLUSH
2018-10-15 21:28:33.172 TRACE 10468 --- [ctor-http-nio-2] r.ipc.netty.channel.ChannelOperations    : [id: 0x6a3c9772, L:/127.0.0.1:8097 - R:/127.0.0.1:27541] Disposing ChannelOperation from a channel

java.lang.Exception: ChannelOperation terminal stack
	at reactor.ipc.netty.channel.ChannelOperations.onHandlerTerminate(ChannelOperations.java:394)
	at reactor.ipc.netty.http.server.HttpServerOperations.cleanHandlerTerminate(HttpServerOperations.java:471)
	at reactor.ipc.netty.http.server.HttpServerHandler$TerminateHttpHandler.operationComplete(HttpServerHandler.java:331)
	at reactor.ipc.netty.http.server.HttpServerHandler$TerminateHttpHandler.operationComplete(HttpServerHandler.java:321)
	at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:511)
	at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:485)
	at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:424)
	at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:103)
	at io.netty.util.internal.PromiseNotificationUtil.trySuccess(PromiseNotificationUtil.java:48)
	at io.netty.channel.ChannelOutboundBuffer.safeSuccess(ChannelOutboundBuffer.java:696)
	at io.netty.channel.ChannelOutboundBuffer.remove(ChannelOutboundBuffer.java:258)
	at io.netty.channel.nio.AbstractNioByteChannel.doWriteInternal(AbstractNioByteChannel.java:216)
	at io.netty.channel.nio.AbstractNioByteChannel.doWrite0(AbstractNioByteChannel.java:209)
	at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:395)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:934)
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0(AbstractNioChannel.java:360)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:901)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1396)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
	at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
	at io.netty.handler.logging.LoggingHandler.flush(LoggingHandler.java:265)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
	at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.flush(CombinedChannelDuplexHandler.java:533)
	at io.netty.channel.ChannelOutboundHandlerAdapter.flush(ChannelOutboundHandlerAdapter.java:115)
	at io.netty.channel.CombinedChannelDuplexHandler.flush(CombinedChannelDuplexHandler.java:358)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
	at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
	at io.netty.channel.ChannelDuplexHandler.flush(ChannelDuplexHandler.java:117)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
	at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
	at reactor.ipc.netty.channel.ChannelOperationsHandler.doWrite(ChannelOperationsHandler.java:295)
	at reactor.ipc.netty.channel.ChannelOperationsHandler.drain(ChannelOperationsHandler.java:464)
	at reactor.ipc.netty.channel.ChannelOperationsHandler.flush(ChannelOperationsHandler.java:192)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
	at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:802)
	at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:814)
	at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:794)
	at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:831)
	at io.netty.channel.DefaultChannelPipeline.writeAndFlush(DefaultChannelPipeline.java:1071)
	at io.netty.channel.AbstractChannel.writeAndFlush(AbstractChannel.java:300)
	at reactor.ipc.netty.http.server.HttpServerOperations.onOutboundComplete(HttpServerOperations.java:449)
	at reactor.ipc.netty.channel.ChannelOperations.onComplete(ChannelOperations.java:219)
	at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onComplete(MonoPeekTerminal.java:318)
	at reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber.onComplete(FluxPeekFuseable.java:555)
	at reactor.core.publisher.Operators$MonoSubscriber.onComplete(Operators.java:1121)
	at reactor.core.publisher.MonoIgnoreThen$ThenAcceptInner.onComplete(MonoIgnoreThen.java:313)
	at reactor.core.publisher.Operators.complete(Operators.java:128)
	at reactor.core.publisher.MonoEmpty.subscribe(MonoEmpty.java:45)
	at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:53)
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.drain(MonoIgnoreThen.java:153)
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.ignoreDone(MonoIgnoreThen.java:190)
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreInner.onComplete(MonoIgnoreThen.java:239)
	at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:1318)
	at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:1318)
	at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:1318)
	at reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber.onComplete(FluxPeekFuseable.java:265)
	at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onComplete(MonoPeekTerminal.java:318)
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:189)
	at reactor.core.publisher.MonoFlatMap$FlatMapInner.onComplete(MonoFlatMap.java:260)
	at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onComplete(MonoPeekTerminal.java:318)
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.onComplete(MonoFlatMap.java:174)
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:189)
	at reactor.core.publisher.MonoFlatMap$FlatMapInner.onComplete(MonoFlatMap.java:260)
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.drain(MonoIgnoreThen.java:144)
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.ignoreDone(MonoIgnoreThen.java:190)
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreInner.onComplete(MonoIgnoreThen.java:239)
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:189)
	at reactor.core.publisher.MonoFlatMap$FlatMapInner.onComplete(MonoFlatMap.java:260)
	at reactor.core.publisher.FluxContextStart$ContextStartSubscriber.onComplete(FluxContextStart.java:122)
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:189)
	at reactor.core.publisher.MonoFlatMap$FlatMapInner.onComplete(MonoFlatMap.java:260)
	at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:1318)
	at reactor.core.publisher.FluxContextStart$ContextStartSubscriber.onComplete(FluxContextStart.java:122)
	at reactor.core.publisher.Operators$MonoSubscriber.onComplete(Operators.java:1121)
	at reactor.core.publisher.MonoIgnoreThen$ThenAcceptInner.onComplete(MonoIgnoreThen.java:313)
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:189)
	at reactor.core.publisher.MonoFlatMap$FlatMapInner.onComplete(MonoFlatMap.java:260)
	at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:1318)
	at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onComplete(FluxSwitchIfEmpty.java:78)
	at reactor.core.publisher.Operators$MonoSubscriber.onComplete(Operators.java:1121)
	at reactor.core.publisher.MonoIgnoreThen$ThenAcceptInner.onComplete(MonoIgnoreThen.java:313)
	at org.springframework.http.server.reactive.ChannelSendOperator$WriteCompletionBarrier.onComplete(ChannelSendOperator.java:373)
	at reactor.core.publisher.MonoIgnoreElements$IgnoreElementsSubscriber.onComplete(MonoIgnoreElements.java:80)
	at reactor.core.publisher.FluxConcatIterable$ConcatIterableSubscriber.onComplete(FluxConcatIterable.java:121)
	at reactor.core.publisher.FluxConcatIterable.subscribe(FluxConcatIterable.java:61)
	at reactor.core.publisher.MonoIgnoreElements.subscribe(MonoIgnoreElements.java:37)
	at reactor.core.publisher.Mono.subscribe(Mono.java:3080)
	at org.springframework.http.server.reactive.ChannelSendOperator$WriteBarrier.onComplete(ChannelSendOperator.java:230)
	at reactor.core.publisher.FluxMap$MapSubscriber.onComplete(FluxMap.java:130)
	at reactor.core.publisher.FluxPeek$PeekSubscriber.onComplete(FluxPeek.java:245)
	at reactor.core.publisher.FluxMap$MapSubscriber.onComplete(FluxMap.java:130)
	at reactor.ipc.netty.channel.FluxReceive.terminateReceiver(FluxReceive.java:377)
	at reactor.ipc.netty.channel.FluxReceive.drainReceiver(FluxReceive.java:202)
	at reactor.ipc.netty.channel.FluxReceive.onInboundComplete(FluxReceive.java:342)
	at reactor.ipc.netty.channel.ChannelOperations.onInboundComplete(ChannelOperations.java:336)
	at reactor.ipc.netty.channel.ChannelOperations.onHandlerTerminate(ChannelOperations.java:403)
	at reactor.ipc.netty.http.client.HttpClientOperations.onInboundNext(HttpClientOperations.java:605)
	at reactor.ipc.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:136)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:438)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:284)
	at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:253)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.handler.logging.LoggingHandler.channelRead(LoggingHandler.java:241)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:647)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:582)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:499)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:461)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)
	at java.lang.Thread.run(Thread.java:748)

2018-10-15 21:28:33.173 DEBUG 10468 --- [ctor-http-nio-2] r.ipc.netty.http.server.HttpServer       : [id: 0x6a3c9772, L:/127.0.0.1:8097 - R:/127.0.0.1:27541] USER_EVENT: [Handler Terminated]

I'm on Windows 10, using Finchley.SR1 and spring-boot-starter-parent 2.0.5.RELEASE.

Any help would be appreciated
@violetagg
Copy link
Member

Hi,

According to the specification there is:

https://tools.ietf.org/html/rfc7230#section-3.3
All 1xx (Informational), 204 (No Content), and 304 (Not Modified)
responses do not include a message body.

https://tools.ietf.org/html/rfc7230#section-3.3.1
Transfer-Encoding MAY be sent in a response to a HEAD request or in a
304 (Not Modified) response (Section 4.1 of [RFC7232]) to a GET
request, neither of which includes a message body, to indicate that
the origin server would have applied a transfer coding to the message
body if the request had been an unconditional GET.

https://tools.ietf.org/html/rfc7230#section-3.3.3
Any response to a HEAD request and any response with a 1xx
(Informational), 204 (No Content), or 304 (Not Modified) status
code is always terminated by the first empty line after the
header fields, regardless of the header fields present in the
message, and thus cannot contain a message body.

https://tools.ietf.org/html/rfc7232#section-4.1
The 304 (Not Modified) status code indicates that a conditional GET
or HEAD request has been received and would have resulted in a 200
(OK) response if it were not for the fact that the condition
evaluated to false.

I was able to reproduce the scenario, here is what happens:

The request to the origin is successful and in the log files I can see the Reactor Netty Http Client receives the response below (Netty silently removes Transfer-Encoding and processes the response (section-3.3.3)):

2018-10-16 11:08:24.139 DEBUG 79095 --- [ctor-http-nio-7] r.ipc.netty.http.client.HttpClient       : [id: 0xc5fa56fb, L:/127.0.0.1:52645 - R:localhost/127.0.0.1:8060] READ: 54B
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 48 54 54 50 2f 31 2e 31 20 33 30 34 20 0d 0a 44 |HTTP/1.1 304 ..D|
|00000010| 61 74 65 3a 20 54 75 65 2c 20 31 36 20 4f 63 74 |ate: Tue, 16 Oct|
|00000020| 20 32 30 31 38 20 30 38 3a 30 38 3a 32 34 20 47 | 2018 08:08:24 G|
|00000030| 4d 54 0d 0a 0d 0a                               |MT....          |
+--------+-------------------------------------------------+----------------+

Then the Reactor Netty Http Server sends the response below (with Transfer-Encoding: chunked added as it is not forbidden (section-3.3.1)):

2018-10-16 11:08:27.031 DEBUG 79095 --- [ctor-http-nio-6] r.ipc.netty.http.server.HttpServer       : [id: 0xff743020, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:52640] WRITE: 94B
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 48 54 54 50 2f 31 2e 31 20 33 30 34 20 4e 6f 74 |HTTP/1.1 304 Not|
|00000010| 20 4d 6f 64 69 66 69 65 64 0d 0a 74 72 61 6e 73 | Modified..trans|
|00000020| 66 65 72 2d 65 6e 63 6f 64 69 6e 67 3a 20 63 68 |fer-encoding: ch|
|00000030| 75 6e 6b 65 64 0d 0a 44 61 74 65 3a 20 54 75 65 |unked..Date: Tue|
|00000040| 2c 20 31 36 20 4f 63 74 20 32 30 31 38 20 30 38 |, 16 Oct 2018 08|
|00000050| 3a 30 38 3a 32 34 20 47 4d 54 0d 0a 0d 0a       |:08:24 GMT....  |
+--------+-------------------------------------------------+----------------+

@smaldini @rstoyanchev @spencergibb Should we silently remove Transfer-Encoding also on the server. It is not the default for Netty and also per specification it is not MUST. Also what about Spring Gateway not to add Transfer-Encoding to the response when there wasn't such received from the origin.

@fifothekid 304 response code is for GET/HEAD requests (section-4.1), for PUT more appropriate is 204.

Regards,
Violeta

@violetagg violetagg added the status/need-decision This needs team attention and discussion label Oct 16, 2018
@ahmedyarub ahmedyarub mentioned this issue Oct 16, 2018
Closed
@ahmedyarub
Copy link
Author

I've just opened a related issue
spring-cloud/spring-cloud-gateway#603

violetagg added a commit that referenced this issue Oct 16, 2018
@violetagg
fix #465 Return full empty body message when 304 response code
84db86d
@violetagg violetagg added type/bug A general bug and removed status/need-decision This needs team attention and discussion labels Oct 16, 2018
@violetagg violetagg added this to the 0.7.11.RELEASE milestone Oct 16, 2018
@violetagg
Copy link
Member

violetagg commented Oct 17, 2018 •
edited
Loading

Fixed with #467
Transfer-Encoding/Content-Length will be removed from 304 responses
The fix is available in 0.7.11.BUILD-SNAPSHOT

violetagg added a commit that referenced this issue Oct 17, 2018
@violetagg
Ensure no Transfer-Encoding/Content-Length when 304 response code in …
fae7905 
…full empty message

Related to #465
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
type/bug A general bug
Projects
None yet
Milestone
0.7.11.RELEASE
Development

No branches or pull requests
2 participants
@violetagg @ahmedyarub