Hi, I have Spring backend app connected to Mongodb (configured with MongoDB Kubernetes Operator) on Kubernetes.
Sometimes (not for every write operation) there is problem with connection between database & backend app.
I attach the logs & config files. I hope you will guide me where I can read more to understand this problem.
Connection uri:
mongodb://username:password@kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local,kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local/kompas2?readPreference=primaryPreferred&ssl=false
Error from backend app
06:48:04.405 INFO org.mongodb.driver.connection : Opened connection [connectionId{localValue:120, serverValue:49559}] to kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017
06:48:04.698 INFO org.mongodb.driver.cluster : No server chosen by WritableServerSelector from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=8, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=382123, setName='kompas2mongo', canonicalAddress=kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017, hosts=[kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017, kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017], passives=[], arbiters=[], primary='kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017', tagSet=TagSet{[]}, electionId=null, setVersion=2, topologyVersion=null, lastWriteDate=Mon Nov 07 06:47:54 GMT 2022, lastUpdateTimeNanos=4233730641707005}, ServerDescription{address=kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketReadException: Prematurely reached end of stream}}]}. Waiting for 30000 ms before timing out
06:48:04.699 INFO org.mongodb.driver.cluster : Monitor thread successfully connected to server with description ServerDescription{address=kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=8, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=374840, setName='kompas2mongo', canonicalAddress=kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017, hosts=[kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017, kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=2, topologyVersion=null, lastWriteDate=Mon Nov 07 06:48:04 GMT 2022, lastUpdateTimeNanos=4233734419530953}
06:48:04.700 INFO org.mongodb.driver.cluster : Exception in monitor thread while connecting to server kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017
com.mongodb.MongoSocketOpenException: Exception opening socket
at com.mongodb.internal.connection.SocketStream.open(SocketStream.java:70)
at com.mongodb.internal.connection.InternalStreamConnection.open(InternalStreamConnection.java:143)
at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.lookupServerDescription(DefaultServerMonitor.java:188)
at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:144)
at java.base/java.lang.Thread.run(Thread.java:832)
Caused by: java.net.ConnectException: Connection refused
at java.base/sun.nio.ch.Net.pollConnect(Native Method)
at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:589)
at java.base/sun.nio.ch.NioSocketImpl.timedFinishConnect(NioSocketImpl.java:542)
at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:597)
at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:333)
at java.base/java.net.Socket.connect(Socket.java:648)
at com.mongodb.internal.connection.SocketStreamHelper.initialize(SocketStreamHelper.java:107)
at com.mongodb.internal.connection.SocketStream.initializeSocket(SocketStream.java:79)
at com.mongodb.internal.connection.SocketStream.open(SocketStream.java:65)
... 4 common frames omitted
06:48:34.701 ERROR o.a.c.c.C.[.[.[.[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [/api] threw exception [Request processing failed; nested exception is org.springframework.dao.DataAccessResourceFailureException: Timed out after 30000 ms while waiting for a server that matches WritableServerSelector. Client view of cluster state is {type=REPLICA_SET, servers=[{address=kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017, type=REPLICA_SET_SECONDARY, roundTripTime=0.4 ms, state=CONNECTED}, {address=kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused}}]; nested exception is com.mongodb.MongoTimeoutException: Timed out after 30000 ms while waiting for a server that matches WritableServerSelector. Client view of cluster state is {type=REPLICA_SET, servers=[{address=kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017, type=REPLICA_SET_SECONDARY, roundTripTime=0.4 ms, state=CONNECTED}, {address=kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused}}]] with root cause
com.mongodb.MongoTimeoutException: Timed out after 30000 ms while waiting for a server that matches WritableServerSelector. Client view of cluster state is {type=REPLICA_SET, servers=[{address=kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017, type=REPLICA_SET_SECONDARY, roundTripTime=0.4 ms, state=CONNECTED}, {address=kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused}}]
at com.mongodb.internal.connection.BaseCluster.createTimeoutException(BaseCluster.java:413)
at com.mongodb.internal.connection.BaseCluster.selectServer(BaseCluster.java:118)
at com.mongodb.internal.connection.AbstractMultiServerCluster.selectServer(AbstractMultiServerCluster.java:50)
at com.mongodb.internal.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:105)
at com.mongodb.internal.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:100)
at com.mongodb.internal.binding.ClusterBinding.getWriteConnectionSource(ClusterBinding.java:92)
at com.mongodb.client.internal.ClientSessionBinding.getWriteConnectionSource(ClientSessionBinding.java:93)
at com.mongodb.internal.operation.OperationHelper.withReleasableConnection(OperationHelper.java:619)
at com.mongodb.internal.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:185)
at com.mongodb.internal.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:76)
at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:187)
at com.mongodb.client.internal.MongoCollectionImpl.executeSingleWriteRequest(MongoCollectionImpl.java:1009)
at com.mongodb.client.internal.MongoCollectionImpl.executeReplaceOne(MongoCollectionImpl.java:567)
at com.mongodb.client.internal.MongoCollectionImpl.replaceOne(MongoCollectionImpl.java:550)
at org.springframework.data.mongodb.core.MongoTemplate.lambda$saveDocument$18(MongoTemplate.java:1539)
at org.springframework.data.mongodb.core.MongoTemplate.execute(MongoTemplate.java:553)
at org.springframework.data.mongodb.core.MongoTemplate.saveDocument(MongoTemplate.java:1507)
at org.springframework.data.mongodb.core.MongoTemplate.doSave(MongoTemplate.java:1443)
at org.springframework.data.mongodb.core.MongoTemplate.save(MongoTemplate.java:1385)
at org.springframework.data.mongodb.repository.support.SimpleMongoRepository.save(SimpleMongoRepository.java:94)
at jdk.internal.reflect.GeneratedMethodAccessor313.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at org.springframework.data.repository.core.support.RepositoryMethodInvoker$RepositoryFragmentMethodInvoker.lambda$new$0(RepositoryMethodInvoker.java:289)
at org.springframework.data.repository.core.support.RepositoryMethodInvoker.doInvoke(RepositoryMethodInvoker.java:137)
at org.springframework.data.repository.core.support.RepositoryMethodInvoker.invoke(RepositoryMethodInvoker.java:121)
at org.springframework.data.repository.core.support.RepositoryComposition$RepositoryFragments.invoke(RepositoryComposition.java:529)
at org.springframework.data.repository.core.support.RepositoryComposition.invoke(RepositoryComposition.java:285)
at org.springframework.data.repository.core.support.RepositoryFactorySupport$ImplementationMethodExecutionInterceptor.invoke(RepositoryFactorySupport.java:599)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.doInvoke(QueryExecutorMethodInterceptor.java:163)
at org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.invoke(QueryExecutorMethodInterceptor.java:138)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:80)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.data.repository.core.support.MethodInvocationValidator.invoke(MethodInvocationValidator.java:98)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
at com.sun.proxy.$Proxy163.save(Unknown Source)
at kompas2.recommendation.persistence.CustomCompanyRecommendationRepository.save(CompanyRecommendationRepository.kt)
at kompas2.recommendation.persistence.CustomCompanyRecommendationRepository.save(CompanyRecommendationRepository.kt:21)
at kompas2.recommendation.persistence.CustomCompanyRecommendationRepository$$FastClassBySpringCGLIB$$6cfc1920.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:779)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:137)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692)
at kompas2.recommendation.persistence.CustomCompanyRecommendationRepository$$EnhancerBySpringCGLIB$$e7db7271.save(<generated>)
at kompas2.recommendation.event.RecommendationCompanyUpdated.receive(RecommendationCompanyUpdated.kt:45)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at org.springframework.context.event.ApplicationListenerMethodAdapter.doInvoke(ApplicationListenerMethodAdapter.java:344)
at org.springframework.context.event.ApplicationListenerMethodAdapter.processEvent(ApplicationListenerMethodAdapter.java:229)
at org.springframework.context.event.ApplicationListenerMethodAdapter.onApplicationEvent(ApplicationListenerMethodAdapter.java:166)
at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:176)
at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:169)
at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:143)
at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:421)
at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:391)
at kompas2.company.events.CompanyUpdatedPublisher.publish(CompanyUpdated.kt:41)
at kompas2.company.application.CompanyBasicsWriter.update(CompanyBasicsWriter.kt:118)
at kompas2.company.application.CompanyBasicsWriter.updateMany(CompanyBasicsWriter.kt:110)
at kompas2.company.application.CompanyBasicsWriter.updateBasics(CompanyBasicsWriter.kt:103)
at kompas2.company.application.CompanyBasicsWriter.validateAndUpdateBasics(CompanyBasicsWriter.kt:41)
at kompas2.company.application.CompanyBasicsWriter$$FastClassBySpringCGLIB$$e20886b1.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:779)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89)
at kompas2.misc.metrics.SkipFirstMeanTiming$measureExecutionTime$2.invoke(SkipFirstMeanTiming.kt:25)
at kompas2.misc.metrics.SkipFirstMeanTimer.record$lambda-1(SkipFirstMeanTimer.kt:29)
at io.micrometer.core.instrument.AbstractTimer.recordCallable(AbstractTimer.java:138)
at kompas2.misc.metrics.SkipFirstMeanTimer.record(SkipFirstMeanTimer.kt:29)
at kompas2.misc.metrics.SkipFirstMeanTiming.measureExecutionTime(SkipFirstMeanTiming.kt:25)
at jdk.internal.reflect.GeneratedMethodAccessor213.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:634)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:624)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:72)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692)
at kompas2.company.application.CompanyBasicsWriter$$EnhancerBySpringCGLIB$$d206123c.validateAndUpdateBasics(<generated>)
at kompas2.company.web.CompanyBasicsController.updateBasics(CompanyBasicsController.kt:29)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:117)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:895)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1067)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:963)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
at org.springframework.web.servlet.FrameworkServlet.doPut(FrameworkServlet.java:920)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:684)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:327)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:115)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:81)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:121)
at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:115)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:126)
at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:81)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:105)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:149)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
at kompas2.security.JwtFilter.doFilterInternal(JwtFilter.kt:43)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:103)
at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:89)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
at org.springframework.security.web.header.HeaderWriterFilter.doHeadersAfter(HeaderWriterFilter.java:90)
at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:75)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:110)
at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:80)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:55)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:211)
at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:183)
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:358)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:271)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
06:48:53.850 INFO org.mongodb.driver.cluster : No server chosen by WritableServerSelector from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=8, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=379787, setName='kompas2mongo', canonicalAddress=kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017, hosts=[kompas2mongo-1.kompas2mongo-svc.test.svc.cluster.local:27017, kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=2, topologyVersion=null, lastWriteDate=Mon Nov 07 06:48:04 GMT 2022, lastUpdateTimeNanos=4233774899280824}, ServerDescription{address=kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused}}]}. Waiting for 30000 ms before timing out
MongoDB operator config:
apiVersion: mongodbcommunity.mongodb.com/v1
kind: MongoDBCommunity
metadata:
name: kompas2mongo
spec:
members: 2
type: ReplicaSet
version: "4.2.6"
security:
authentication:
modes: ["SCRAM"]
Logs from mongo:
[2022-11-07T06:48:04.107+0000] [.info] [src/mongoctl/processctl.go:Update:3263] <kompas2mongo-0> [06:48:04.107] <DB_WRITE> Updated with query map[] and update [{$set [{agentFeatures [StateCache]} {lastVersion 2} {nextVersion 2}]}] and upsert=true on local.clustermanager
2022-11-07T06:48:04.376+0000 I CONNPOOL [RS] Ending connection to host kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017 due to bad connection status: HostUnreachable: Connection closed by peer; 1 connections to that host remain open
2022-11-07T06:48:04.377+0000 I NETWORK [conn9] end connection 10.244.1.183:47630 (9 connections now open)
2022-11-07T06:48:04.379+0000 I REPL [replication-20] Restarting oplog query due to error: HostUnreachable: error in fetcher batch callback :: caused by :: Connection closed by peer. Last fetched optime: { ts: Timestamp(1667803684, 102), t: 219 }. Restarts remaining: 1
2022-11-07T06:48:04.379+0000 I CONNPOOL [replication-20] dropping unhealthy pooled connection to kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017
2022-11-07T06:48:04.379+0000 I CONNPOOL [RS] Connecting to kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017
2022-11-07T06:48:04.379+0000 I REPL [replication-20] Scheduled new oplog query Fetcher source: kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017 database: local query: { find: "oplog.rs", filter: { ts: { $gte: Timestamp(1667803684, 102) } }, tailable: true, oplogReplay: true, awaitData: true, maxTimeMS: 2000, batchSize: 13981010, term: 219, readConcern: { afterClusterTime: Timestamp(0, 1) } } query metadata: { $replData: 1, $oplogQueryData: 1, $readPreference: { mode: "secondaryPreferred" } } active: 1 findNetworkTimeout: 7000ms getMoreNetworkTimeout: 10000ms shutting down?: 0 first: 1 firstCommandScheduler: RemoteCommandRetryScheduler request: RemoteCommand 304917 -- target:kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017 db:local cmd:{ find: "oplog.rs", filter: { ts: { $gte: Timestamp(1667803684, 102) } }, tailable: true, oplogReplay: true, awaitData: true, maxTimeMS: 2000, batchSize: 13981010, term: 219, readConcern: { afterClusterTime: Timestamp(0, 1) } } active: 1 callbackHandle.valid: 1 callbackHandle.cancelled: 0 attempt: 1 retryPolicy: {type: "NoRetryPolicy"}
2022-11-07T06:48:04.379+0000 I NETWORK [listener] connection accepted from 10.244.1.136:54320 #49559 (10 connections now open)
2022-11-07T06:48:04.380+0000 I NETWORK [conn49559] received client metadata from 10.244.1.136:54320 conn49559: { driver: { name: "mongo-java-driver|sync|spring-boot", version: "4.2.3" }, os: { type: "Linux", name: "Linux", architecture: "amd64", version: "4.19.0-17-amd64" }, platform: "Java/Azul Systems, Inc./14.0.2+12" }
2022-11-07T06:48:04.387+0000 I REPL [replication-18] Error returned from oplog query (no more query restarts left): HostUnreachable: error in fetcher batch callback :: caused by :: Error connecting to kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017 (10.244.1.183:27017) :: caused by :: Connection refused
...
2022-11-07T06:48:37.471+0000 I REPL_HB [replexec-4] Heartbeat to kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017 failed after 2 retries, response status: HostUnreachable: Error connecting to kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017 (10.244.1.183:27017) :: caused by :: Connection refused
2022-11-07T06:48:37.979+0000 I ELECTION [replexec-3] Not starting an election, since we are not electable due to: Not standing for election because I cannot see a majority (mask 0x1)
Election after sec
2022-11-07T06:49:20.851+0000 I ELECTION [replexec-4] Starting an election, since we've seen no PRIMARY in the past 10000ms
2022-11-07T06:49:20.851+0000 I ELECTION [replexec-4] conducting a dry run election to see if we could be elected. current term: 219
2022-11-07T06:49:20.851+0000 I REPL [replexec-4] Scheduling remote command request for vote request: RemoteCommand 305346 -- target:kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017 db:admin cmd:{ replSetRequestVotes: 1, setName: "kompas2mongo", dryRun: true, term: 219, candidateIndex: 1, configVersion: 2, lastCommittedOp: { ts: Timestamp(1667803684, 102), t: 219 } }
2022-11-07T06:49:20.851+0000 I ELECTION [replexec-3] VoteRequester(term 219 dry run) received a yes vote from kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017; response message: { term: 219, voteGranted: true, reason: "", ok: 1.0, $clusterTime: { clusterTime: Timestamp(1667803684, 102), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, operationTime: Timestamp(1667803684, 102) }
2022-11-07T06:49:20.851+0000 I ELECTION [replexec-3] dry election run succeeded, running for election in term 220
2022-11-07T06:49:20.851+0000 I ELECTION [conn11] Received vote request: { replSetRequestVotes: 1, setName: "kompas2mongo", dryRun: true, term: 219, candidateIndex: 1, configVersion: 2, lastCommittedOp: { ts: Timestamp(1667803684, 102), t: 219 } }
2022-11-07T06:49:20.851+0000 I ELECTION [conn11] Sending vote response: { term: 219, voteGranted: true, reason: "" }
2022-11-07T06:49:20.852+0000 I REPL [replexec-3] Scheduling remote command request for vote request: RemoteCommand 305347 -- target:kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017 db:admin cmd:{ replSetRequestVotes: 1, setName: "kompas2mongo", dryRun: false, term: 220, candidateIndex: 1, configVersion: 2, lastCommittedOp: { ts: Timestamp(1667803684, 102), t: 219 } }
2022-11-07T06:49:20.852+0000 I ELECTION [conn11] Received vote request: { replSetRequestVotes: 1, setName: "kompas2mongo", dryRun: false, term: 220, candidateIndex: 1, configVersion: 2, lastCommittedOp: { ts: Timestamp(1667803684, 102), t: 219 } }
2022-11-07T06:49:20.852+0000 I ELECTION [conn11] Sending vote response: { term: 220, voteGranted: true, reason: "" }
2022-11-07T06:49:20.852+0000 I ELECTION [replexec-4] VoteRequester(term 220) received a yes vote from kompas2mongo-0.kompas2mongo-svc.test.svc.cluster.local:27017; response message: { term: 220, voteGranted: true, reason: "", ok: 1.0, $clusterTime: { clusterTime: Timestamp(1667803684, 102), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, operationTime: Timestamp(1667803684, 102) }
2022-11-07T06:49:20.852+0000 I ELECTION [replexec-4] election succeeded, assuming primary role in term 220
And after that database connection is restored
Also on stackoverflow:
https://stackoverflow.com/questions/73455042/spring-with-mongodb-losing-connection
