Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

SSLEngine closed already; nested exception is io.netty.handler.ssl.SslClosedEngineException #2509

Closed
anmol1vw13 opened this issue Sep 28, 2022 · 11 comments · Fixed by #2518
Closed
Labels
type/bug A general bug
Milestone

Comments

@anmol1vw13
Copy link

anmol1vw13 commented Sep 28, 2022

I'm facing the following SSLEngine issue with negligible load.

The connection observed an error io.netty.handler.ssl.SslClosedEngineException: SSLEngine closed already

Stack:
spring-boot-starter-parent 2.5.6
spring-boot-starter-webflux 2.5.6

Here's the trace

[id:31e016c9-2, L:/x.xx.xxx.xx:56499 - R:xxx.payu.in/xy.xyy.xyyy.xyy:443] The connection observed an error
io.netty.handler.ssl.SslClosedEngineException: SSLEngine closed already
    at io.netty.handler.ssl.SslHandler.wrap(SslHandler.java:861)
    at io.netty.handler.ssl.SslHandler.wrapAndFlush(SslHandler.java:800)
    at io.netty.handler.ssl.SslHandler.flush(SslHandler.java:781)
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750)
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:742)
    at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:728)
    at io.netty.handler.logging.LoggingHandler.flush(LoggingHandler.java:304)
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750)
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:742)
    at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:728)
    at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.flush(CombinedChannelDuplexHandler.java:531)
    at io.netty.channel.ChannelOutboundHandlerAdapter.flush(ChannelOutboundHandlerAdapter.java:125)
    at io.netty.channel.CombinedChannelDuplexHandler.flush(CombinedChannelDuplexHandler.java:356)
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750)
    at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:765)
    at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:790)
    at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:758)
    at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:808)
    at io.netty.channel.DefaultChannelPipeline.writeAndFlush(DefaultChannelPipeline.java:1025)
    at io.netty.channel.AbstractChannel.writeAndFlush(AbstractChannel.java:306)
    at reactor.netty.http.HttpOperations.lambda$send$0(HttpOperations.java:128)
    at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:125)
    at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onNext(ScopePassingSpanSubscriber.java:90)
    at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:127)
    at reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2398)
    at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.request(FluxMapFuseable.java:169)
    at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.request(ScopePassingSpanSubscriber.java:76)
    at reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:110)
    at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onSubscribe(ScopePassingSpanSubscriber.java:69)
    at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onSubscribe(FluxMapFuseable.java:96)
    at reactor.core.publisher.MonoJust.subscribe(MonoJust.java:55)
    at reactor.core.publisher.Mono.subscribe(Mono.java:4338)
    at reactor.core.publisher.FluxConcatIterable$ConcatIterableSubscriber.onComplete(FluxConcatIterable.java:147)
    at reactor.core.publisher.FluxConcatIterable.subscribe(FluxConcatIterable.java:60)
    at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64)
    at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:157)
    at reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2398)
    at reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:110)
    at reactor.core.publisher.MonoJust.subscribe(MonoJust.java:55)
    at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64)
    at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:157)
    at reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2398)
    at reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:110)
    at reactor.core.publisher.MonoJust.subscribe(MonoJust.java:55)
    at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64)
    at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:52)
    at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64)
    at reactor.netty.http.client.HttpClientConnect$HttpIOHandlerObserver.onStateChange(HttpClientConnect.java:424)
    at reactor.netty.ReactorNetty$CompositeConnectionObserver.onStateChange(ReactorNetty.java:654)
    at reactor.netty.resources.DefaultPooledConnectionProvider$DisposableAcquire.run(DefaultPooledConnectionProvider.java:287)
    at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
    at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
    at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
    at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
    at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.base/java.lang.Thread.run(Unknown Source)

The web client bean that is used is as shown below

@Bean
    public WebClient apiClient() {
        HttpClient httpClient = HttpClient.create()
            .wiretap("reactor.netty.http.client.HttpClient", LogLevel.DEBUG, AdvancedByteBufFormat.TEXTUAL)
            .responseTimeout(Duration.of(5, ChronoUnit.SECONDS));

        return WebClient.builder()
            .clientConnector(new ReactorClientHttpConnector(httpClient))
            .build();
    }

A sample API call using webclient

String data = apiClient.post().uri(url)
            .contentType(MediaType.APPLICATION_FORM_URLENCODED)
            .body(BodyInserters.fromFormData(formData))
            .retrieve()
            .bodyToMono(String.class)
            .block();

Dependency tree

[INFO] +- org.springframework.boot:spring-boot-starter-webflux:jar:2.5.6:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-json:jar:2.5.6:compile
[INFO] |  |  +- com.fasterxml.jackson.datatype:jackson-datatype-jdk8:jar:2.12.5:compile
[INFO] |  |  +- com.fasterxml.jackson.datatype:jackson-datatype-jsr310:jar:2.12.5:compile
[INFO] |  |  \- com.fasterxml.jackson.module:jackson-module-parameter-names:jar:2.12.5:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-reactor-netty:jar:2.5.6:compile
[INFO] |  |  \- io.projectreactor.netty:reactor-netty-http:jar:1.0.12:compile
[INFO] |  |     +- io.netty:netty-codec-http2:jar:4.1.69.Final:compile
[INFO] |  |     +- io.netty:netty-resolver-dns:jar:4.1.69.Final:compile
[INFO] |  |     |  \- io.netty:netty-codec-dns:jar:4.1.69.Final:compile
[INFO] |  |     +- io.netty:netty-resolver-dns-native-macos:jar:osx-x86_64:4.1.69.Final:compile
[INFO] |  |     |  \- io.netty:netty-transport-native-unix-common:jar:4.1.69.Final:compile
[INFO] |  |     +- io.netty:netty-transport-native-epoll:jar:linux-x86_64:4.1.69.Final:compile
[INFO] |  |     \- io.projectreactor.netty:reactor-netty-core:jar:1.0.12:compile
[INFO] |  |        \- io.netty:netty-handler-proxy:jar:4.1.69.Final:compile
[INFO] |  |           \- io.netty:netty-codec-socks:jar:4.1.69.Final:compile
[INFO] |  +- org.springframework:spring-web:jar:5.3.12:compile
[INFO] |  |  \- org.springframework:spring-beans:jar:5.3.12:compile
[INFO] |  \- org.springframework:spring-webflux:jar:5.3.12:compile
[INFO] +- org.springframework.cloud:spring-cloud-gcp-starter-logging:jar:1.2.8.RELEASE:compile
[INFO] |  +- org.springframework.cloud:spring-cloud-gcp-starter:jar:1.2.8.RELEASE:compile
[INFO] |  |  +- org.springframework.cloud:spring-cloud-gcp-core:jar:1.2.8.RELEASE:compile
[INFO] |  |  \- org.springframework.cloud:spring-cloud-gcp-autoconfigure:jar:1.2.8.RELEASE:compile
[INFO] |  +- org.springframework.cloud:spring-cloud-gcp-logging:jar:1.2.8.RELEASE:compile
[INFO] |  |  +- ch.qos.logback.contrib:logback-json-classic:jar:0.1.5:compile
[INFO] |  |  |  +- ch.qos.logback:logback-classic:jar:1.2.6:compile
[INFO] |  |  |  \- ch.qos.logback.contrib:logback-json-core:jar:0.1.5:compile
[INFO] |  |  \- com.google.cloud:google-cloud-logging-logback:jar:0.119.0-alpha:compile
[INFO] |  |     +- ch.qos.logback:logback-core:jar:1.2.6:compile
[INFO] |  |     +- com.google.cloud:google-cloud-logging:jar:2.0.1:compile
[INFO] |  |     \- com.google.api.grpc:proto-google-cloud-logging-v2:jar:0.85.1:compile
[INFO] |  \- org.slf4j:slf4j-api:jar:1.7.32:compile
[INFO] +- org.springframework.cloud:spring-cloud-starter-sleuth:jar:2.2.8.RELEASE:compile
[INFO] |  +- org.springframework.cloud:spring-cloud-starter:jar:3.0.3:compile
[INFO] |  |  +- org.springframework.cloud:spring-cloud-context:jar:3.0.3:compile
[INFO] |  |  |  \- org.springframework.security:spring-security-crypto:jar:5.5.3:compile
[INFO] |  |  +- org.springframework.cloud:spring-cloud-commons:jar:3.0.3:compile
[INFO] |  |  \- org.springframework.security:spring-security-rsa:jar:1.0.10.RELEASE:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-aop:jar:2.5.6:compile
[INFO] |  |  \- org.aspectj:aspectjweaver:jar:1.9.7:compile
[INFO] |  \- org.springframework.cloud:spring-cloud-sleuth-core:jar:2.2.8.RELEASE:compile
[INFO] |     +- org.aspectj:aspectjrt:jar:1.9.7:compile
[INFO] |     +- io.zipkin.brave:brave:jar:5.13.2:compile
[INFO] |     |  \- io.zipkin.reporter2:zipkin-reporter-brave:jar:2.16.1:compile
[INFO] |     +- io.zipkin.brave:brave-context-slf4j:jar:5.13.2:compile
[INFO] |     +- io.zipkin.brave:brave-instrumentation-messaging:jar:5.13.2:compile
[INFO] |     +- io.zipkin.brave:brave-instrumentation-rpc:jar:5.13.2:compile
[INFO] |     +- io.zipkin.brave:brave-instrumentation-spring-web:jar:5.13.2:compile
[INFO] |     |  \- io.zipkin.brave:brave-instrumentation-http:jar:5.13.2:compile
[INFO] |     +- io.zipkin.brave:brave-instrumentation-spring-rabbit:jar:5.13.2:compile
[INFO] |     +- io.zipkin.brave:brave-instrumentation-kafka-clients:jar:5.13.2:compile
[INFO] |     +- io.zipkin.brave:brave-instrumentation-kafka-streams:jar:5.13.2:compile
[INFO] |     +- io.zipkin.brave:brave-instrumentation-httpclient:jar:5.13.2:compile
[INFO] |     +- io.zipkin.brave:brave-instrumentation-httpasyncclient:jar:5.13.2:compile
[INFO] |     +- io.zipkin.brave:brave-instrumentation-spring-webmvc:jar:5.13.2:compile
[INFO] |     |  \- io.zipkin.brave:brave-instrumentation-servlet:jar:5.13.2:compile
[INFO] |     +- io.zipkin.brave:brave-instrumentation-jms:jar:5.13.2:compile
[INFO] |     \- io.zipkin.reporter2:zipkin-reporter-metrics-micrometer:jar:2.16.1:compile
[INFO] |        \- io.zipkin.reporter2:zipkin-reporter:jar:2.16.1:compile
[INFO] |           \- io.zipkin.zipkin2:zipkin:jar:2.23.0:compile
[INFO] +- org.springframework.boot:spring-boot-starter:jar:2.5.6:compile
[INFO] |  +- org.springframework.boot:spring-boot:jar:2.5.6:compile
[INFO] |  +- org.springframework.boot:spring-boot-autoconfigure:jar:2.5.6:compile
[INFO] |  +- jakarta.annotation:jakarta.annotation-api:jar:1.3.5:compile
[INFO] |  +- org.springframework:spring-core:jar:5.3.12:compile
[INFO] |  |  \- org.springframework:spring-jcl:jar:5.3.12:compile
[INFO] |  \- org.yaml:snakeyaml:jar:1.28:compile
[INFO] +- org.springframework.boot:spring-boot-starter-test:jar:2.5.6:test
[INFO] |  +- org.springframework.boot:spring-boot-test:jar:2.5.6:test
[INFO] |  +- org.springframework.boot:spring-boot-test-autoconfigure:jar:2.5.6:test
[INFO] |  +- com.jayway.jsonpath:json-path:jar:2.5.0:test
[INFO] |  |  \- net.minidev:json-smart:jar:2.4.7:test
[INFO] |  |     \- net.minidev:accessors-smart:jar:2.4.7:test
[INFO] |  +- jakarta.xml.bind:jakarta.xml.bind-api:jar:2.3.3:compile
[INFO] |  |  \- jakarta.activation:jakarta.activation-api:jar:1.2.2:compile
[INFO] |  +- org.assertj:assertj-core:jar:3.19.0:test
[INFO] |  +- org.hamcrest:hamcrest:jar:2.2:compile
[INFO] |  +- org.junit.jupiter:junit-jupiter:jar:5.7.2:test
[INFO] |  |  +- org.junit.jupiter:junit-jupiter-params:jar:5.7.2:test
[INFO] |  |  \- org.junit.jupiter:junit-jupiter-engine:jar:5.7.2:test
[INFO] |  |     \- org.junit.platform:junit-platform-engine:jar:1.7.2:test
[INFO] |  +- org.mockito:mockito-core:jar:3.9.0:compile
[INFO] |  |  +- net.bytebuddy:byte-buddy:jar:1.10.22:compile
[INFO] |  |  +- net.bytebuddy:byte-buddy-agent:jar:1.10.22:compile
[INFO] |  |  \- org.objenesis:objenesis:jar:3.2:compile
[INFO] |  +- org.mockito:mockito-junit-jupiter:jar:3.9.0:test
[INFO] |  +- org.skyscreamer:jsonassert:jar:1.5.0:test
[INFO] |  |  \- com.vaadin.external.google:android-json:jar:0.0.20131108.vaadin1:test
[INFO] |  +- org.springframework:spring-test:jar:5.3.12:test
[INFO] |  \- org.xmlunit:xmlunit-core:jar:2.8.3:test
[INFO] +- org.springframework.boot:spring-boot-starter-web:jar:2.5.6:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-tomcat:jar:2.5.6:compile
[INFO] |  |  +- org.apache.tomcat.embed:tomcat-embed-core:jar:9.0.54:compile
[INFO] |  |  +- org.apache.tomcat.embed:tomcat-embed-el:jar:9.0.54:compile
[INFO] |  |  \- org.apache.tomcat.embed:tomcat-embed-websocket:jar:9.0.54:compile
[INFO] |  \- org.springframework:spring-webmvc:jar:5.3.12:compile
[INFO] |     \- org.springframework:spring-expression:jar:5.3.12:compile
[INFO] +- org.springdoc:springdoc-openapi-ui:jar:1.5.10:compile
[INFO] |  +- org.springdoc:springdoc-openapi-webmvc-core:jar:1.5.10:compile
[INFO] |  |  \- org.springdoc:springdoc-openapi-common:jar:1.5.10:compile
[INFO] |  |     +- io.swagger.core.v3:swagger-models:jar:2.1.10:compile
[INFO] |  |     +- io.swagger.core.v3:swagger-annotations:jar:2.1.10:compile
[INFO] |  |     +- io.swagger.core.v3:swagger-integration:jar:2.1.10:compile
[INFO] |  |     |  \- io.swagger.core.v3:swagger-core:jar:2.1.10:compile
[INFO] |  |     |     +- com.fasterxml.jackson.dataformat:jackson-dataformat-yaml:jar:2.12.5:compile
[INFO] |  |     |     \- jakarta.validation:jakarta.validation-api:jar:2.0.2:compile
[INFO] |  |     \- io.github.classgraph:classgraph:jar:4.8.69:compile
[INFO] |  +- org.webjars:swagger-ui:jar:3.51.1:compile
[INFO] |  \- org.webjars:webjars-locator-core:jar:0.46:compile
[INFO] +- org.springframework.boot:spring-boot-devtools:jar:2.5.6:compile
[INFO] +- org.springframework.boot:spring-boot-starter-data-jpa:jar:2.5.6:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-jdbc:jar:2.5.6:compile
[INFO] |  |  \- org.springframework:spring-jdbc:jar:5.3.12:compile
[INFO] |  +- jakarta.transaction:jakarta.transaction-api:jar:1.3.3:compile
[INFO] |  +- jakarta.persistence:jakarta.persistence-api:jar:2.2.3:compile
[INFO] |  +- org.hibernate:hibernate-core:jar:5.4.32.Final:compile
[INFO] |  |  +- org.jboss.logging:jboss-logging:jar:3.4.2.Final:compile
[INFO] |  |  +- org.javassist:javassist:jar:3.27.0-GA:compile
[INFO] |  |  +- antlr:antlr:jar:2.7.7:compile
[INFO] |  |  +- org.jboss:jandex:jar:2.2.3.Final:compile
[INFO] |  |  +- com.fasterxml:classmate:jar:1.5.1:compile
[INFO] |  |  +- org.dom4j:dom4j:jar:2.1.3:compile
[INFO] |  |  +- org.hibernate.common:hibernate-commons-annotations:jar:5.1.2.Final:compile
[INFO] |  |  \- org.glassfish.jaxb:jaxb-runtime:jar:2.3.5:compile
[INFO] |  |     +- org.glassfish.jaxb:txw2:jar:2.3.5:compile
[INFO] |  |     +- com.sun.istack:istack-commons-runtime:jar:3.0.12:compile
[INFO] |  |     \- com.sun.activation:jakarta.activation:jar:1.2.2:runtime
[INFO] |  +- org.springframework.data:spring-data-jpa:jar:2.5.6:compile
[INFO] |  |  +- org.springframework.data:spring-data-commons:jar:2.5.6:compile
[INFO] |  |  \- org.springframework:spring-orm:jar:5.3.12:compile
[INFO] |  \- org.springframework:spring-aspects:jar:5.3.12:compile
[INFO] +- org.springframework.boot:spring-boot-starter-security:jar:2.5.6:compile
[INFO] |  +- org.springframework:spring-aop:jar:5.3.12:compile
[INFO] |  +- org.springframework.security:spring-security-config:jar:5.5.3:compile
[INFO] |  |  \- org.springframework.security:spring-security-core:jar:5.5.3:compile
[INFO] |  \- org.springframework.security:spring-security-web:jar:5.5.3:compile
[INFO] +- org.springframework.cloud:spring-cloud-gcp-starter-pubsub:jar:1.2.8.RELEASE:compile
[INFO] |  \- org.springframework.cloud:spring-cloud-gcp-pubsub:jar:1.2.8.RELEASE:compile
[INFO] |     \- com.google.cloud:google-cloud-pubsub:jar:1.110.1:compile
[INFO] |        \- com.google.api.grpc:proto-google-cloud-pubsub-v1:jar:1.92.1:compile
[INFO] +- org.springframework.integration:spring-integration-core:jar:5.5.5:compile
[INFO] |  +- org.springframework:spring-context:jar:5.3.12:compile
[INFO] |  +- org.springframework:spring-messaging:jar:5.3.12:compile
[INFO] |  +- org.springframework:spring-tx:jar:5.3.12:compile
[INFO] |  +- org.springframework.retry:spring-retry:jar:1.3.1:compile
[INFO] |  |  \- javax.annotation:javax.annotation-api:jar:1.3.2:compile
[INFO] |  \- io.projectreactor:reactor-core:jar:3.4.11:compile
[INFO] |     \- org.reactivestreams:reactive-streams:jar:1.0.3:compile
[INFO] +- com.zaxxer:HikariCP:jar:4.0.3:compile
[INFO] +- org.postgresql:postgresql:jar:42.2.23:compile
[INFO] |  \- org.checkerframework:checker-qual:jar:3.5.0:runtime
[INFO] +- com.h2database:h2:jar:1.4.200:runtime
[INFO] +- org.projectlombok:lombok:jar:1.18.20:compile (optional)
[INFO] +- io.jsonwebtoken:jjwt:jar:0.9.0:compile
[INFO] +- org.testcontainers:testcontainers:jar:1.15.1:test
[INFO] |  +- junit:junit:jar:4.13.2:compile
[INFO] |  |  \- org.hamcrest:hamcrest-core:jar:2.2:compile
[INFO] |  +- org.apache.commons:commons-compress:jar:1.20:test
[INFO] |  +- org.rnorth.duct-tape:duct-tape:jar:1.0.8:test
[INFO] |  +- org.rnorth.visible-assertions:visible-assertions:jar:2.1.2:test
[INFO] |  |  \- net.java.dev.jna:jna:jar:5.2.0:test
[INFO] |  +- com.github.docker-java:docker-java-api:jar:3.2.7:test
[INFO] |  \- com.github.docker-java:docker-java-transport-zerodep:jar:3.2.7:test
[INFO] |     \- com.github.docker-java:docker-java-transport:jar:3.2.7:test
[INFO] +- org.testcontainers:junit-jupiter:jar:1.15.1:test
[INFO] |  \- org.junit.jupiter:junit-jupiter-api:jar:5.7.2:test
[INFO] |     +- org.apiguardian:apiguardian-api:jar:1.1.0:test
[INFO] |     +- org.opentest4j:opentest4j:jar:1.2.0:test
[INFO] |     \- org.junit.platform:junit-platform-commons:jar:1.7.2:test
[INFO] +- org.mockito:mockito-inline:jar:4.2.0:test
[INFO] +- org.testcontainers:postgresql:jar:1.16.3:test
[INFO] |  \- org.testcontainers:jdbc:jar:1.16.3:test
[INFO] |     \- org.testcontainers:database-commons:jar:1.16.3:test
[INFO] +- com.turkraft:spring-filter:jar:2.0.1:compile
[INFO] |  \- org.apache.commons:commons-lang3:jar:3.12.0:compile
[INFO] +- org.apache.commons:commons-math3:jar:3.6.1:compile
[INFO] +- com.googlecode.json-simple:json-simple:jar:1.1.1:compile
[INFO] +- com.squareup.okhttp3:okhttp:jar:4.0.1:test
[INFO] |  +- com.squareup.okio:okio:jar:2.2.2:test
[INFO] |  \- org.jetbrains.kotlin:kotlin-stdlib:jar:1.5.31:test
[INFO] |     +- org.jetbrains:annotations:jar:13.0:test
[INFO] |     \- org.jetbrains.kotlin:kotlin-stdlib-common:jar:1.5.31:test
[INFO] +- com.squareup.okhttp3:mockwebserver:jar:4.0.1:test
[INFO] +- org.codehaus.janino:janino:jar:3.1.6:compile
[INFO] |  \- org.codehaus.janino:commons-compiler:jar:3.1.6:compile
[INFO] +- com.google.firebase:firebase-admin:jar:7.3.0:compile
[INFO] |  +- com.google.api-client:google-api-client:jar:1.31.4:compile
[INFO] |  |  +- com.google.oauth-client:google-oauth-client:jar:1.31.5:compile
[INFO] |  |  +- com.google.http-client:google-http-client-gson:jar:1.39.2:compile
[INFO] |  |  +- com.google.http-client:google-http-client-apache-v2:jar:1.39.2:compile
[INFO] |  |  +- org.apache.httpcomponents:httpcore:jar:4.4.14:compile
[INFO] |  |  \- org.apache.httpcomponents:httpclient:jar:4.5.13:compile
[INFO] |  +- com.google.api-client:google-api-client-gson:jar:1.31.4:compile
[INFO] |  +- com.google.http-client:google-http-client:jar:1.35.0:compile
[INFO] |  |  +- com.google.code.findbugs:jsr305:jar:3.0.2:compile
[INFO] |  |  +- com.google.j2objc:j2objc-annotations:jar:1.3:compile
[INFO] |  |  +- io.opencensus:opencensus-api:jar:0.24.0:compile
[INFO] |  |  \- io.opencensus:opencensus-contrib-http-util:jar:0.24.0:compile
[INFO] |  +- com.google.api:api-common:jar:1.9.2:compile
[INFO] |  |  \- com.google.auto.value:auto-value-annotations:jar:1.7.2:compile
[INFO] |  +- com.google.auth:google-auth-library-oauth2-http:jar:0.20.0:compile
[INFO] |  |  +- com.google.auth:google-auth-library-credentials:jar:0.20.0:compile
[INFO] |  |  \- com.google.http-client:google-http-client-jackson2:jar:1.34.0:compile
[INFO] |  +- com.google.cloud:google-cloud-storage:jar:1.110.0:compile
[INFO] |  |  +- com.google.guava:failureaccess:jar:1.0.1:compile
[INFO] |  |  +- com.google.guava:listenablefuture:jar:9999.0-empty-to-avoid-conflict-with-guava:compile
[INFO] |  |  +- org.checkerframework:checker-compat-qual:jar:2.5.5:compile
[INFO] |  |  +- com.google.errorprone:error_prone_annotations:jar:2.3.4:compile
[INFO] |  |  +- com.google.apis:google-api-services-storage:jar:v1-rev20200430-1.30.9:compile
[INFO] |  |  +- com.google.code.gson:gson:jar:2.8.8:compile
[INFO] |  |  +- com.google.cloud:google-cloud-core:jar:1.93.6:compile
[INFO] |  |  +- com.google.api.grpc:proto-google-common-protos:jar:1.18.0:compile
[INFO] |  |  +- com.google.cloud:google-cloud-core-http:jar:1.93.6:compile
[INFO] |  |  +- com.google.http-client:google-http-client-appengine:jar:1.35.0:compile
[INFO] |  |  +- com.google.api:gax-httpjson:jar:0.74.0:compile
[INFO] |  |  +- com.google.api:gax:jar:1.57.0:compile
[INFO] |  |  +- io.grpc:grpc-context:jar:1.30.0:compile
[INFO] |  |  +- com.google.api.grpc:proto-google-iam-v1:jar:0.13.0:compile
[INFO] |  |  +- com.google.protobuf:protobuf-java:jar:3.12.2:compile
[INFO] |  |  +- com.google.protobuf:protobuf-java-util:jar:3.12.2:compile
[INFO] |  |  \- org.threeten:threetenbp:jar:1.4.4:compile
[INFO] |  +- com.google.cloud:google-cloud-firestore:jar:1.35.0:compile
[INFO] |  |  +- com.google.cloud:google-cloud-core-grpc:jar:1.93.6:compile
[INFO] |  |  +- io.grpc:grpc-core:jar:1.30.0:compile
[INFO] |  |  +- com.google.android:annotations:jar:4.1.1.4:runtime
[INFO] |  |  +- io.perfmark:perfmark-api:jar:0.19.0:runtime
[INFO] |  |  +- commons-logging:commons-logging:jar:1.2:compile
[INFO] |  |  +- commons-codec:commons-codec:jar:1.15:compile
[INFO] |  |  +- com.google.api.grpc:proto-google-cloud-firestore-admin-v1:jar:1.35.0:compile
[INFO] |  |  +- com.google.api.grpc:proto-google-cloud-firestore-v1:jar:1.35.0:compile
[INFO] |  |  +- com.google.api.grpc:proto-google-cloud-firestore-v1beta1:jar:0.88.0:compile
[INFO] |  |  +- io.opencensus:opencensus-contrib-grpc-util:jar:0.24.0:compile
[INFO] |  |  +- io.grpc:grpc-protobuf:jar:1.30.0:compile
[INFO] |  |  +- io.grpc:grpc-protobuf-lite:jar:1.30.0:compile
[INFO] |  |  +- org.codehaus.mojo:animal-sniffer-annotations:jar:1.18:runtime
[INFO] |  |  +- io.grpc:grpc-api:jar:1.30.0:compile
[INFO] |  |  +- com.google.api:gax-grpc:jar:1.57.0:compile
[INFO] |  |  +- io.grpc:grpc-auth:jar:1.30.0:compile
[INFO] |  |  +- io.grpc:grpc-netty-shaded:jar:1.30.0:compile
[INFO] |  |  +- io.grpc:grpc-alts:jar:1.30.0:compile
[INFO] |  |  +- io.grpc:grpc-grpclb:jar:1.30.0:compile
[INFO] |  |  +- org.conscrypt:conscrypt-openjdk-uber:jar:2.2.1:compile
[INFO] |  |  \- io.grpc:grpc-stub:jar:1.30.0:compile
[INFO] |  +- com.google.guava:guava:jar:29.0-android:compile
[INFO] |  +- io.netty:netty-codec-http:jar:4.1.69.Final:compile
[INFO] |  |  +- io.netty:netty-common:jar:4.1.69.Final:compile
[INFO] |  |  +- io.netty:netty-buffer:jar:4.1.69.Final:compile
[INFO] |  |  \- io.netty:netty-codec:jar:4.1.69.Final:compile
[INFO] |  +- io.netty:netty-handler:jar:4.1.69.Final:compile
[INFO] |  |  \- io.netty:netty-resolver:jar:4.1.69.Final:compile
[INFO] |  \- io.netty:netty-transport:jar:4.1.69.Final:compile
[INFO] +- net.ttddyy:datasource-proxy:jar:1.8:compile
[INFO] +- com.vladmihalcea:hibernate-types-55:jar:2.14.0:compile
[INFO] |  \- com.fasterxml.jackson.module:jackson-module-jaxb-annotations:jar:2.12.5:compile
[INFO] +- org.springframework.boot:spring-boot-starter-thymeleaf:jar:2.5.6:compile
[INFO] |  +- org.thymeleaf:thymeleaf-spring5:jar:3.0.12.RELEASE:compile
[INFO] |  |  \- org.thymeleaf:thymeleaf:jar:3.0.12.RELEASE:compile
[INFO] |  |     +- org.attoparser:attoparser:jar:2.0.5.RELEASE:compile
[INFO] |  |     \- org.unbescape:unbescape:jar:1.1.6.RELEASE:compile
[INFO] |  \- org.thymeleaf.extras:thymeleaf-extras-java8time:jar:3.0.4.RELEASE:compile
[INFO] +- com.itextpdf:kernel:jar:7.2.1:compile
[INFO] |  +- com.itextpdf:io:jar:7.2.1:compile
[INFO] |  |  \- com.itextpdf:commons:jar:7.2.1:compile
[INFO] |  +- org.bouncycastle:bcpkix-jdk15on:jar:1.69:compile
[INFO] |  |  \- org.bouncycastle:bcutil-jdk15on:jar:1.69:compile
[INFO] |  \- org.bouncycastle:bcprov-jdk15on:jar:1.69:compile
[INFO] +- com.itextpdf:html2pdf:jar:4.0.2:compile
[INFO] |  +- com.itextpdf:forms:jar:7.2.2:compile
[INFO] |  +- com.itextpdf:layout:jar:7.2.2:compile
[INFO] |  \- com.itextpdf:svg:jar:7.2.2:compile
[INFO] |     \- com.itextpdf:styled-xml-parser:jar:7.2.2:compile
[INFO] +- com.google.cloud.sql:postgres-socket-factory:jar:1.1.0:compile
[INFO] |  +- com.google.cloud.sql:jdbc-socket-factory-core:jar:1.1.0:compile
[INFO] |  |  \- com.google.apis:google-api-services-sqladmin:jar:v1beta4-rev20190827-1.30.1:compile
[INFO] |  +- com.github.jnr:jnr-unixsocket:jar:0.38.0:compile
[INFO] |  |  +- com.github.jnr:jnr-ffi:jar:2.2.0:compile
[INFO] |  |  |  +- com.github.jnr:jffi:jar:1.3.0:compile
[INFO] |  |  |  +- com.github.jnr:jffi:jar:native:1.3.0:runtime
[INFO] |  |  |  +- org.ow2.asm:asm-commons:jar:7.1:compile
[INFO] |  |  |  +- com.github.jnr:jnr-a64asm:jar:1.0.0:compile
[INFO] |  |  |  \- com.github.jnr:jnr-x86asm:jar:1.0.2:compile
[INFO] |  |  +- com.github.jnr:jnr-constants:jar:0.10.0:compile
[INFO] |  |  +- com.github.jnr:jnr-enxio:jar:0.32.0:compile
[INFO] |  |  \- com.github.jnr:jnr-posix:jar:3.1.0:compile
[INFO] |  \- org.ow2.asm:asm-util:jar:8.0.1:compile
[INFO] |     +- org.ow2.asm:asm:jar:8.0.1:compile
[INFO] |     +- org.ow2.asm:asm-tree:jar:8.0.1:compile
[INFO] |     \- org.ow2.asm:asm-analysis:jar:8.0.1:compile
[INFO] +- org.apache.commons:commons-csv:jar:1.9.0:compile
[INFO] +- com.sendgrid:sendgrid-java:jar:4.0.1:compile
[INFO] |  +- com.sendgrid:java-http-client:jar:4.1.0:compile
[INFO] |  \- com.fasterxml.jackson.core:jackson-annotations:jar:2.12.5:compile
[INFO] +- org.liquibase:liquibase-core:jar:4.9.1:compile
[INFO] |  \- javax.xml.bind:jaxb-api:jar:2.3.1:compile
[INFO] |     \- javax.activation:javax.activation-api:jar:1.2.0:compile
[INFO] +- com.fasterxml.jackson.dataformat:jackson-dataformat-csv:jar:2.13.3:compile
[INFO] +- com.fasterxml.jackson.core:jackson-databind:jar:2.13.3:compile
[INFO] +- com.fasterxml.jackson.core:jackson-core:jar:2.13.3:compile
[INFO] \- com.cosium.spring.data:spring-data-jpa-entity-graph:jar:2.5.0:compile
@anmol1vw13 anmol1vw13 added status/need-triage A new issue that still need to be evaluated as a whole type/bug A general bug labels Sep 28, 2022
@violetagg
Copy link
Member

@anmol1vw13 As @pderop wrote in his comment #2499 (comment) please upgrade to the latest released versions for Reactor/Spring

@anmol1vw13
Copy link
Author

I've enabled debug logs and here's my observation.

Things work fine, if there's continuous traffic. But once there's a complete halt i.e. the API calls using netty is not being made, I see the following log

USER_EVENT: SslCloseCompletionEvent(SUCCESS)
READ COMPLETE

All the subsequent requests fail thereafter.

When does this USER_EVENT, SslCloseCompletionEvent get fired and how do I auto recover the connection, when the next request comes through?

@violetagg violetagg added for/user-attention This issue needs user attention (feedback, rework, etc...) and removed status/need-triage A new issue that still need to be evaluated as a whole labels Sep 28, 2022
@anmol1vw13
Copy link
Author

anmol1vw13 commented Sep 28, 2022

@violetagg Updating spring to the latest version is not an option at the moment. There could be a lot of breaking changes. It would be great if you could help out with
the SslCloseCompletionEvent.. Couldn't find much on it online.

@violetagg
Copy link
Member

violetagg commented Sep 28, 2022

@anmol1vw13 That's unfortunate ... you are missing an important fix in 1.0.18 release https://github.com/reactor/reactor-netty/releases/tag/v1.0.18

@violetagg
Copy link
Member

@anmol1vw13 May be as a workaround for your case (as you cannot upgrade) you can configure maxIdleTime for the connection pool - More information you can find here #1318 (comment)

@anmol1vw13
Copy link
Author

anmol1vw13 commented Sep 28, 2022

@violetagg I found a patch version of spring-boot-starter-webflux
and it makes use of reactor-netty-http version 1.0.19.
Here's my dependency tree

[INFO] +- org.springframework.boot:spring-boot-starter-webflux:jar:2.5.14:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-json:jar:2.5.14:compile
[INFO] |  |  +- com.fasterxml.jackson.datatype:jackson-datatype-jdk8:jar:2.12.6:compile
[INFO] |  |  +- com.fasterxml.jackson.datatype:jackson-datatype-jsr310:jar:2.12.6:compile
[INFO] |  |  \- com.fasterxml.jackson.module:jackson-module-parameter-names:jar:2.12.6:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-reactor-netty:jar:2.5.14:compile
[INFO] |  |  \- io.projectreactor.netty:reactor-netty-http:jar:1.0.19:compile
[INFO] |  |     +- io.netty:netty-codec-http2:jar:4.1.77.Final:compile
[INFO] |  |     +- io.netty:netty-resolver-dns:jar:4.1.77.Final:compile
[INFO] |  |     |  \- io.netty:netty-codec-dns:jar:4.1.77.Final:compile
[INFO] |  |     +- io.netty:netty-resolver-dns-native-macos:jar:osx-x86_64:4.1.77.Final:compile
[INFO] |  |     |  \- io.netty:netty-resolver-dns-classes-macos:jar:4.1.77.Final:compile
[INFO] |  |     +- io.netty:netty-transport-native-epoll:jar:linux-x86_64:4.1.77.Final:compile
[INFO] |  |     |  +- io.netty:netty-transport-native-unix-common:jar:4.1.77.Final:compile
[INFO] |  |     |  \- io.netty:netty-transport-classes-epoll:jar:4.1.77.Final:compile
[INFO] |  |     \- io.projectreactor.netty:reactor-netty-core:jar:1.0.19:compile
[INFO] |  |        \- io.netty:netty-handler-proxy:jar:4.1.77.Final:compile
[INFO] |  |           \- io.netty:netty-codec-socks:jar:4.1.77.Final:compile
                ...

This doesn't seem to work though because after a few minutes of inactivity I still see the SslCloseCompletionEvent in the logs, after which all the subsequent request fail with SslClosedEngineException.

Can you help me understanding when and why does SslCloseCompletionEvent occur? I mean even if the SSLEngine gets closed, how can we recover when the next external API call happens?

@anmol1vw13
Copy link
Author

anmol1vw13 commented Sep 28, 2022

Setting maxIdleTime got things working. This exercise also helped me gain a lot of understanding on how reactor-netty-http works. It's a beast and does a lot of things to ensure the requests are quick.

@violetagg Instead of using environment variables, I'm using a ConnectionProvider as shown below. Please let me know if this is the right way to set it or if I need to change anything.

 @Bean
    public WebClient apiClient() {

        /*
         * Setting maxIdleTime as 10s, because servers usually have a keepAliveTimeout
         * of 60s, after which the connection gets closed.
         * If the connection pool has any connection which has been idle for over 10s, it
         * will be evicted from the pool.
         * Refer https://github.com/reactor/reactor-netty/issues/1318#issuecomment-702668918
         */
        ConnectionProvider connectionProvider = ConnectionProvider.builder("connectionProvider")
            .maxIdleTime(Duration.ofSeconds(10))
            .build();

        HttpClient httpClient = HttpClient.create(connectionProvider)
            .wiretap("reactor.netty.http.client.HttpClient", LogLevel.DEBUG, AdvancedByteBufFormat.TEXTUAL)
            .responseTimeout(Duration.of(5, ChronoUnit.SECONDS));

        return WebClient.builder()
            .clientConnector(new ReactorClientHttpConnector(httpClient))
            .build();
    }

@violetagg
Copy link
Member

@anmol1vw13 Yes that's the correct way of configuring the connection pool. You may want to configure max connections because with the configuration above you will have only 16 connections. Please check the documentation for more information https://projectreactor.io/docs/netty/release/reference/index.html#_connection_pool_2

@anmol1vw13
Copy link
Author

@violetagg How about I use this configuration, as mentioned in the document!

ConnectionProvider provider =
				ConnectionProvider.builder("custom")
				                  .maxConnections(50)
				                  .maxIdleTime(Duration.ofSeconds(20))           
				                  .maxLifeTime(Duration.ofSeconds(60))           
				                  .pendingAcquireTimeout(Duration.ofSeconds(60)) 
				                  .evictInBackground(Duration.ofSeconds(120))    
				                  .build();

Can you explain what pending acquire timeout means?

@violetagg
Copy link
Member

violetagg commented Sep 29, 2022

@anmol1vw13 This is just an example, you have to test the configuration with your solution and to see which settings are more appropriate for your use case.

pending acquire timeout

If there is no free connection in the pool, this is the time that we will wait for a connection to become free.

@pderop
Copy link
Member

pderop commented Sep 30, 2022

@anmol1vw13 ,

Hi,

We are about to merge the #2518 PR, which may avoid the "SSLEngine closed already" exception in your case.
In the meantime, you can try to use the work around described by Violeta.

However, using the PR, if the server closes the connection while the client is currently writing a request to the connection, or is currently waiting for the response, then the client will get a PrematureCloseException or an AbortedException (this we can't avoid).
thanks.

pderop added a commit that referenced this issue Sep 30, 2022
#2518)

When a TLS close_notify is received and when the close_notify ack is replied, then the Netty SslHandler just does not close the channel. Instead of that, in that case it fires a SslCloseCompletionEvent.SUCCESS event down the pipeline, and the closing of the channel is left to other handlers.

And since the TLS RFC states that the party receiving a close_notify MUST respond with a close_notify alert of its own and close down the connection immediately, let's do this in Reactor-Netty.

This patch won't avoid AbortedExceptions or PrematureCloseException exceptions in case a close_notify is being received while a request is being written, or while a response is waited for, but it may address some of the pain highlighted by #2498, #2499, and #2509; and may avoid SslClosedEngineException: SSLEngine closed already " exceptions.
@violetagg violetagg added this to the 1.0.24 milestone Sep 30, 2022
@violetagg violetagg removed the for/user-attention This issue needs user attention (feedback, rework, etc...) label Sep 30, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type/bug A general bug
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants