Upgrade to Pro — share decks privately, control downloads, hide ads and more …

How to Avoid Common Mistakes When Using Reactor...

How to Avoid Common Mistakes When Using Reactor Netty

Violeta Georgieva

September 03, 2020
Tweet

Other Decks in Programming

Transcript

  1. How to Avoid Common Mistakes When Using Reactor Netty September

    2–3, 2020 springone.io session-how-to-avoid-common-mistakes-when-using-reactor-netty 1
  2. Violeta Georgieva • VMware • Reactor Netty committer ◦ Netty

    contributor • Apache Tomcat committer ◦ RM for Tomcat 7 • Spring Framework contributor 2
  3. Agenda • Reactor Netty • Logging • Memory Leaks •

    Timeouts • Connection Closed • Connection Pool 3
  4. Reactor Netty • Reactive Streams API for Netty • Hides

    the complexity of Netty • Supports UDP, TCP and HTTP • Build-in Backpressure support 5
  5. Reactor Netty ❤ Spring • Spring Boot 2.x reactive web

    starter • Spring WebClient • Spring Cloud Gateway 7
  6. 17:51:48.453 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] New

    http connection, requesting read 17:51:48.453 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Initialized pipeline DefaultChannelPipeline... 17:51:48.462 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Increasing pending responses, now 1 17:51:48.462 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Handler is being applied: org.springframe… 17:51:48.463 ... [ctor-http-nio-3] ... [2db101be-2] HTTP GET "/hello/100" 17:51:48.463 ... [ctor-http-nio-3] ... [2db101be-2] Mapped to io.springone.demo.HelloController#hello(long) 17:51:48.464 ... [ctor-http-nio-3] ... [2db101be-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 17:51:48.464 ... [ctor-http-nio-3] ... [2db101be-2] 0..1 [java.lang.String] 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Decreasing pending responses, now 0 17:51:48.578 ... [ctor-http-nio-3] ... [2db101be-2] Completed 200 OK 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Last HTTP response frame 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Last HTTP packet was sent, terminating... 13 Logging
  7. 14 17:51:48.453 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY]

    New http connection, requesting read 17:51:48.453 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Initialized pipeline DefaultChannelPipeline... 17:51:48.462 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Increasing pending responses, now 1 17:51:48.462 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Handler is being applied: org.springframe… 17:51:48.463 ... [ctor-http-nio-3] ... [2db101be-2] HTTP GET "/hello/100" 17:51:48.463 ... [ctor-http-nio-3] ... [2db101be-2] Mapped to io.springone.demo.HelloController#hello(long) 17:51:48.464 ... [ctor-http-nio-3] ... [2db101be-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 17:51:48.464 ... [ctor-http-nio-3] ... [2db101be-2] 0..1 [java.lang.String] 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Decreasing pending responses, now 0 17:51:48.578 ... [ctor-http-nio-3] ... [2db101be-2] Completed 200 OK 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Last HTTP response frame 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Last HTTP packet was sent, terminating... Logging
  8. 15 17:51:48.453 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY]

    New http connection, requesting read 17:51:48.453 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Initialized pipeline DefaultChannelPipeline... 17:51:48.462 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Increasing pending responses, now 1 17:51:48.462 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Handler is being applied: org.springframe… 17:51:48.463 ... [ctor-http-nio-3] ... [2db101be-2] HTTP GET "/hello/100" 17:51:48.463 ... [ctor-http-nio-3] ... [2db101be-2] Mapped to io.springone.demo.HelloController#hello(long) 17:51:48.464 ... [ctor-http-nio-3] ... [2db101be-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 17:51:48.464 ... [ctor-http-nio-3] ... [2db101be-2] 0..1 [java.lang.String] 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Decreasing pending responses, now 0 17:51:48.578 ... [ctor-http-nio-3] ... [2db101be-2] Completed 200 OK 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Last HTTP response frame 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Last HTTP packet was sent, terminating... New connection established Logging
  9. 16 17:51:48.453 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY]

    New http connection, requesting read 17:51:48.453 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Initialized pipeline DefaultChannelPipeline... 17:51:48.462 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Increasing pending responses, now 1 17:51:48.462 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Handler is being applied: org.springframe… 17:51:48.463 ... [ctor-http-nio-3] ... [2db101be-2] HTTP GET "/hello/100" 17:51:48.463 ... [ctor-http-nio-3] ... [2db101be-2] Mapped to io.springone.demo.HelloController#hello(long) 17:51:48.464 ... [ctor-http-nio-3] ... [2db101be-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 17:51:48.464 ... [ctor-http-nio-3] ... [2db101be-2] 0..1 [java.lang.String] 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Decreasing pending responses, now 0 17:51:48.578 ... [ctor-http-nio-3] ... [2db101be-2] Completed 200 OK 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Last HTTP response frame 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Last HTTP packet was sent, terminating... Request received Logging
  10. 17 17:51:48.453 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY]

    New http connection, requesting read 17:51:48.453 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Initialized pipeline DefaultChannelPipeline... 17:51:48.462 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Increasing pending responses, now 1 17:51:48.462 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Handler is being applied: org.springframe… 17:51:48.463 ... [ctor-http-nio-3] ... [2db101be-2] HTTP GET "/hello/100" 17:51:48.463 ... [ctor-http-nio-3] ... [2db101be-2] Mapped to io.springone.demo.HelloController#hello(long) 17:51:48.464 ... [ctor-http-nio-3] ... [2db101be-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 17:51:48.464 ... [ctor-http-nio-3] ... [2db101be-2] 0..1 [java.lang.String] 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Decreasing pending responses, now 0 17:51:48.578 ... [ctor-http-nio-3] ... [2db101be-2] Completed 200 OK 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Last HTTP response frame 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Last HTTP packet was sent, terminating... Response completed Logging
  11. 18 17:51:48.453 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY]

    New http connection, requesting read 17:51:48.453 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Initialized pipeline DefaultChannelPipeline... 17:51:48.462 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Increasing pending responses, now 1 17:51:48.462 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Handler is being applied: org.springframe… 17:51:48.463 ... [ctor-http-nio-3] ... [2db101be-2] HTTP GET "/hello/100" 17:51:48.463 ... [ctor-http-nio-3] ... [2db101be-2] Mapped to io.springone.demo.HelloController#hello(long) 17:51:48.464 ... [ctor-http-nio-3] ... [2db101be-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 17:51:48.464 ... [ctor-http-nio-3] ... [2db101be-2] 0..1 [java.lang.String] 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Decreasing pending responses, now 0 17:51:48.578 ... [ctor-http-nio-3] ... [2db101be-2] Completed 200 OK 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Last HTTP response frame 17:51:48.578 ... [ctor-http-nio-3] ... [id: 0x2db101be, L:/XXX - R:/YYY] Last HTTP packet was sent, terminating… Logging
  12. 20 19:09:01.128 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA]

    New http connection, requesting read 19:09:01.129 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Initialized pipeline DefaultChannelPipeline... 19:09:01.164 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Increasing pending responses, now 1 19:09:01.170 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Handler is being applied: org.springframework.. 19:09:01.181 ... [ctor-http-nio-5] ... [3f368fe3-2] HTTP GET "/hello/100" 19:09:01.199 ... [ctor-http-nio-5] ... [3f368fe3-2] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] 0..1 [java.lang.String] 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] New http connection, requesting read 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" Logging
  13. 21 19:09:01.128 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA]

    New http connection, requesting read 19:09:01.129 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Initialized pipeline DefaultChannelPipeline... 19:09:01.164 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Increasing pending responses, now 1 19:09:01.170 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Handler is being applied: org.springframework.. 19:09:01.181 ... [ctor-http-nio-5] ... [3f368fe3-2] HTTP GET "/hello/100" 19:09:01.199 ... [ctor-http-nio-5] ... [3f368fe3-2] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] 0..1 [java.lang.String] 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] New http connection, requesting read 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" Logging
  14. 22 19:09:01.128 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA]

    New http connection, requesting read 19:09:01.129 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Initialized pipeline DefaultChannelPipeline... 19:09:01.164 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Increasing pending responses, now 1 19:09:01.170 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Handler is being applied: org.springframework.. 19:09:01.181 ... [ctor-http-nio-5] ... [3f368fe3-2] HTTP GET "/hello/100" 19:09:01.199 ... [ctor-http-nio-5] ... [3f368fe3-2] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] 0..1 [java.lang.String] 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] New http connection, requesting read 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" New connection established Logging
  15. 23 19:09:01.128 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA]

    New http connection, requesting read 19:09:01.129 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Initialized pipeline DefaultChannelPipeline... 19:09:01.164 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Increasing pending responses, now 1 19:09:01.170 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Handler is being applied: org.springframework.. 19:09:01.181 ... [ctor-http-nio-5] ... [3f368fe3-2] HTTP GET "/hello/100" 19:09:01.199 ... [ctor-http-nio-5] ... [3f368fe3-2] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] 0..1 [java.lang.String] 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] New http connection, requesting read 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" Request received Logging
  16. 24 19:09:01.128 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA]

    New http connection, requesting read 19:09:01.129 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Initialized pipeline DefaultChannelPipeline... 19:09:01.164 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Increasing pending responses, now 1 19:09:01.170 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Handler is being applied: org.springframework.. 19:09:01.181 ... [ctor-http-nio-5] ... [3f368fe3-2] HTTP GET "/hello/100" 19:09:01.199 ... [ctor-http-nio-5] ... [3f368fe3-2] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] 0..1 [java.lang.String] 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] New http connection, requesting read 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" Another connection established Logging
  17. 25 19:09:01.128 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA]

    New http connection, requesting read 19:09:01.129 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Initialized pipeline DefaultChannelPipeline... 19:09:01.164 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Increasing pending responses, now 1 19:09:01.170 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Handler is being applied: org.springframework.. 19:09:01.181 ... [ctor-http-nio-5] ... [3f368fe3-2] HTTP GET "/hello/100" 19:09:01.199 ... [ctor-http-nio-5] ... [3f368fe3-2] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] 0..1 [java.lang.String] 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] New http connection, requesting read 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" Third connection established Logging
  18. 26 19:09:01.128 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA]

    New http connection, requesting read 19:09:01.129 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Initialized pipeline DefaultChannelPipeline... 19:09:01.164 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Increasing pending responses, now 1 19:09:01.170 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Handler is being applied: org.springframework.. 19:09:01.181 ... [ctor-http-nio-5] ... [3f368fe3-2] HTTP GET "/hello/100" 19:09:01.199 ... [ctor-http-nio-5] ... [3f368fe3-2] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] 0..1 [java.lang.String] 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] New http connection, requesting read 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" Logging Request received
  19. 27 19:09:01.128 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA]

    New http connection, requesting read 19:09:01.129 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Initialized pipeline DefaultChannelPipeline... 19:09:01.164 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Increasing pending responses, now 1 19:09:01.170 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Handler is being applied: org.springframework.. 19:09:01.181 ... [ctor-http-nio-5] ... [3f368fe3-2] HTTP GET "/hello/100" 19:09:01.199 ... [ctor-http-nio-5] ... [3f368fe3-2] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] 0..1 [java.lang.String] 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] New http connection, requesting read 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" !??!! Logging
  20. Non-Blocking I/O 31 Requests etc. Intensive Operations File System Database

    Computation Register Callback Operation Complete Event Loop Trigger Callback
  21. 32 19:09:01.128 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA]

    New http connection, requesting read 19:09:01.129 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Initialized pipeline DefaultChannelPipeline... 19:09:01.164 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Increasing pending responses, now 1 19:09:01.170 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Handler is being applied: org.springframework.. 19:09:01.181 ... [ctor-http-nio-5] ... [3f368fe3-2] HTTP GET "/hello/100" 19:09:01.199 ... [ctor-http-nio-5] ... [3f368fe3-2] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] 0..1 [java.lang.String] 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] New http connection, requesting read 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" Logging
  22. 33 19:09:01.128 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA]

    New http connection, requesting read 19:09:01.129 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Initialized pipeline DefaultChannelPipeline... 19:09:01.164 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Increasing pending responses, now 1 19:09:01.170 ... [ctor-http-nio-5] ... [id: 0x3f368fe3, L:/XXX - R:/AAA] Handler is being applied: org.springframework.. 19:09:01.181 ... [ctor-http-nio-5] ... [3f368fe3-2] HTTP GET "/hello/100" 19:09:01.199 ... [ctor-http-nio-5] ... [3f368fe3-2] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.228 ... [ctor-http-nio-5] ... [3f368fe3-2] 0..1 [java.lang.String] 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] New http connection, requesting read 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0x97fe3c71, L:/XXX - R:/CCC] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" Logging
  23. 34 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB]

    New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.241 ... [ctor-http-nio-5] ... [e2dd0ccb-24] 0..1 [java.lang.String] 19:09:01.371 ... [ parallel-1] ... [e2dd0ccb-24] Writing "Hello, World!" 19:09:01.384 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Decreasing pending responses, now 0 19:09:01.385 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Completed 200 OK 19:09:01.385 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Last HTTP response frame 19:09:01.385 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Last HTTP packet was sent, terminating the channel Logging
  24. 35 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB]

    New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.241 ... [ctor-http-nio-5] ... [e2dd0ccb-24] 0..1 [java.lang.String] 19:09:01.371 ... [ parallel-1] ... [e2dd0ccb-24] Writing "Hello, World!" 19:09:01.384 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Decreasing pending responses, now 0 19:09:01.385 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Completed 200 OK 19:09:01.385 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Last HTTP response frame 19:09:01.385 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Last HTTP packet was sent, terminating the channel New connection established Logging
  25. 36 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB]

    New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.241 ... [ctor-http-nio-5] ... [e2dd0ccb-24] 0..1 [java.lang.String] 19:09:01.371 ... [ parallel-1] ... [e2dd0ccb-24] Writing "Hello, World!" 19:09:01.384 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Decreasing pending responses, now 0 19:09:01.385 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Completed 200 OK 19:09:01.385 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Last HTTP response frame 19:09:01.385 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Last HTTP packet was sent, terminating the channel Request received Logging
  26. 37 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB]

    New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.241 ... [ctor-http-nio-5] ... [e2dd0ccb-24] 0..1 [java.lang.String] 19:09:01.371 ... [ parallel-1] ... [e2dd0ccb-24] Writing "Hello, World!" 19:09:01.384 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Decreasing pending responses, now 0 19:09:01.385 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Completed 200 OK 19:09:01.385 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Last HTTP response frame 19:09:01.385 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Last HTTP packet was sent, terminating the channel Response prepared Logging
  27. 38 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB]

    New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.241 ... [ctor-http-nio-5] ... [e2dd0ccb-24] 0..1 [java.lang.String] 19:09:01.371 ... [ parallel-1] ... [e2dd0ccb-24] Writing "Hello, World!" 19:09:01.384 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Decreasing pending responses, now 0 19:09:01.385 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Completed 200 OK 19:09:01.385 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Last HTTP response frame 19:09:01.385 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Last HTTP packet was sent, terminating the channel Response completed Logging
  28. 39 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB]

    New http connection, requesting read 19:09:01.238 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Initialized pipeline DefaultChannelPipeline... 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Increasing pending responses, now 1 19:09:01.239 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Handler is being applied: org.springframework.. 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] HTTP GET "/hello/100" 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Mapped to io.springone.demo.HelloController#hello(long) 19:09:01.240 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 19:09:01.241 ... [ctor-http-nio-5] ... [e2dd0ccb-24] 0..1 [java.lang.String] 19:09:01.371 ... [ parallel-1] ... [e2dd0ccb-24] Writing "Hello, World!" 19:09:01.384 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Decreasing pending responses, now 0 19:09:01.385 ... [ctor-http-nio-5] ... [e2dd0ccb-24] Completed 200 OK 19:09:01.385 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Last HTTP response frame 19:09:01.385 ... [ctor-http-nio-5] ... [id: 0xe2dd0ccb, L:/XXX - R:/BBB] Last HTTP packet was sent, terminating the channel Logging
  29. @GetMapping("/hello/{delay}") public Mono<String> hello(ServerWebExchange exchange, @PathVariable("delay") long delay) { var

    logPrefix = exchange.getLogPrefix(); log.debug(logPrefix + "Preparing the response"); return Mono.just("Hello, World!") .delayElement(Duration.ofMillis(delay)) .doFinally(sig -> log.debug(logPrefix + "Response sent")); } 48 Logging - Log Prefix
  30. @GetMapping("/hello/{delay}") public Mono<String> hello(ServerWebExchange exchange, @PathVariable("delay") long delay) { var

    logPrefix = exchange.getLogPrefix(); log.debug(logPrefix + "Preparing the response"); return Mono.just("Hello, World!") .delayElement(Duration.ofMillis(delay)) .doFinally(sig -> log.debug(logPrefix + "Response sent")); } 49 Log ID Logging - Log Prefix
  31. 50 12:34:19.206 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY]

    New http connection, requesting read 12:34:19.206 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Initialized pipeline DefaultChannelPipeline... 12:34:19.215 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Increasing pending responses, now 1 12:34:19.215 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Handler is being applied: org.springframe... 12:34:19.215 ... [ctor-http-nio-3] ... [c5a4f03d-2] HTTP GET "/hello/100" 12:34:19.215 ... [ctor-http-nio-3] ... [c5a4f03d-2] Mapped to io.springone.demo.HelloController#hello... 12:34:19.216 ... [ctor-http-nio-3] ... [c5a4f03d-2] Preparing the response 12:34:19.216 ... [ctor-http-nio-3] ... [c5a4f03d-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 12:34:19.216 ... [ctor-http-nio-3] ... [c5a4f03d-2] 0..1 [java.lang.String] 12:34:19.321 ... [ parallel-2] ... [c5a4f03d-2] Writing "Hello, World!" 12:34:19.332 ... [ parallel-2] ... [c5a4f03d-2] Response sent 12:34:19.332 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Decreasing pending responses, now 0 12:34:19.333 ... [ctor-http-nio-3] ... [c5a4f03d-2] Completed 200 OK 12:34:19.333 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Last HTTP response frame 12:34:19.333 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Last HTTP packet was sent, terminating... Logging - Log Prefix
  32. 51 12:34:19.206 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY]

    New http connection, requesting read 12:34:19.206 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Initialized pipeline DefaultChannelPipeline... 12:34:19.215 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Increasing pending responses, now 1 12:34:19.215 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Handler is being applied: org.springframe... 12:34:19.215 ... [ctor-http-nio-3] ... [c5a4f03d-2] HTTP GET "/hello/100" 12:34:19.215 ... [ctor-http-nio-3] ... [c5a4f03d-2] Mapped to io.springone.demo.HelloController#hello... 12:34:19.216 ... [ctor-http-nio-3] ... [c5a4f03d-2] Preparing the response 12:34:19.216 ... [ctor-http-nio-3] ... [c5a4f03d-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 12:34:19.216 ... [ctor-http-nio-3] ... [c5a4f03d-2] 0..1 [java.lang.String] 12:34:19.321 ... [ parallel-2] ... [c5a4f03d-2] Writing "Hello, World!" 12:34:19.332 ... [ parallel-2] ... [c5a4f03d-2] Response sent 12:34:19.332 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Decreasing pending responses, now 0 12:34:19.333 ... [ctor-http-nio-3] ... [c5a4f03d-2] Completed 200 OK 12:34:19.333 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Last HTTP response frame 12:34:19.333 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Last HTTP packet was sent, terminating... Application logs Logging - Log Prefix
  33. 52 12:34:19.206 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY]

    New http connection, requesting read 12:34:19.206 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Initialized pipeline DefaultChannelPipeline... 12:34:19.215 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Increasing pending responses, now 1 12:34:19.215 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Handler is being applied: org.springframe... 12:34:19.215 ... [ctor-http-nio-3] ... [c5a4f03d-2] HTTP GET "/hello/100" 12:34:19.215 ... [ctor-http-nio-3] ... [c5a4f03d-2] Mapped to io.springone.demo.HelloController#hello... 12:34:19.216 ... [ctor-http-nio-3] ... [c5a4f03d-2] Preparing the response 12:34:19.216 ... [ctor-http-nio-3] ... [c5a4f03d-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported... 12:34:19.216 ... [ctor-http-nio-3] ... [c5a4f03d-2] 0..1 [java.lang.String] 12:34:19.321 ... [ parallel-2] ... [c5a4f03d-2] Writing "Hello, World!" 12:34:19.332 ... [ parallel-2] ... [c5a4f03d-2] Response sent 12:34:19.332 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Decreasing pending responses, now 0 12:34:19.333 ... [ctor-http-nio-3] ... [c5a4f03d-2] Completed 200 OK 12:34:19.333 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Last HTTP response frame 12:34:19.333 ... [ctor-http-nio-3] ... [id: 0xc5a4f03d, L:/XXX - R:/YYY] Last HTTP packet was sent, terminating... Application logs Logging - Log Prefix
  34. Spring WebFlux Logging ID Server • ServerWebExchange#LOG_ID_ATTRIBUTE • ServerWebExchange#getLogPrefix() Client

    • ClientRequest#LOG_ID_ATTRIBUTE • ClientRequest#logPrefix() https://docs.spring.io/spring/docs/current/spring-framework-reference/web-reactive.html#webflux-logging-id 53
  35. 55 @Component public class MyNettyWebServerCustomizer implements WebServerFactoryCustomizer<NettyReactiveWebServerFactory> { @Override public

    void customize(NettyReactiveWebServerFactory factory) { factory.addServerCustomizers(httpServer -> httpServer.wiretap(true)); } } Server Side - Wire Logging
  36. 56 @Component public class MyNettyWebServerCustomizer implements WebServerFactoryCustomizer<NettyReactiveWebServerFactory> { @Override public

    void customize(NettyReactiveWebServerFactory factory) { factory.addServerCustomizers(httpServer -> httpServer.wiretap(true)); } } Wire logging Server Side - Wire Logging
  37. Client Side - Wire Logging var httpClient = HttpClient.create() .wiretap(true);

    WebClient.builder() .clientConnector(new ReactorClientHttpConnector(httpClient)) .build(); 57
  38. 58 Client Side - Wire Logging var httpClient = HttpClient.create()

    .wiretap(true); WebClient.builder() .clientConnector(new ReactorClientHttpConnector(httpClient)) .build(); 6 Wire logging
  39. 59 14:43:26.250 ... [ctor-http-nio-6] ... [id: 0x6e9c38fd, L:/XXX - R:/YYY]

    READ: 87B +——————————————————————+ | 0 1 2 3 4 5 6 7 8 9 a b c d e f | +————+——————————————————————+————————+ |00000000| 47 45 54 20 2f 68 65 6c 6c 6f 2f 31 30 30 20 48 | GET /hello/100 H | |00000010| 54 54 50 2f 31 2e 31 0d 0a 48 6f 73 74 3a 20 6c | TTP/1.1..Host: l. | |00000020| 6f 63 61 6c 68 6f 73 74 3a 38 30 38 30 0d 0a 55 | ocalhost:8080..U. | |00000030| 73 65 72 2d 41 67 65 6e 74 3a 20 63 75 72 6c 2f | ser-Agent: curl/. | |00000040| 37 2e 37 31 2e 31 0d 0a 41 63 63 65 70 74 3a 20 | 7.71.1..Accept: | |00000050| 2a 2f 2a 0d 0a 0d 0a | */*…. | +————+——————————————————————+————————+ Wire Logging HTTP/1.1 - Read Events
  40. 60 14:43:26.366 ... [ctor-http-nio-6] ... [id: 0x6e9c38fd, L:/XXX - R:/YYY]

    WRITE: 92B +——————————————————————+ | 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 32 30 30 20 4f 4b 0d | HTTP/1.1 200 OK.| |00000010| 0a 43 6f 6e 74 65 6e 74 2d 54 79 70 65 3a 20 74 | .Content-Type: t. | |00000020| 65 78 74 2f 70 6c 61 69 6e 3b 63 68 61 72 73 65 | ext/plain;charse | |00000030| 74 3d 55 54 46 2d 38 0d 0a 43 6f 6e 74 65 6e 74 | t=UTF-8..Content. | |00000040| 2d 4c 65 6e 67 74 68 3a 20 31 33 0d 0a 0d 0a 48 | -Length: 13….H. | |00000050| 65 6c 6c 6f 2c 20 57 6f 72 6c 64 21 | ello, World! | +————+——————————————————————+———————-—+ 14:43:26.366 ... [ctor-http-nio-6] ... [id: 0x6e9c38fd, L:/XXX - R:/YYY] FLUSH Wire Logging HTTP/1.1 - Write Events
  41. 61 [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND SETTINGS: ack=false settings={MAX_HEADER_LIST_SIZE=8192}

    [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=33554432} [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND SETTINGS: ack=true [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=33488897 [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND HEADERS: streamId=1 headers=DefaultHttp2Headers[:method: GET, :path: /hello/100, :scheme: https, :authority: localhost:8090, user-agent: curl/7.71.1, accept: */*] padding=0 endStream=true [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) New HTTP/2 stream [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) Initialized HTTP/2 stream pipeline AbstractHttp2StreamChannel$3… [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) Handler is being applied: org.springframework… [1d3dcabb/1-2] HTTP GET "/hello/100" [1d3dcabb/1-2] Mapped to io.springone.demo.HelloController#hello(ServerWebExchange, long) [1d3dcabb/1-2] Preparing the response [1d3dcabb/1-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported [text/plain;charset=UTF-8, text/event-stream, text/plain;charset=UTF-8, */*] [1d3dcabb/1-2] 0..1 [java.lang.String] [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND SETTINGS: ack=true [1d3dcabb/1-2] Writing "Hello, World!" [1d3dcabb/1-2] Response sent [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND HEADERS: streamId=1 headers=DefaultHttp2Headers[:status: 200, content-type: text/plain;charset=UTF-8, content-length: 13] padding=0 endStream=false [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND DATA: streamId=1 padding=0 endStream=true length=13 bytes=48656c6c6f2c20576f726c6421 [1d3dcabb/1-2] Completed 200 OK Wire Logging HTTP/2
  42. 62 [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND SETTINGS: ack=false settings={MAX_HEADER_LIST_SIZE=8192}

    [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=33554432} [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND SETTINGS: ack=true [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=33488897 [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND HEADERS: streamId=1 headers=DefaultHttp2Headers[:method: GET, :path: /hello/100, :scheme: https, :authority: localhost:8090, user-agent: curl/7.71.1, accept: */*] padding=0 endStream=true [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) New HTTP/2 stream [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) Initialized HTTP/2 stream pipeline AbstractHttp2StreamChannel$3… [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) Handler is being applied: org.springframework… [1d3dcabb/1-2] HTTP GET "/hello/100" [1d3dcabb/1-2] Mapped to io.springone.demo.HelloController#hello(ServerWebExchange, long) [1d3dcabb/1-2] Preparing the response [1d3dcabb/1-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported [text/plain;charset=UTF-8, text/event-stream, text/plain;charset=UTF-8, */*] [1d3dcabb/1-2] 0..1 [java.lang.String] [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND SETTINGS: ack=true [1d3dcabb/1-2] Writing "Hello, World!" [1d3dcabb/1-2] Response sent [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND HEADERS: streamId=1 headers=DefaultHttp2Headers[:status: 200, content-type: text/plain;charset=UTF-8, content-length: 13] padding=0 endStream=false [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND DATA: streamId=1 padding=0 endStream=true length=13 bytes=48656c6c6f2c20576f726c6421 [1d3dcabb/1-2] Completed 200 OK Wire Logging HTTP/2
  43. 63 [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND SETTINGS: ack=false settings={MAX_HEADER_LIST_SIZE=8192}

    [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=33554432} [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND SETTINGS: ack=true [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=33488897 [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND HEADERS: streamId=1 headers=DefaultHttp2Headers[:method: GET, :path: /hello/100, :scheme: https, :authority: localhost:8090, user-agent: curl/7.71.1, accept: */*] padding=0 endStream=true [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) New HTTP/2 stream [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) Initialized HTTP/2 stream pipeline AbstractHttp2StreamChannel$3… [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) Handler is being applied: org.springframework… [1d3dcabb/1-2] HTTP GET "/hello/100" [1d3dcabb/1-2] Mapped to io.springone.demo.HelloController#hello(ServerWebExchange, long) [1d3dcabb/1-2] Preparing the response [1d3dcabb/1-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported [text/plain;charset=UTF-8, text/event-stream, text/plain;charset=UTF-8, */*] [1d3dcabb/1-2] 0..1 [java.lang.String] [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND SETTINGS: ack=true [1d3dcabb/1-2] Writing "Hello, World!" [1d3dcabb/1-2] Response sent [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND HEADERS: streamId=1 headers=DefaultHttp2Headers[:status: 200, content-type: text/plain;charset=UTF-8, content-length: 13] padding=0 endStream=false [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND DATA: streamId=1 padding=0 endStream=true length=13 bytes=48656c6c6f2c20576f726c6421 [1d3dcabb/1-2] Completed 200 OK Wire Logging HTTP/2
  44. 64 [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND SETTINGS: ack=false settings={MAX_HEADER_LIST_SIZE=8192}

    [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=33554432} [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND SETTINGS: ack=true [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=33488897 [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND HEADERS: streamId=1 headers=DefaultHttp2Headers[:method: GET, :path: /hello/100, :scheme: https, :authority: localhost:8090, user-agent: curl/7.71.1, accept: */*] padding=0 endStream=true [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) New HTTP/2 stream [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) Initialized HTTP/2 stream pipeline AbstractHttp2StreamChannel$3… [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) Handler is being applied: org.springframework… [1d3dcabb/1-2] HTTP GET "/hello/100" [1d3dcabb/1-2] Mapped to io.springone.demo.HelloController#hello(ServerWebExchange, long) [1d3dcabb/1-2] Preparing the response [1d3dcabb/1-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported [text/plain;charset=UTF-8, text/event-stream, text/plain;charset=UTF-8, */*] [1d3dcabb/1-2] 0..1 [java.lang.String] [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND SETTINGS: ack=true [1d3dcabb/1-2] Writing "Hello, World!" [1d3dcabb/1-2] Response sent [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND HEADERS: streamId=1 headers=DefaultHttp2Headers[:status: 200, content-type: text/plain;charset=UTF-8, content-length: 13] padding=0 endStream=false [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND DATA: streamId=1 padding=0 endStream=true length=13 bytes=48656c6c6f2c20576f726c6421 [1d3dcabb/1-2] Completed 200 OK Wire Logging HTTP/2
  45. 65 [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND SETTINGS: ack=false settings={MAX_HEADER_LIST_SIZE=8192}

    [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=33554432} [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND SETTINGS: ack=true [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=33488897 [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND HEADERS: streamId=1 headers=DefaultHttp2Headers[:method: GET, :path: /hello/100, :scheme: https, :authority: localhost:8090, user-agent: curl/7.71.1, accept: */*] padding=0 endStream=true [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) New HTTP/2 stream [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) Initialized HTTP/2 stream pipeline AbstractHttp2StreamChannel$3… [id: 0x1d3dcabb, L:/XXX - R:/YYY](H2 - 1) Handler is being applied: org.springframework… [1d3dcabb/1-2] HTTP GET "/hello/100" [1d3dcabb/1-2] Mapped to io.springone.demo.HelloController#hello(ServerWebExchange, long) [1d3dcabb/1-2] Preparing the response [1d3dcabb/1-2] Using 'text/plain;charset=UTF-8' given [*/*] and supported [text/plain;charset=UTF-8, text/event-stream, text/plain;charset=UTF-8, */*] [1d3dcabb/1-2] 0..1 [java.lang.String] [id: 0x1d3dcabb, L:/XXX - R:/YYY] INBOUND SETTINGS: ack=true [1d3dcabb/1-2] Writing "Hello, World!" [1d3dcabb/1-2] Response sent [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND HEADERS: streamId=1 headers=DefaultHttp2Headers[:status: 200, content-type: text/plain;charset=UTF-8, content-length: 13] padding=0 endStream=false [id: 0x1d3dcabb, L:/XXX - R:/YYY] OUTBOUND DATA: streamId=1 padding=0 endStream=true length=13 bytes=48656c6c6f2c20576f726c6421 [1d3dcabb/1-2] Completed 200 OK Wire Logging HTTP/2
  46. @GetMapping("/remote") public Mono<String> remote() { return webClient.get() .uri("http://localhost:8080/") .exchange() .flatMap(response

    -> Mono.just(response.statusCode() .toString())) .timeout(Duration.ofSeconds(5)); } Memory Leaks 67
  47. LEAK: ByteBuf.release() was not called before it's garbage-collected. See https://netty.io/wiki/reference-counted-objects.html

    for more information. Recent access records: Created at: io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:363) io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:187) io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:178) io.netty.buffer.AbstractByteBufAllocator.ioBuffer(AbstractByteBufAllocator.java:139) io.netty.channel.DefaultMaxMessagesRecvByteBufAllocator$MaxMessageHandle.allocate(DefaultMaxMessagesRecvByteBufAllocator.java:114) io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:147) io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714) io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650) io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576) io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) java.base/java.lang.Thread.run(Thread.java:832) Memory Leaks 68
  48. LEAK: ByteBuf.release() was not called before it's garbage-collected. See https://netty.io/wiki/reference-counted-objects.html

    for more information. Recent access records: #1: Hint: [id: 0x2c17d156, L:/127.0.0.1:62487 - R:localhost/127.0.0.1:8080] Buffered ByteBufHolder in Inbound Flux Queue io.netty.handler.codec.http.DefaultHttpContent.touch(DefaultHttpContent.java:86) io.netty.handler.codec.http.DefaultHttpContent.touch(DefaultHttpContent.java:25) reactor.netty.channel.FluxReceive.onInboundNext(FluxReceive.java:357) reactor.netty.channel.ChannelOperations.onInboundNext(ChannelOperations.java:373) reactor.netty.http.client.HttpClientOperations.onInboundNext(HttpClientOperations.java:686) reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:94) ... #2: Hint: 'reactor.right.reactiveBridge' will handle the message from this point. io.netty.handler.codec.http.DefaultHttpContent.touch(DefaultHttpContent.java:86) io.netty.handler.codec.http.DefaultHttpContent.touch(DefaultHttpContent.java:25) io.netty.channel.DefaultChannelPipeline.touch(DefaultChannelPipeline.java:116) io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436) ... Memory Leaks 70
  49. LEAK: ByteBuf.release() was not called before it's garbage-collected. See https://netty.io/wiki/reference-counted-objects.html

    for more information. Recent access records: #1: Hint: [id: 0x2c17d156, L:/127.0.0.1:62487 - R:localhost/127.0.0.1:8080] Buffered ByteBufHolder in Inbound Flux Queue io.netty.handler.codec.http.DefaultHttpContent.touch(DefaultHttpContent.java:86) io.netty.handler.codec.http.DefaultHttpContent.touch(DefaultHttpContent.java:25) reactor.netty.channel.FluxReceive.onInboundNext(FluxReceive.java:357) reactor.netty.channel.ChannelOperations.onInboundNext(ChannelOperations.java:373) reactor.netty.http.client.HttpClientOperations.onInboundNext(HttpClientOperations.java:686) reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:94) ... #2: Hint: 'reactor.right.reactiveBridge' will handle the message from this point. io.netty.handler.codec.http.DefaultHttpContent.touch(DefaultHttpContent.java:86) io.netty.handler.codec.http.DefaultHttpContent.touch(DefaultHttpContent.java:25) io.netty.channel.DefaultChannelPipeline.touch(DefaultChannelPipeline.java:116) io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436) ... Connection ID Memory Leaks 71
  50. LEAK: ByteBuf.release() was not called before it's garbage-collected. See https://netty.io/wiki/reference-counted-objects.html

    for more information. Recent access records: #1: Hint: [id: 0x2c17d156, L:/127.0.0.1:62487 - R:localhost/127.0.0.1:8080] Buffered ByteBufHolder in Inbound Flux Queue io.netty.handler.codec.http.DefaultHttpContent.touch(DefaultHttpContent.java:86) io.netty.handler.codec.http.DefaultHttpContent.touch(DefaultHttpContent.java:25) reactor.netty.channel.FluxReceive.onInboundNext(FluxReceive.java:357) reactor.netty.channel.ChannelOperations.onInboundNext(ChannelOperations.java:373) reactor.netty.http.client.HttpClientOperations.onInboundNext(HttpClientOperations.java:686) reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:94) ... #2: Hint: 'reactor.right.reactiveBridge' will handle the message from this point. io.netty.handler.codec.http.DefaultHttpContent.touch(DefaultHttpContent.java:86) io.netty.handler.codec.http.DefaultHttpContent.touch(DefaultHttpContent.java:25) io.netty.channel.DefaultChannelPipeline.touch(DefaultChannelPipeline.java:116) io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436) ... Incoming Data Buffered Memory Leaks 72
  51. 10:55:23.820 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Channel

    acquired, now 500 active connections and 0 inactive connections 10:55:23.820 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Handler is being applied: {uri=http:// localhost:8080/, method=GET} 10:55:23.821 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Received response (auto-read:false) : [Content- Type=text/html;charset=UTF-8, Transfer-Encoding=chunked, Date=Sun, 30 Aug 2020 07:55:23 GMT, Connection=close] 10:55:23.821 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Received last HTTP packet Hint: [id: 0x2c17d156, L:/XXX - R:YYY] Buffered ByteBufHolder in Inbound Flux Queue Memory Leaks 73
  52. 10:55:23.820 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Channel

    acquired, now 500 active connections and 0 inactive connections 10:55:23.820 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Handler is being applied: {uri=http:// localhost:8080/, method=GET} 10:55:23.821 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Received response (auto-read:false) : [Content- Type=text/html;charset=UTF-8, Transfer-Encoding=chunked, Date=Sun, 30 Aug 2020 07:55:23 GMT, Connection=close] 10:55:23.821 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Received last HTTP packet Hint: [id: 0x2c17d156, L:/XXX - R:YYY] Buffered ByteBufHolder in Inbound Flux Queue Memory Leaks 74
  53. 10:55:23.820 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Channel

    acquired, now 500 active connections and 0 inactive connections 10:55:23.820 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Handler is being applied: {uri=http:// localhost:8080/, method=GET} 10:55:23.821 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Received response (auto-read:false) : [Content- Type=text/html;charset=UTF-8, Transfer-Encoding=chunked, Date=Sun, 30 Aug 2020 07:55:23 GMT, Connection=close] 10:55:23.821 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Received last HTTP packet Hint: [id: 0x2c17d156, L:/XXX - R:YYY] Buffered ByteBufHolder in Inbound Flux Queue Memory Leaks 75
  54. 76 10:55:23.820 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY]

    Channel acquired, now 500 active connections and 0 inactive connections 10:55:23.820 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Handler is being applied: {uri=http:// localhost:8080/, method=GET} 10:55:23.821 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Received response (auto-read:false) : [Content- Type=text/html;charset=UTF-8, Transfer-Encoding=chunked, Date=Sun, 30 Aug 2020 07:55:23 GMT, Connection=close] 10:55:23.821 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Received last HTTP packet Hint: [id: 0x2c17d156, L:/XXX - R:YYY] Buffered ByteBufHolder in Inbound Flux Queue 6 Memory Leaks
  55. 10:55:23.820 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Channel

    acquired, now 500 active connections and 0 inactive connections 10:55:23.820 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Handler is being applied: {uri=http:// localhost:8080/, method=GET} 10:55:23.821 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Received response (auto-read:false) : [Content- Type=text/html;charset=UTF-8, Transfer-Encoding=chunked, Date=Sun, 30 Aug 2020 07:55:23 GMT, Connection=close] 10:55:23.821 ... [ctor-http-nio-9] ... [id: 0x2c17d156, L:/XXX - R:YYY] Received last HTTP packet Hint: [id: 0x2c17d156, L:/XXX - R:YYY] Buffered ByteBufHolder in Inbound Flux Queue Was the incoming data consumed !??!! Memory Leaks 77
  56. @GetMapping("/remote") public Mono<String> remote() { return webClient.get() .uri("http://localhost:8080/") .exchange() .flatMap(response

    -> Mono.just(response.statusCode() .toString())) .timeout(Duration.ofSeconds(5)); } Memory Leaks 78
  57. @GetMapping("/remote") public Mono<String> remote() { return webClient.get() .uri("http://localhost:8080/") .exchange() .flatMap(response

    -> Mono.just(response.statusCode() .toString())) .timeout(Duration.ofSeconds(5)); } Was the incoming data consumed !??!! Memory Leaks 79
  58. Unlike retrieve(), when using exchange(), it is the responsibility of

    the application to consume any response content regardless of the scenario (success, error, unexpected data, etc). Not doing so can cause a memory leak. https://docs.spring.io/spring/docs/current/spring-framework-reference/web- reactive.html#webflux-client-exchange 80 Memory Leaks
  59. @GetMapping("/remote") public Mono<String> remote() { return webClient.get() .uri("http://localhost:8080/") .retrieve() .toEntity(String.class)

    .flatMap(entity -> Mono.just(entity.getStatusCode() .toString())) .timeout(Duration.ofSeconds(5)); } ResponseEntity 81
  60. @GetMapping("/remote") public Mono<String> remote() { return webClient.get() .uri("http://localhost:8080/") .retrieve() .toEntity(String.class)

    .flatMap(entity -> Mono.just(entity.getStatusCode() .toString())) .timeout(Duration.ofSeconds(5)); } ResponseEntity Status Code Headers Body 82
  61. @GetMapping("/remote") public Mono<String> remote() { return webClient.get() .uri("http://localhost:8080/") .retrieve() .onStatus(HttpStatus::is4xxClientError,

    response -> Mono.error(new RuntimeException("Client error"))) .onStatus(HttpStatus::is5xxServerError, response -> Mono.error(new RuntimeException("Server error"))) .bodyToMono(String.class) .timeout(Duration.ofSeconds(5)); } OnStatus 83
  62. @GetMapping("/remote") public Mono<String> remote() { return webClient.get() .uri("http://localhost:8080/") .retrieve() .onStatus(HttpStatus::is4xxClientError,

    response -> Mono.error(new RuntimeException("Client error"))) .onStatus(HttpStatus::is5xxServerError, response -> Mono.error(new RuntimeException("Server error"))) .bodyToMono(String.class) .timeout(Duration.ofSeconds(5)); } OnStatus Custom Exception 84
  63. When onStatus is used, if the response is expected to

    have content, then the onStatus callback should consume it. If not, the content will be automatically drained to ensure resources are released. https://docs.spring.io/spring/docs/current/spring-framework-reference/web- reactive.html#webflux-client-retrieve 85 OnStatus
  64. Server Side - Read Timeout @Component public class MyNettyWebServerCustomizer implements

    WebServerFactoryCustomizer<NettyReactiveWebServerFactory> { @Override public void customize(NettyReactiveWebServerFactory factory) { factory.addServerCustomizers( server -> server.doOnConnection(conn -> conn.addHandlerFirst( new ReadTimeoutHandler(50, TimeUnit.MILLISECONDS)))); } } 88
  65. Server Side - Read Timeout @Component public class MyNettyWebServerCustomizer implements

    WebServerFactoryCustomizer<NettyReactiveWebServerFactory> { @Override public void customize(NettyReactiveWebServerFactory factory) { factory.addServerCustomizers( server -> server.doOnConnection(conn -> conn.addHandlerFirst( new ReadTimeoutHandler(50, TimeUnit.MILLISECONDS)))); } } Read timeout 89
  66. Server Side - Read Timeout • Time between two requests

    • Timeout for the incoming data ◦ network latency • May interfere when TLS handshake • May interfere when sending a response ◦ processing latency 90
  67. Client Side - Timeouts var provider = ConnectionProvider.builder("demo") .maxConnections(16) .maxIdleTime(Duration.ofSeconds(60))

    .maxLifeTime(Duration.ofSeconds(60)) .build(); var httpClient = HttpClient.create() .option(ChannelOption.CONNECT_TIMEOUT_MILLIS, 60000) .wiretap(true) .responseTimeout(Duration.ofSeconds(1)); WebClient.builder() .clientConnector(new ReactorClientHttpConnector(httpClient)) .build(); 91
  68. Client Side - Connection Pool var provider = ConnectionProvider.builder("demo") .maxConnections(16)

    .maxIdleTime(Duration.ofSeconds(60)) .maxLifeTime(Duration.ofSeconds(60)) .build(); var httpClient = HttpClient.create() .option(ChannelOption.CONNECT_TIMEOUT_MILLIS, 60000) .wiretap(true) .responseTimeout(Duration.ofSeconds(1)); WebClient.builder() .clientConnector(new ReactorClientHttpConnector(httpClient)) .build(); Max idle time in the pool 92
  69. Client Side - Connection Pool var provider = ConnectionProvider.builder("demo") .maxConnections(16)

    .maxIdleTime(Duration.ofSeconds(60)) .maxLifeTime(Duration.ofSeconds(60)) .build(); var httpClient = HttpClient.create() .option(ChannelOption.CONNECT_TIMEOUT_MILLIS, 60000) .wiretap(true) .responseTimeout(Duration.ofSeconds(1)); WebClient.builder() .clientConnector(new ReactorClientHttpConnector(httpClient)) .build(); Max life time for the connection 93
  70. Client Side - Establishing Connection var provider = ConnectionProvider.builder("demo") .maxConnections(16)

    .maxIdleTime(Duration.ofSeconds(60)) .maxLifeTime(Duration.ofSeconds(60)) .build(); var httpClient = HttpClient.create() .option(ChannelOption.CONNECT_TIMEOUT_MILLIS, 60000) .wiretap(true) .responseTimeout(Duration.ofSeconds(1)); WebClient.builder() .clientConnector(new ReactorClientHttpConnector(httpClient)) .build(); Max time waiting to establish connection 94
  71. Client Side - Response Timeout var provider = ConnectionProvider.builder("demo") .maxConnections(16)

    .maxIdleTime(Duration.ofSeconds(60)) .maxLifeTime(Duration.ofSeconds(60)) .build(); var httpClient = HttpClient.create() .option(ChannelOption.CONNECT_TIMEOUT_MILLIS, 60000) .wiretap(true) .responseTimeout(Duration.ofSeconds(1)); WebClient.builder() .clientConnector(new ReactorClientHttpConnector(httpClient)) .build(); Max time waiting for a response 95
  72. 96 Client Side - Response Timeout @GetMapping("/remote") public Mono<String> remote()

    { return webClient.get() .uri("http://localhost:8080/") .httpRequest(request -> ((HttpClientRequest) request.getNativeRequest()) .responseTimeout(Duration.ofSeconds(1))) .retrieve() … } 6
  73. Client Side - Response Timeout @GetMapping("/remote") public Mono<String> remote() {

    return webClient.get() .uri("http://localhost:8080/") .httpRequest(request -> ((HttpClientRequest) request.getNativeRequest()) .responseTimeout(Duration.ofSeconds(1))) .retrieve() … } Max time waiting for a response 97
  74. Client Side - Timeout for Mono/Flux @GetMapping("/remote") public Mono<String> remote()

    { return webClient.get() .uri("http://localhost:8080/") .retrieve() … .timeout(…) } 98
  75. Client Side - Timeout for Mono/Flux @GetMapping("/remote") public Mono<String> remote()

    { return webClient.get() .uri("http://localhost:8080/") .retrieve() … .timeout(…) } Timeout for this Mono 99
  76. • Time between two signals from this Flux/Mono • Timeout

    for the incoming data ◦ network latency • May interfere when establishing connection • May interfere when TLS handshake • May interfere when sending a request ◦ processing latency 100 Client Side - Timeout for Mono/Flux
  77. Target Server - Read Timeout @Component public class MyNettyWebServerCustomizer implements

    WebServerFactoryCustomizer<NettyReactiveWebServerFactory> { @Override public void customize(NettyReactiveWebServerFactory factory) { factory.addServerCustomizers( server -> server.doOnConnection(conn -> conn.addHandlerFirst( new ReadTimeoutHandler(50, TimeUnit.MILLISECONDS)))); } } 103
  78. Target Server - Read Timeout @Component public class MyNettyWebServerCustomizer implements

    WebServerFactoryCustomizer<NettyReactiveWebServerFactory> { @Override public void customize(NettyReactiveWebServerFactory factory) { factory.addServerCustomizers( server -> server.doOnConnection(conn -> conn.addHandlerFirst( new ReadTimeoutHandler(50, TimeUnit.MILLISECONDS)))); } } Read timeout (50ms) 104
  79. 106 Client - Read Timeout @GetMapping("/remote") public Mono<String> remote() {

    var flux = Flux.just(CONTENT, CONTENT) .delayElements(Duration.ofMillis(100)); return webClient.post() .uri(“http://localhost:8080/echo") .body(BodyInserters.fromPublisher(flux, String.class)) .retrieve() .bodyToMono(String.class); } 6
  80. Client - Read Timeout @GetMapping("/remote") public Mono<String> remote() { var

    flux = Flux.just(CONTENT, CONTENT) .delayElements(Duration.ofMillis(100)); return webClient.post() .uri(“http://localhost:8080/echo") .body(BodyInserters.fromPublisher(flux, String.class)) .retrieve() .bodyToMono(String.class); } Simulate Network Latency 107
  81. 15:18:39.799 ... [ctor-http-nio-1] ... [id: 0x808fe695] Created a new pooled

    channel, now 16 active connections and 0 inactive… 15:18:39.799 ... [ctor-http-nio-1] ... [id: 0x808fe695] Initialized pipeline DefaultChannelPipeline.... 15:18:39.799 ... [ctor-http-nio-1] ... [id: 0x808fe695] REGISTERED 15:18:39.821 ... [ctor-http-nio-1] ... [id: 0x808fe695] CONNECT: localhost/127.0.0.1:8080 15:18:39.868 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 - R:YYY] Registering pool release on close event for… 15:18:39.868 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 - R:YYY] Channel connected, now 3 active connections… 15:18:39.868 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 - R:YYY] ACTIVE 15:18:39.868 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 - R:YYY] Handler is being applied: {uri=http://… 15:18:40.086 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 ! R:YYY] Channel closed, now 0 active connections and… 15:18:40.094 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 ! R:YYY] INACTIVE 15:18:40.094 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 ! R:YYY] The connection observed an error reactor.netty.http.client.PrematureCloseException: Connection has been closed BEFORE response, while sending request body Client - Read Timeout 108
  82. 15:18:39.799 ... [ctor-http-nio-1] ... [id: 0x808fe695] Created a new pooled

    channel, now 16 active connections and 0 inactive… 15:18:39.799 ... [ctor-http-nio-1] ... [id: 0x808fe695] Initialized pipeline DefaultChannelPipeline.... 15:18:39.799 ... [ctor-http-nio-1] ... [id: 0x808fe695] REGISTERED 15:18:39.821 ... [ctor-http-nio-1] ... [id: 0x808fe695] CONNECT: localhost/127.0.0.1:8080 15:18:39.868 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 - R:YYY] Registering pool release on close event for… 15:18:39.868 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 - R:YYY] Channel connected, now 3 active connections… 15:18:39.868 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 - R:YYY] ACTIVE 15:18:39.868 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 - R:YYY] Handler is being applied: {uri=http://… 15:18:40.086 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 ! R:YYY] Channel closed, now 0 active connections and… 15:18:40.094 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 ! R:YYY] INACTIVE 15:18:40.094 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 ! R:YYY] The connection observed an error reactor.netty.http.client.PrematureCloseException: Connection has been closed BEFORE response, while sending request body Client - Read Timeout !??!! 109
  83. 15:18:39.799 ... [ctor-http-nio-1] ... [id: 0x808fe695] Created a new pooled

    channel, now 16 active connections and 0 inactive… 15:18:39.799 ... [ctor-http-nio-1] ... [id: 0x808fe695] Initialized pipeline DefaultChannelPipeline.... 15:18:39.799 ... [ctor-http-nio-1] ... [id: 0x808fe695] REGISTERED 15:18:39.821 ... [ctor-http-nio-1] ... [id: 0x808fe695] CONNECT: localhost/127.0.0.1:8080 15:18:39.868 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 - R:YYY] Registering pool release on close event for… 15:18:39.868 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 - R:YYY] Channel connected, now 3 active connections… 15:18:39.868 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 - R:YYY] ACTIVE 15:18:39.868 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 - R:YYY] Handler is being applied: {uri=http://… 15:18:40.086 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 ! R:YYY] Channel closed, now 0 active connections and… 15:18:40.094 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 ! R:YYY] INACTIVE 15:18:40.094 ... [ctor-http-nio-1] ... [id: 0x808fe695, L:/127.0.0.1:50246 ! R:YYY] The connection observed an error reactor.netty.http.client.PrematureCloseException: Connection has been closed BEFORE response, while sending request body Client - Read Timeout Client port 110
  84. 15:18:39.821 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] New

    http connection, requesting read 15:18:39.821 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Initialized pipeline DefaultChannelPipeline… 15:18:39.871 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Increasing pending responses, now 1 15:18:39.871 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Added encoder [ReadTimeoutHandler] at the… 15:18:39.871 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Handler is being applied: org.springframework.. 15:18:39.872 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] FluxReceive{pending=0, cancelled=false… 15:18:39.927 ... [ctor-http-nio-5] ... [d4c75b22-100] 500 Server Error for HTTP POST "/echo" io.netty.handler.timeout.ReadTimeoutException: null 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Decreasing pending responses, now 0 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Last HTTP packet was sent, terminating… 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Last HTTP response frame 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY ! R:/127.0.0.1:50246] Non Removed handler: ... Target Server - Read Timeout 111
  85. 15:18:39.821 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] New

    http connection, requesting read 15:18:39.821 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Initialized pipeline DefaultChannelPipeline… 15:18:39.871 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Increasing pending responses, now 1 15:18:39.871 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Added encoder [ReadTimeoutHandler] at the… 15:18:39.871 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Handler is being applied: org.springframework.. 15:18:39.872 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] FluxReceive{pending=0, cancelled=false… 15:18:39.927 ... [ctor-http-nio-5] ... [d4c75b22-100] 500 Server Error for HTTP POST "/echo" io.netty.handler.timeout.ReadTimeoutException: null 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Decreasing pending responses, now 0 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Last HTTP packet was sent, terminating… 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Last HTTP response frame 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY ! R:/127.0.0.1:50246] Non Removed handler: ... Target Server - Read Timeout Client port 112
  86. 15:18:39.821 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] New

    http connection, requesting read 15:18:39.821 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Initialized pipeline DefaultChannelPipeline… 15:18:39.871 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Increasing pending responses, now 1 15:18:39.871 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Added encoder [ReadTimeoutHandler] at the… 15:18:39.871 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Handler is being applied: org.springframework.. 15:18:39.872 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] FluxReceive{pending=0, cancelled=false… 15:18:39.927 ... [ctor-http-nio-5] ... [d4c75b22-100] 500 Server Error for HTTP POST "/echo" io.netty.handler.timeout.ReadTimeoutException: null 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Decreasing pending responses, now 0 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Last HTTP packet was sent, terminating… 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Last HTTP response frame 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY ! R:/127.0.0.1:50246] Non Removed handler: ... Target Server - Read Timeout 113
  87. 15:18:39.821 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] New

    http connection, requesting read 15:18:39.821 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Initialized pipeline DefaultChannelPipeline… 15:18:39.871 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Increasing pending responses, now 1 15:18:39.871 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Added encoder [ReadTimeoutHandler] at the… 15:18:39.871 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Handler is being applied: org.springframework.. 15:18:39.872 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] FluxReceive{pending=0, cancelled=false… 15:18:39.927 ... [ctor-http-nio-5] ... [d4c75b22-100] 500 Server Error for HTTP POST "/echo" io.netty.handler.timeout.ReadTimeoutException: null 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Decreasing pending responses, now 0 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Last HTTP packet was sent, terminating… 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY - R:/127.0.0.1:50246] Last HTTP response frame 15:18:39.928 ... [ctor-http-nio-5] ... [id: 0xd4c75b22, L:/YYY ! R:/127.0.0.1:50246] Non Removed handler: ... Target Server - Read Timeout Read timeout (50ms) 114
  88. 116 Target Server - Read Timeout @Component public class MyNettyWebServerCustomizer

    implements WebServerFactoryCustomizer<NettyReactiveWebServerFactory> { @Override public void customize(NettyReactiveWebServerFactory factory) { factory.addServerCustomizers( server -> server.doOnConnection(conn -> conn.addHandlerFirst( new ReadTimeoutHandler(50, TimeUnit.MILLISECONDS)))); } } 6
  89. Target Server - Read Timeout @Component public class MyNettyWebServerCustomizer implements

    WebServerFactoryCustomizer<NettyReactiveWebServerFactory> { @Override public void customize(NettyReactiveWebServerFactory factory) { factory.addServerCustomizers( server -> server.doOnConnection(conn -> conn.addHandlerFirst( new ReadTimeoutHandler(50, TimeUnit.MILLISECONDS)))); } } Read timeout (50ms) 117
  90. Target Server - Read Timeout @PostMapping("/echo") public Mono<String> echo(@RequestBody String

    body) { return Mono.just(body) .delayElement(Duration.ofMillis(100)); } 118
  91. Target Server - Read Timeout @PostMapping("/echo") public Mono<String> echo(@RequestBody String

    body) { return Mono.just(body) .delayElement(Duration.ofMillis(100)); } Simulate Processing Latency 119
  92. Client - Read Timeout @GetMapping("/remote") public Mono<String> remote() { var

    flux = Flux.just(CONTENT, CONTENT); return webClient.post() .uri(“http://localhost:8080/echo") .body(BodyInserters.fromPublisher(flux, String.class)) .retrieve() .bodyToMono(String.class); } 120
  93. 16:22:03.936 ... [tor-http-nio-10] ... [id: 0x058eaaa2] Created a new pooled

    channel, now 3 active connections and 0 inactive... 16:22:03.937 ... [tor-http-nio-10] ... [id: 0x058eaaa2] Initialized pipeline DefaultChannelPipeline... 16:22:03.937 ... [tor-http-nio-10] ... [id: 0x058eaaa2] REGISTERED 16:22:03.964 ... [tor-http-nio-10] ... [id: 0x058eaaa2] CONNECT: localhost/127.0.0.1:8080 16:22:04.082 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 - R:YYY] Registering pool release on close event for... 16:22:04.082 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 - R:YYY] Channel connected, now 16 active connections... 16:22:04.082 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 - R:YYY] ACTIVE 16:22:04.082 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 - R:YYY] Handler is being applied: {uri=http:... 16:22:04.567 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 ! R:YYY] Channel closed, now 16 active connections and... 16:22:04.642 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 ! R:YYY] INACTIVE 16:22:04.642 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 ! R:YYY] The connection observed an error reactor.netty.http.client.PrematureCloseException: Connection prematurely closed BEFORE response Client - Read Timeout 121
  94. 16:22:03.936 ... [tor-http-nio-10] ... [id: 0x058eaaa2] Created a new pooled

    channel, now 3 active connections and 0 inactive... 16:22:03.937 ... [tor-http-nio-10] ... [id: 0x058eaaa2] Initialized pipeline DefaultChannelPipeline... 16:22:03.937 ... [tor-http-nio-10] ... [id: 0x058eaaa2] REGISTERED 16:22:03.964 ... [tor-http-nio-10] ... [id: 0x058eaaa2] CONNECT: localhost/127.0.0.1:8080 16:22:04.082 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 - R:YYY] Registering pool release on close event for... 16:22:04.082 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 - R:YYY] Channel connected, now 16 active connections... 16:22:04.082 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 - R:YYY] ACTIVE 16:22:04.082 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 - R:YYY] Handler is being applied: {uri=http:... 16:22:04.567 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 ! R:YYY] Channel closed, now 16 active connections and... 16:22:04.642 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 ! R:YYY] INACTIVE 16:22:04.642 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 ! R:YYY] The connection observed an error reactor.netty.http.client.PrematureCloseException: Connection prematurely closed BEFORE response Client - Read Timeout !??!! 122
  95. 16:22:03.936 ... [tor-http-nio-10] ... [id: 0x058eaaa2] Created a new pooled

    channel, now 3 active connections and 0 inactive... 16:22:03.937 ... [tor-http-nio-10] ... [id: 0x058eaaa2] Initialized pipeline DefaultChannelPipeline... 16:22:03.937 ... [tor-http-nio-10] ... [id: 0x058eaaa2] REGISTERED 16:22:03.964 ... [tor-http-nio-10] ... [id: 0x058eaaa2] CONNECT: localhost/127.0.0.1:8080 16:22:04.082 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 - R:YYY] Registering pool release on close event for... 16:22:04.082 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 - R:YYY] Channel connected, now 16 active connections... 16:22:04.082 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 - R:YYY] ACTIVE 16:22:04.082 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 - R:YYY] Handler is being applied: {uri=http:... 16:22:04.567 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 ! R:YYY] Channel closed, now 16 active connections and... 16:22:04.642 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 ! R:YYY] INACTIVE 16:22:04.642 ... [tor-http-nio-10] ... [id: 0x058eaaa2, L:/127.0.0.1:49908 ! R:YYY] The connection observed an error reactor.netty.http.client.PrematureCloseException: Connection prematurely closed BEFORE response Client - Read Timeout Client port 123
  96. 16:22:04.016 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] New

    http connection, requesting read 16:22:04.017 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Initialized pipeline DefaultChannelPipeline... 16:22:04.099 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Increasing pending responses, now 1 16:22:04.099 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Added encoder [ReadTimeoutHandler] at the... 16:22:04.099 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Handler is being applied: org.springframework.. 16:22:04.106 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] FluxReceive{pending=0, cancelled=false... 16:22:04.178 ... [ctor-http-nio-4] ... [09740dff-3] 500 Server Error for HTTP POST "/echo" io.netty.handler.timeout.ReadTimeoutException: null 16:22:04.235 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Decreasing pending responses, now 0 16:22:04.238 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Last HTTP packet was sent, terminating... 16:22:04.239 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Last HTTP response frame 16:22:04.241 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY ! R:/127.0.0.1:49908] Non Removed handler... Target Server - Read Timeout 124
  97. 16:22:04.016 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] New

    http connection, requesting read 16:22:04.017 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Initialized pipeline DefaultChannelPipeline... 16:22:04.099 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Increasing pending responses, now 1 16:22:04.099 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Added encoder [ReadTimeoutHandler] at the... 16:22:04.099 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Handler is being applied: org.springframework.. 16:22:04.106 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] FluxReceive{pending=0, cancelled=false... 16:22:04.178 ... [ctor-http-nio-4] ... [09740dff-3] 500 Server Error for HTTP POST "/echo" io.netty.handler.timeout.ReadTimeoutException: null 16:22:04.235 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Decreasing pending responses, now 0 16:22:04.238 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Last HTTP packet was sent, terminating... 16:22:04.239 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Last HTTP response frame 16:22:04.241 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY ! R:/127.0.0.1:49908] Non Removed handler... Target Server - Read Timeout Client port 125
  98. 126 16:22:04.016 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908]

    New http connection, requesting read 16:22:04.017 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Initialized pipeline DefaultChannelPipeline... 16:22:04.099 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Increasing pending responses, now 1 16:22:04.099 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Added encoder [ReadTimeoutHandler] at the... 16:22:04.099 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Handler is being applied: org.springframework.. 16:22:04.106 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] FluxReceive{pending=0, cancelled=false... 16:22:04.178 ... [ctor-http-nio-4] ... [09740dff-3] 500 Server Error for HTTP POST "/echo" io.netty.handler.timeout.ReadTimeoutException: null 16:22:04.235 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Decreasing pending responses, now 0 16:22:04.238 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Last HTTP packet was sent, terminating... 16:22:04.239 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Last HTTP response frame 16:22:04.241 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY ! R:/127.0.0.1:49908] Non Removed handler... 6 Target Server - Read Timeout
  99. 16:22:04.016 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] New

    http connection, requesting read 16:22:04.017 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Initialized pipeline DefaultChannelPipeline... 16:22:04.099 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Increasing pending responses, now 1 16:22:04.099 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Added encoder [ReadTimeoutHandler] at the... 16:22:04.099 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Handler is being applied: org.springframework.. 16:22:04.106 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] FluxReceive{pending=0, cancelled=false... 16:22:04.178 ... [ctor-http-nio-4] ... [09740dff-3] 500 Server Error for HTTP POST "/echo" io.netty.handler.timeout.ReadTimeoutException: null 16:22:04.235 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Decreasing pending responses, now 0 16:22:04.238 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Last HTTP packet was sent, terminating... 16:22:04.239 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY - R:/127.0.0.1:49908] Last HTTP response frame 16:22:04.241 ... [ctor-http-nio-4] ... [id: 0x09740dff, L:/YYY ! R:/127.0.0.1:49908] Non Removed handler... Target Server - Read Timeout Read timeout (50ms) 127
  100. Target Server - Keep Alive Timeout Reactor Netty • ReadTimeoutHandler

    (default - no timeout) Tomcat • connectionTimeout (default 20s) • keepAliveTimeout (default == connectionTimeout) Proxy/Loadbalancer • keepAliveTimeout/maxIdleTimeout http://tomcat.apache.org/tomcat-9.0-doc/config/http.html#Standard_Implementation https://netty.io/4.1/api/io/netty/handler/timeout/ReadTimeoutHandler.html 129
  101. Client - Connection Pool • Max idle time • Prefer

    LIFO vs. FIFO leasing strategy 130
  102. Target Server - Upload Limit @Configuration public class WebConfig implements

    WebFluxConfigurer { @Override public void configureHttpMessageCodecs(ServerCodecConfigurer configurer) { configurer.defaultCodecs().maxInMemorySize(512); } } 132
  103. Target Server - Upload Limit @Configuration public class WebConfig implements

    WebFluxConfigurer { @Override public void configureHttpMessageCodecs(ServerCodecConfigurer configurer) { configurer.defaultCodecs().maxInMemorySize(512); } } Max in memory configuration 133
  104. Client - Upload Limit @GetMapping("/remote") public Mono<String> remote() { var

    flux = Flux.just(CONTENT, CONTENT); return webClient.post() .uri(“http://localhost:8080/echo") .body(BodyInserters.fromPublisher(flux, String.class)) .retrieve() .bodyToMono(String.class); } 135
  105. ... [ctor-http-nio-2] ... [id: 0xbbc66538, L:/127.0.0.1:59307 - R:YYY] Channel acquired,

    now 16 active connections… ... [ctor-http-nio-2] ... [id: 0xbbc66538, L:/127.0.0.1:59307 - R:YYY] Handler is being applied: {uri=http://… ... [ctor-http-nio-2] ... [id: 0xbbc66538, L:/127.0.0.1:59307 ! R:YYY] Channel closed, now 15 active connections… ... [ctor-http-nio-2] ... [id: 0xbbc66538, L:/127.0.0.1:59307 ! R:YYY] The connection observed an error reactor.netty.http.client.PrematureCloseException: Connection has been closed BEFORE response, while sending request body Client - Upload Limit 136
  106. ... [ctor-http-nio-2] ... [id: 0xbbc66538, L:/127.0.0.1:59307 - R:YYY] Channel acquired,

    now 16 active connections… ... [ctor-http-nio-2] ... [id: 0xbbc66538, L:/127.0.0.1:59307 - R:YYY] Handler is being applied: {uri=http://… ... [ctor-http-nio-2] ... [id: 0xbbc66538, L:/127.0.0.1:59307 ! R:YYY] Channel closed, now 15 active connections… ... [ctor-http-nio-2] ... [id: 0xbbc66538, L:/127.0.0.1:59307 ! R:YYY] The connection observed an error reactor.netty.http.client.PrematureCloseException: Connection has been closed BEFORE response, while sending request body Client - Upload Limit !??!! 137
  107. ... [ctor-http-nio-2] ... [id: 0xbbc66538, L:/127.0.0.1:59307 - R:YYY] Channel acquired,

    now 16 active connections… ... [ctor-http-nio-2] ... [id: 0xbbc66538, L:/127.0.0.1:59307 - R:YYY] Handler is being applied: {uri=http://… ... [ctor-http-nio-2] ... [id: 0xbbc66538, L:/127.0.0.1:59307 ! R:YYY] Channel closed, now 15 active connections… ... [ctor-http-nio-2] ... [id: 0xbbc66538, L:/127.0.0.1:59307 ! R:YYY] The connection observed an error reactor.netty.http.client.PrematureCloseException: Connection has been closed BEFORE response, while sending request body Client - Upload Limit Client port 138
  108. ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] New http

    connection, requesting read ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Initialized pipeline DefaultChannelPipeline... ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Increasing pending responses, now 1 ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Handler is being applied: org.springframework... ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] FluxReceive{pending=0, cancelled=false, inboundDone=false... ... [ctor-http-nio-7] ... [5b9debd7-6] 500 Server Error for HTTP POST "/echo" org.springframework.core.io.buffer.DataBufferLimitException: Exceeded limit on max bytes to buffer : 512 at org.springframework.core.io.buffer.LimitedDataBufferList.raiseLimitException(LimitedDataBufferList.java:101) Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: Error has been observed at the following site(s): |_ checkpoint ⇢ HTTP POST "/echo" [ExceptionHandlingWebHandler] Stack trace: at org.springframework.core.io.buffer.LimitedDataBufferList.raiseLimitException(LimitedDataBufferList.java:101) ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Decreasing pending responses, now 0 ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Last HTTP packet was sent, terminating the channel ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Last HTTP response frame Target Server - Upload Limit Client port 139
  109. ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] New http

    connection, requesting read ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Initialized pipeline DefaultChannelPipeline... ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Increasing pending responses, now 1 ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Handler is being applied: org.springframework... ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] FluxReceive{pending=0, cancelled=false, inboundDone=false... ... [ctor-http-nio-7] ... [5b9debd7-6] 500 Server Error for HTTP POST "/echo" org.springframework.core.io.buffer.DataBufferLimitException: Exceeded limit on max bytes to buffer : 512 at org.springframework.core.io.buffer.LimitedDataBufferList.raiseLimitException(LimitedDataBufferList.java:101) Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: Error has been observed at the following site(s): |_ checkpoint ⇢ HTTP POST "/echo" [ExceptionHandlingWebHandler] Stack trace: at org.springframework.core.io.buffer.LimitedDataBufferList.raiseLimitException(LimitedDataBufferList.java:101) ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Decreasing pending responses, now 0 ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Last HTTP packet was sent, terminating the channel ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Last HTTP response frame Target Server - Upload Limit 140
  110. ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] New http

    connection, requesting read ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Initialized pipeline DefaultChannelPipeline... ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Increasing pending responses, now 1 ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Handler is being applied: org.springframework... ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] FluxReceive{pending=0, cancelled=false, inboundDone=false... ... [ctor-http-nio-7] ... [5b9debd7-6] 500 Server Error for HTTP POST "/echo" org.springframework.core.io.buffer.DataBufferLimitException: Exceeded limit on max bytes to buffer : 512 at org.springframework.core.io.buffer.LimitedDataBufferList.raiseLimitException(LimitedDataBufferList.java:101) Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: Error has been observed at the following site(s): |_ checkpoint ⇢ HTTP POST "/echo" [ExceptionHandlingWebHandler] Stack trace: at org.springframework.core.io.buffer.LimitedDataBufferList.raiseLimitException(LimitedDataBufferList.java:101) ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Decreasing pending responses, now 0 ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Last HTTP packet was sent, terminating the channel ... [ctor-http-nio-7] ... [id: 0x5b9debd7, L:/YYY - R:/127.0.0.1:59307] Last HTTP response frame Target Server - Upload Limit Max in memory exceeded 141
  111. Client Side - Connection Pool var provider = ConnectionProvider.create("demo", 1);

    var httpClient = HttpClient.create() .wiretap(true); WebClient.builder() .clientConnector(new ReactorClientHttpConnector(httpClient)) .build(); 143
  112. Client Side - Connection Pool var provider = ConnectionProvider.create("demo", 1);

    var httpClient = HttpClient.create() .wiretap(true); WebClient.builder() .clientConnector(new ReactorClientHttpConnector(httpClient)) .build(); Max connections per remote address 144
  113. Client Side - Connection Pool @GetMapping("/remote") public Mono<String> remote() {

    Mono<String> mono1 = webClient.get() .uri("https://example.com") .retrieve() .bodyToMono(String.class); Mono<String> mono2 = webClient.get() .uri("https://httpbin.org/get") .retrieve() .bodyToMono(String.class); return Flux.merge(mono1, mono2).next(); } 145
  114. 146 Client Side - Connection Pool @GetMapping("/remote") public Mono<String> remote()

    { Mono<String> mono1 = webClient.get() .uri("https://example.com") .retrieve() .bodyToMono(String.class); Mono<String> mono2 = webClient.get() .uri("https://httpbin.org/get") .retrieve() .bodyToMono(String.class); return Flux.merge(mono1, mono2).next(); } 6 Need only the first result
  115. 09:59:13.266 ... [ctor-http-nio-3] ... Creating a new [demo] client pool

    ... for [example.com… 09:59:13.272 ... [ctor-http-nio-3] ... [id: 0x233f98cc] Created a new pooled channel, now 1 active connection... 09:59:13.302 ... [ctor-http-nio-3] ... Creating a new [demo] client pool ... for [httpbin.org… 09:59:13.302 ... [ctor-http-nio-3] ... [id: 0xaca6699b] Created a new pooled channel, now 1 active connection... 09:59:13.330 ... [ctor-http-nio-3] ... [id: 0x233f98cc] CONNECT: example.com... 09:59:13.331 ... [ctor-http-nio-3] ... [id: 0xaca6699b] CONNECT: httpbin.org... Client Side - Connection Pool 147
  116. 09:59:13.266 ... [ctor-http-nio-3] ... Creating a new [demo] client pool

    ... for [example.com… 09:59:13.272 ... [ctor-http-nio-3] ... [id: 0x233f98cc] Created a new pooled channel, now 1 active connection... 09:59:13.302 ... [ctor-http-nio-3] ... Creating a new [demo] client pool ... for [httpbin.org… 09:59:13.302 ... [ctor-http-nio-3] ... [id: 0xaca6699b] Created a new pooled channel, now 1 active connection... 09:59:13.330 ... [ctor-http-nio-3] ... [id: 0x233f98cc] CONNECT: example.com... 09:59:13.331 ... [ctor-http-nio-3] ... [id: 0xaca6699b] CONNECT: httpbin.org... Client Side - Connection Pool Connection Pool per remote address 148
  117. 09:59:13.266 ... [ctor-http-nio-3] ... Creating a new [demo] client pool

    ... for [example.com… 09:59:13.272 ... [ctor-http-nio-3] ... [id: 0x233f98cc] Created a new pooled channel, now 1 active connection... 09:59:13.302 ... [ctor-http-nio-3] ... Creating a new [demo] client pool ... for [httpbin.org… 09:59:13.302 ... [ctor-http-nio-3] ... [id: 0xaca6699b] Created a new pooled channel, now 1 active connection... 09:59:13.330 ... [ctor-http-nio-3] ... [id: 0x233f98cc] CONNECT: example.com... 09:59:13.331 ... [ctor-http-nio-3] ... [id: 0xaca6699b] CONNECT: httpbin.org... Client Side - Connection Pool Connection Pool per remote address 149
  118. 09:59:13.958 ... [ctor-http-nio-3] ... [id: 0x233f98cc, L:/XXX - R:example.com/...] CLOSE

    09:59:13.962 ... [ctor-http-nio-3] ... [id: 0x233f98cc, L:/XXX ! R:example.com/...] Channel closed, now 0 active connections and 0 inactive connections 09:59:13.963 ... [ctor-http-nio-3] ... [id: 0xaca6699b, L:/XXX - R:httpbin.org/...] Releasing channel 09:59:13.964 ... [ctor-http-nio-3] ... [id: 0xaca6699b, L:/XXX - R:httpbin.org/...] Channel cleaned, now 0 active connections and 1 inactive connections Client Side - Connection Pool 150
  119. 09:59:13.958 ... [ctor-http-nio-3] ... [id: 0x233f98cc, L:/XXX - R:example.com/...] CLOSE

    09:59:13.962 ... [ctor-http-nio-3] ... [id: 0x233f98cc, L:/XXX ! R:example.com/...] Channel closed, now 0 active connections and 0 inactive connections 09:59:13.963 ... [ctor-http-nio-3] ... [id: 0xaca6699b, L:/XXX - R:httpbin.org/...] Releasing channel 09:59:13.964 ... [ctor-http-nio-3] ... [id: 0xaca6699b, L:/XXX - R:httpbin.org/...] Channel cleaned, now 0 active connections and 1 inactive connections Client Side - Connection Pool Connection returned to the pool 151
  120. 09:59:13.958 ... [ctor-http-nio-3] ... [id: 0x233f98cc, L:/XXX - R:example.com/...] CLOSE

    09:59:13.962 ... [ctor-http-nio-3] ... [id: 0x233f98cc, L:/XXX ! R:example.com/...] Channel closed, now 0 active connections and 0 inactive connections 09:59:13.963 ... [ctor-http-nio-3] ... [id: 0xaca6699b, L:/XXX - R:httpbin.org/...] Releasing channel 09:59:13.964 ... [ctor-http-nio-3] ... [id: 0xaca6699b, L:/XXX - R:httpbin.org/...] Channel cleaned, now 0 active connections and 1 inactive connections Client Side - Connection Pool Connection closed 152
  121. Key Takeaways • Know your infrastructure and its configuration •

    Know how to configure your solution • Extensive testing for memory leaks, connection closed etc. • Your friends to ask for help ◦ TCP dump ◦ E2E traceability 154
  122. Safe Harbor Statement The following is intended to outline the

    general direction of VMware's offerings. It is intended for information purposes only and may not be incorporated into any contract. Any information regarding pre-release of VMware offerings, future updates or other planned modifications is subject to ongoing evaluation by VMware and is subject to change. This information is provided without warranty or any kind, express or implied, and is not a commitment to deliver any material, code, or functionality, and should not be relied upon in making purchasing decisions regarding VMware's offerings. These purchasing decisions should only be based on features currently available. The development, release, and timing of any features or functionality described for VMware's offerings in this presentation remain at the sole discretion of Pivotal. Pivotal has no obligation to update forward looking information in this presentation. 156