[JAVA-4551] RejectedExecutionException happens in driver Created: 28/Mar/22  Updated: 28/Oct/23  Resolved: 01/Apr/22

Status: Closed
Project: Java Driver
Component/s: Error Handling
Affects Version/s: 4.5.1
Fix Version/s: 4.6.0

Type: Bug Priority: Major - P3
Reporter: Francisco Alejandro Lozano López Assignee: Valentin Kavalenka
Resolution: Fixed Votes: 0
Labels: external-user
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: Text File mongo-driver-log.txt    
Backwards Compatibility: Fully Compatible
Documentation Changes: Not Needed

 Description   

During my integration tests, I setup a 3-node replica-set in docker, and connect to it with Java client. 

Often I get this exception in the logs:

Exception in thread "cluster-ClusterId{value='62415548404dc25237ffe99d', description='null'}-127.0.0.1:55059" Exception in thread "cluster-ClusterId{value='62415548404dc25237ffe99d', description='null'}-127.0.0.1:55058" java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@39dcce0f[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@3324a57f[Wrapped task = com.mongodb.internal.connection.DefaultConnectionPool$BackgroundMaintenanceManager$$Lambda$194/0x00000008003b9440@3de34d6b]] rejected from java.util.concurrent.ScheduledThreadPoolExecutor@7cde4750[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
	at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2055)
	at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:825)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:340)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.scheduleAtFixedRate(ScheduledThreadPoolExecutor.java:632)
	at java.base/java.util.concurrent.Executors$DelegatedScheduledExecutorService.scheduleAtFixedRate(Executors.java:785)
	at com.mongodb.internal.connection.DefaultConnectionPool$BackgroundMaintenanceManager.start(DefaultConnectionPool.java:1419)
	at com.mongodb.internal.connection.DefaultConnectionPool$StateAndGeneration.ready(DefaultConnectionPool.java:1500)
	at com.mongodb.internal.connection.DefaultConnectionPool.ready(DefaultConnectionPool.java:270)
	at com.mongodb.internal.connection.DefaultSdamServerDescriptionManager.lambda$update$0(DefaultSdamServerDescriptionManager.java:72)
	at com.mongodb.internal.connection.BaseCluster.withLock(BaseCluster.java:271)
	at com.mongodb.internal.connection.AbstractMultiServerCluster.withLock(AbstractMultiServerCluster.java:50)
	at com.mongodb.internal.connection.DefaultSdamServerDescriptionManager.update(DefaultSdamServerDescriptionManager.java:60)
	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:165)
	at java.base/java.lang.Thread.run(Thread.java:829)
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@3912c812[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@782fc229[Wrapped task = com.mongodb.internal.connection.DefaultConnectionPool$BackgroundMaintenanceManager$$Lambda$194/0x00000008003b9440@7c1059f4]] rejected from java.util.concurrent.ScheduledThreadPoolExecutor@e59b1a6[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
	at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2055)
	at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:825)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:340)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.scheduleAtFixedRate(ScheduledThreadPoolExecutor.java:632)
	at java.base/java.util.concurrent.Executors$DelegatedScheduledExecutorService.scheduleAtFixedRate(Executors.java:785)
	at com.mongodb.internal.connection.DefaultConnectionPool$BackgroundMaintenanceManager.start(DefaultConnectionPool.java:1419)
	at com.mongodb.internal.connection.DefaultConnectionPool$StateAndGeneration.ready(DefaultConnectionPool.java:1500)
	at com.mongodb.internal.connection.DefaultConnectionPool.ready(DefaultConnectionPool.java:270)
	at com.mongodb.internal.connection.DefaultSdamServerDescriptionManager.lambda$update$0(DefaultSdamServerDescriptionManager.java:72)
	at com.mongodb.internal.connection.BaseCluster.withLock(BaseCluster.java:271)
	at com.mongodb.internal.connection.AbstractMultiServerCluster.withLock(AbstractMultiServerCluster.java:50)
	at com.mongodb.internal.connection.DefaultSdamServerDescriptionManager.update(DefaultSdamServerDescriptionManager.java:60)
	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:165)
	at java.base/java.lang.Thread.run(Thread.java:829)

 

Sometimes this exception manages to fail my test raising to the main junit thread. other times it stays in the background thread that launched the task. It's really weird.

Versions:

  • MongoDB 4.4.6 
  • Java 11 / Driver 4.5.1
  • OS X and Linux

 



 Comments   
Comment by Githook User [ 01/Apr/22 ]

Author:

{'name': 'Valentin Kovalenko', 'email': 'valentin.kovalenko@mongodb.com', 'username': 'stIncMale'}

Message: Tolerate `DefaultConnectionPool.ready`/`invalidate` being called after or concurrently with `close` (#906)

JAVA-4551
Branch: 4.5.x
https://github.com/mongodb/mongo-java-driver/commit/2aa4a5decc3a9dffc49cf6b05998a36c0965a525

Comment by Githook User [ 01/Apr/22 ]

Author:

{'name': 'Valentin Kovalenko', 'email': 'valentin.kovalenko@mongodb.com', 'username': 'stIncMale'}

Message: Tolerate `DefaultConnectionPool.ready`/`invalidate` being called after or concurrently with `close` (#906)

JAVA-4551
Branch: master
https://github.com/mongodb/mongo-java-driver/commit/22cf7f932a8245b58e04c88e39302b74252e7c10

Comment by Francisco Alejandro Lozano López [ 01/Apr/22 ]

thanks a lot!

Comment by Valentin Kavalenka [ 31/Mar/22 ]

Hi flozano@gmail.com,

Thank you for reporting the problem. The stacktrace you provided happens in a thread different from the thread running your tests, but there is indeed a code path that allows observing RejectedExecutionException in a user thread: this happens when DefaultConnectionPool is closed concurrently with an exception thrown while the driver executes a user-requested operation.

Even though we don't have the stacktrace of an exception that effects your test thread, the PR linked with this ticket should deal with all situations.

Generated at Thu Feb 08 09:02:22 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.