Azure / azure-sdk-for-java

This repository is for active development of the Azure SDK for Java. For consumers of the SDK we recommend visiting our public developer docs at https://docs.microsoft.com/java/azure/ or our versioned developer docs at https://azure.github.io/azure-sdk-for-java.
MIT License
2.36k stars 2k forks source link

[BUG] SSL Exception with spring-data-cosmosdb SDK version “2.3.0” #18656

Closed chenrujun closed 3 years ago

chenrujun commented 3 years ago

We have one microservice in JAVA Spring boot deployed on AKS and we are using spring-data-cosmosdb SDK version “2.3.0” to save data in cosmosDB asynchronously. Below are the dependencies that we are using in pom.xml.

`

<dependency>
<groupId>com.microsoft.azure</groupId>
<artifactId>azure-cosmosdb-spring-boot-starter</artifactId>
<version>2.2.0</version>
</dependency>
<dependency>
<groupId>com.microsoft.azure</groupId>
<artifactId>spring-data-cosmosdb</artifactId>
<version>2.3.0</version>
</dependency>

`

We are logging into Application Insights with dependency tracking. We can see “SSLException” very often with OTHER CONNECT as dependency in our logs. Below is the stack trace for the issue:

javax.net.ssl.SSLException: SSLEngine closed already at io.netty.handler.ssl.SslHandler.wrap(SslHandler.java:854) at io.netty.handler.ssl.SslHandler.wrapAndFlush(SslHandler.java:811) at io.netty.handler.ssl.SslHandler.flush(SslHandler.java:792) at io.netty.handler.ssl.SslHandler.flush(SslHandler.java:1939) at io.netty.handler.ssl.SslHandler.closeOutbound0(SslHandler.java:668) at io.netty.handler.ssl.SslHandler.closeOutbound(SslHandler.java:652) at io.netty.handler.ssl.SslHandler.closeOutbound(SslHandler.java:640) at com.azure.data.cosmos.internal.directconnectivity.rntbd.RntbdRequestManager.close(RntbdRequestManager.java:391) at io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:622) at io.netty.channel.AbstractChannelHandlerContext.access$1200(AbstractChannelHandlerContext.java:61) at io.netty.channel.AbstractChannelHandlerContext$11.run(AbstractChannelHandlerContext.java:611) at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) 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)

We suspect that it’s trying to close the connection which is already closed. We don’t have any custom configurations and we are following Spring azure cosmos default configurations.

image

ghost commented 3 years ago

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @kushagraThapar, @anfeldma-ms

chenrujun commented 3 years ago

This issue is copied from: https://github.com/microsoft/spring-data-cosmosdb/issues/556

kushagraThapar commented 3 years ago

@SaurabhWajpe- This is not a functional issue, rather an error log which gets thrown when the connection is already closed. This should not cause any harm to your application. However, we have tried solving it in the new version of the azure-spring-data-cosmos SDK - https://mvnrepository.com/artifact/com.azure/azure-spring-data-cosmos

You can read more about this new module here: https://docs.microsoft.com/en-us/azure/cosmos-db/sql-api-sdk-java-spring-v3?tabs=explore

SaurabhWajpe commented 3 years ago

Thanks for the update @kushagraThapar. Will try with latest version and let you know.

Thank you!

poaggar commented 3 years ago

@kushagraThapar

We have removed the dependency for spring-data-cosmosdb and are just using azure-cosmosdb-spring-boot-starter. We have upgraded the version for latter dependency to the recent version. Documents are getting saved successfully in Cosmos but still getting SSLException as mentioned above.

<dependency>
<groupId>com.microsoft.azure</groupId>
<artifactId>azure-cosmosdb-spring-boot-starter</artifactId>
<version>2.3.5</version>
</dependency>
kushagraThapar commented 3 years ago

@poojaaggarwal-java - as I mentioned previously, this is not a functional issue, this is just noise coming from netty modules, while we are looking into this, there is no necessary solution to this as this is just noise coming from netty code.

@mbhaskar @FabianMeiswinkel @moderakh @simplynaveen20 @xinlian12 - for visibility.

kushagraThapar commented 3 years ago

@SaurabhWajpe - did you get a chance to try out the latest version of spring-data-cosmos, if you still see the issue, can you provide a repro for this issue ? https://mvnrepository.com/artifact/com.azure/azure-spring-data-cosmos/3.3.0

@poojaaggarwal-java - Regarding the spring-boot-cosmos-starter version you are using, that is old version. Can you please upgrade your app to the below version and try again ? https://mvnrepository.com/artifact/com.azure.spring/azure-spring-boot-starter-cosmos/3.1.0

kushagraThapar commented 3 years ago

@SaurabhWajpe - please test this on the latest version of azure-spring-data-cosmos. Closing this issue due to inactivity.

gauravece9162k5 commented 3 years ago

Hi Team , I tested the fix with azure-spring-boot-starter-cosmos/3.1.0 and spring-boot-starter-parent

2.3.5.RELEASE

Definitely The frequency of javax.net.ssl.SSLException has decreased BUt I can still see the exception with slight change in trace: javax.net.ssl.SSLException: SSLEngine closed already at io.netty.handler.ssl.SslHandler.wrap(SslHandler.java:854) at io.netty.handler.ssl.SslHandler.wrapAndFlush(SslHandler.java:811) at io.netty.handler.ssl.SslHandler.flush(SslHandler.java:792) at io.netty.handler.ssl.SslHandler.flush(SslHandler.java:1946) at io.netty.handler.ssl.SslHandler.closeOutboundAndChannel(SslHandler.java:1914) at io.netty.handler.ssl.SslHandler.close(SslHandler.java:743) at io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:622) at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:606) at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.close(CombinedChannelDuplexHandler.java:505) at io.netty.channel.ChannelOutboundHandlerAdapter.close(ChannelOutboundHandlerAdapter.java:77) at io.netty.channel.CombinedChannelDuplexHandler.close(CombinedChannelDuplexHandler.java:316) at io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:622) at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:606) at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.close(CombinedChannelDuplexHandler.java:505) at io.netty.channel.ChannelOutboundHandlerAdapter.close(ChannelOutboundHandlerAdapter.java:77) at io.netty.channel.CombinedChannelDuplexHandler.close(CombinedChannelDuplexHandler.java:316) at io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:622) at io.netty.channel.AbstractChannelHandlerContext.access$1200(AbstractChannelHandlerContext.java:61) at io.netty.channel.AbstractChannelHandlerContext$11.run(AbstractChannelHandlerContext.java:611) at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.lang.Thread.run(Thread.java:748)