Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.

Bug 369799

Summary: [MongoDB] Monitor Timeouts during large commits
Product: [Modeling] EMF Reporter: Stefan Winkler <stefan>
Component: cdo.coreAssignee: Project Inbox <emf.cdo-inbox>
Status: NEW --- QA Contact:
Severity: normal    
Priority: P3    
Version: 4.13   
Target Milestone: ---   
Hardware: All   
OS: All   
Whiteboard:

Description Stefan Winkler CLA 2012-01-26 08:35:38 EST 
I encountered a timeout during large commits with MongoDB store:

org.eclipse.emf.cdo.tests.config.impl.ConfigTestException: Error in ReadPerformanceTest.testAll [Combined, MongoDB-auditing, JVM, Legacy]
	at org.eclipse.emf.cdo.tests.config.impl.ConfigTest.runBare(ConfigTest.java:535)
	at org.eclipse.emf.cdo.tests.performance.framework.PerformanceTest.runBareBasic(PerformanceTest.java:90)
	at org.eclipse.emf.cdo.tests.performance.framework.PerformanceTest.runBare(PerformanceTest.java:74)
	at junit.framework.TestResult$1.protect(TestResult.java:110)
	at junit.framework.TestResult.runProtected(TestResult.java:128)
	at junit.framework.TestResult.run(TestResult.java:113)
	at junit.framework.TestCase.run(TestCase.java:124)
	at org.eclipse.net4j.util.tests.AbstractOMTest.run(AbstractOMTest.java:264)
	at junit.framework.TestSuite.runTest(TestSuite.java:243)
	at org.eclipse.emf.cdo.tests.config.impl.ConfigTestSuite$TestWrapper.runTest(ConfigTestSuite.java:183)
	at junit.framework.TestSuite.run(TestSuite.java:238)
	at junit.framework.TestSuite.runTest(TestSuite.java:243)
	at junit.framework.TestSuite.run(TestSuite.java:238)
	at junit.framework.TestSuite.runTest(TestSuite.java:243)
	at junit.framework.TestSuite.run(TestSuite.java:238)
	at org.eclipse.emf.cdo.tests.config.impl.ConfigTestSuite$MainSuite.run(ConfigTestSuite.java:143)
	at org.eclipse.jdt.internal.junit.runner.junit3.JUnit3TestReference.run(JUnit3TestReference.java:130)
	at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)
Caused by: org.eclipse.emf.cdo.util.CommitException: org.eclipse.net4j.signal.RemoteException: org.eclipse.net4j.util.om.monitor.MonitorCanceledException: org.eclipse.net4j.util.concurrent.TimeoutRuntimeException: Timeout after 10001 millis
	at org.eclipse.emf.internal.cdo.transaction.CDOTransactionImpl.commit(CDOTransactionImpl.java:1123)
	at org.eclipse.emf.internal.cdo.transaction.CDOTransactionImpl.commit(CDOTransactionImpl.java:1129)
	at org.eclipse.emf.cdo.tests.performance.ReadPerformanceTest.initModel(ReadPerformanceTest.java:49)
	at org.eclipse.emf.cdo.tests.performance.ReadPerformanceTest.testAll(ReadPerformanceTest.java:58)
	at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at junit.framework.TestCase.runTest(TestCase.java:168)
	at org.eclipse.net4j.util.tests.AbstractOMTest.runBare(AbstractOMTest.java:218)
	at org.eclipse.emf.cdo.tests.config.impl.ConfigTest.runBare(ConfigTest.java:526)
	... 21 more
Caused by: org.eclipse.net4j.signal.RemoteException: org.eclipse.net4j.util.om.monitor.MonitorCanceledException: org.eclipse.net4j.util.concurrent.TimeoutRuntimeException: Timeout after 10001 millis
	at org.eclipse.net4j.signal.RequestWithConfirmation.getRemoteException(RequestWithConfirmation.java:139)
	at org.eclipse.net4j.signal.RequestWithConfirmation.setRemoteException(RequestWithConfirmation.java:128)
	at org.eclipse.net4j.signal.SignalProtocol.handleRemoteException(SignalProtocol.java:460)
	at org.eclipse.net4j.signal.RemoteExceptionIndication.indicating(RemoteExceptionIndication.java:63)
	at org.eclipse.net4j.signal.Indication.doExtendedInput(Indication.java:55)
	at org.eclipse.net4j.signal.Signal.doInput(Signal.java:326)
	at org.eclipse.net4j.signal.Indication.execute(Indication.java:49)
	at org.eclipse.net4j.signal.Signal.runSync(Signal.java:251)
	at org.eclipse.net4j.signal.Signal.run(Signal.java:147)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:680)
Caused by: org.eclipse.net4j.util.om.monitor.MonitorCanceledException: org.eclipse.net4j.util.concurrent.TimeoutRuntimeException: Timeout after 10001 millis
	at org.eclipse.net4j.util.om.monitor.Monitor.checkCanceled(Monitor.java:56)
	at org.eclipse.net4j.util.om.monitor.TimeoutMonitor.checkCanceled(TimeoutMonitor.java:116)
	at org.eclipse.net4j.util.om.monitor.NestedMonitor.checkCanceled(NestedMonitor.java:55)
	at org.eclipse.net4j.util.om.monitor.NestedMonitor.checkCanceled(NestedMonitor.java:55)
	at org.eclipse.net4j.util.om.monitor.AbstractMonitor.hasBegun(AbstractMonitor.java:36)
	at org.eclipse.net4j.util.om.monitor.AbstractMonitor.checkBegun(AbstractMonitor.java:141)
	at org.eclipse.net4j.util.om.monitor.AbstractMonitor.fork(AbstractMonitor.java:65)
	at org.eclipse.net4j.util.om.monitor.ProgressDistributor.run(ProgressDistributor.java:86)
	at org.eclipse.emf.cdo.server.internal.net4j.protocol.CommitTransactionIndication.indicatingCommit(CommitTransactionIndication.java:262)
	at org.eclipse.emf.cdo.server.internal.net4j.protocol.CommitTransactionIndication.indicating(CommitTransactionIndication.java:96)
	at org.eclipse.emf.cdo.server.internal.net4j.protocol.CDOServerIndicationWithMonitoring.indicating(CDOServerIndicationWithMonitoring.java:109)
	at org.eclipse.net4j.signal.IndicationWithMonitoring.indicating(IndicationWithMonitoring.java:84)
	at org.eclipse.net4j.signal.IndicationWithResponse.doExtendedInput(IndicationWithResponse.java:90)
	at org.eclipse.net4j.signal.Signal.doInput(Signal.java:326)
	at org.eclipse.net4j.signal.IndicationWithResponse.execute(IndicationWithResponse.java:63)
	at org.eclipse.net4j.signal.IndicationWithMonitoring.execute(IndicationWithMonitoring.java:63)
	... 5 more
Caused by: org.eclipse.net4j.util.concurrent.TimeoutRuntimeException: Timeout after 10001 millis
	at org.eclipse.net4j.util.om.monitor.TimeoutMonitor.handleTimeout(TimeoutMonitor.java:121)
	at org.eclipse.net4j.util.om.monitor.TimeoutMonitor$1.handleTimeout(TimeoutMonitor.java:61)
	at org.eclipse.net4j.util.concurrent.Timeouter$1.run(Timeouter.java:88)
	at java.util.TimerThread.mainLoop(Timer.java:512)
	at java.util.TimerThread.run(Timer.java:462)


The reason for this is most likely the monitor handling in org.eclipse.emf.cdo.server.internal.mongodb.Commits.write(MongoDBStoreAccessor, InternalCommitContext, OMMonitor)

In that method, only the OMMonitor is used. For long-running library code (as, e.g., collection.insert(doc)), an additional forkAsync() should be used around it to keep the timeout monitor fresh and alive during that call.
Comment 1 Stefan Winkler CLA 2012-01-26 08:44:47 EST 
I have created a branch and corrected the most prominent case. But other MongoDB API calls might be also affected. This should be checked.

commit 383ecd8abc866df961d384dbdc8076f4c5104430
Author: Stefan Winkler <stefan@winklerweb.net> 2012-01-26 14:40:47
Committer: Stefan Winkler <stefan@winklerweb.net> 2012-01-26 14:40:47
Parent: 2e0525193ca757cf5756597a67c892dfc6a4c814 (fix time test failures with h2/linux)
Branches: committers/swinkler/performance-measurement, origin/bugs/369799, bugs/369799

[369799] [MongoDB] Monitor Timeouts during large commits 
https://bugs.eclipse.org/bugs/show_bug.cgi?id=369799
Comment 2 Eike Stepper CLA 2012-08-14 22:51:12 EDT 
Moving all open issues to 4.2. Open bugs can be ported to 4.1 maintenance after they've been fixed in master.
Comment 3 Eike Stepper CLA 2013-06-29 12:17:03 EDT 
We'll try to address open problems in 4.3 (master) first and then port fixes back to 4.2.
Comment 4 Eike Stepper CLA 2015-07-14 02:09:01 EDT 
Moving all open bugzillas to 4.5.
Comment 5 Eike Stepper CLA 2016-07-31 00:51:52 EDT 
Moving all unaddressed bugzillas to 4.6.
Comment 6 Eike Stepper CLA 2017-12-28 01:18:09 EST 
Moving all open bugs to 4.7
Comment 7 Eike Stepper CLA 2019-11-08 02:17:05 EST 
Moving all unresolved issues to version 4.8-
Comment 8 Eike Stepper CLA 2019-12-13 12:51:04 EST 
Moving all unresolved issues to version 4.9
Comment 9 Eike Stepper CLA 2020-12-11 10:45:27 EST 
Moving to 4.13.