-
Type: Bug
-
Status: Resolved
-
Priority: Major
-
Resolution: Fixed
-
Affects Version/s: None
-
Fix Version/s: 9.3
-
Component/s: Events / Works, Runtime
-
Epic Link:
-
Tags:
-
Sprint:nxcore 9.3.4
-
Story Points:2
We want to improve AsyncEventExecutor exception handling in order to not log expected error as ERROR. See the current error below:
2017-08-21 17:33:39,252 ERROR [Nuxeo-Work-default-2:170133511393893.2079590158] [org.nuxeo.ecm.core.event.impl.AsyncEventExecutor] Failed to execute async event default on listener notificationListener org.nuxeo.ecm.core.api.NuxeoException: javax.resource.ResourceException: Interrupted while requesting permit. at org.nuxeo.ecm.core.storage.sql.ra.ConnectionFactoryImpl.getConnection(ConnectionFactoryImpl.java:117) at org.nuxeo.ecm.core.storage.sql.ra.ConnectionFactoryImpl.getSession(ConnectionFactoryImpl.java:166) at org.nuxeo.ecm.core.repository.RepositoryService.getSession(RepositoryService.java:204) at org.nuxeo.ecm.core.api.local.LocalSession.createSession(LocalSession.java:127) at org.nuxeo.ecm.core.api.local.LocalSession.<init>(LocalSession.java:84) at org.nuxeo.ecm.core.api.CoreSessionServiceImpl.createCoreSession(CoreSessionServiceImpl.java:43) at org.nuxeo.ecm.core.api.CoreInstance.openCoreSession(CoreInstance.java:163) at org.nuxeo.ecm.core.api.CoreInstance.openCoreSessionSystem(CoreInstance.java:98) at org.nuxeo.ecm.core.event.impl.ReconnectedEventBundleImpl.getReconnectedCoreSession(ReconnectedEventBundleImpl.java:93) at org.nuxeo.ecm.core.event.impl.ReconnectedEventBundleImpl.getReconnectedEvents(ReconnectedEventBundleImpl.java:111) at org.nuxeo.ecm.core.event.impl.ReconnectedEventBundleImpl.iterator(ReconnectedEventBundleImpl.java:222) at org.nuxeo.ecm.platform.ec.notification.NotificationEventListener.handleEvent(NotificationEventListener.java:108) at org.nuxeo.ecm.core.event.impl.AsyncEventExecutor$ListenerWork.work(AsyncEventExecutor.java:218) at org.nuxeo.ecm.core.work.AbstractWork.runWorkWithTransaction(AbstractWork.java:373) at org.nuxeo.ecm.core.work.AbstractWork.run(AbstractWork.java:332) at org.nuxeo.ecm.core.work.WorkHolder.run(WorkHolder.java:57) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: javax.resource.ResourceException: Interrupted while requesting permit. at org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.getConnection(AbstractSinglePoolConnectionInterceptor.java:97) at org.nuxeo.runtime.jtajca.NuxeoPool$1.getConnection(NuxeoPool.java:66) at org.apache.geronimo.connector.outbound.ThreadLocalCachingConnectionInterceptor.getConnection(ThreadLocalCachingConnectionInterceptor.java:70) at org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:49) at org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:101) at org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.getConnection(ConnectionHandleInterceptor.java:43) at org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39) at org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:66) at org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:77) at org.nuxeo.runtime.jtajca.NuxeoContainer$ConnectionManagerWrapper.allocateConnection(NuxeoContainer.java:764) at org.nuxeo.ecm.core.storage.sql.ra.ConnectionFactoryImpl.getConnection(ConnectionFactoryImpl.java:103) ... 18 more Caused by: java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1326) at java.util.concurrent.Semaphore.tryAcquire(Semaphore.java:409) at org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.getConnection(AbstractSinglePoolConnectionInterceptor.java:78) ... 28 more
When we have a look at code logging this error:
@Override public void cleanUp(boolean ok, Exception e) { super.cleanUp(ok, e); bundle.disconnect(); if (e != null && !(e instanceof InterruptedException) && !(e instanceof ConcurrentUpdateException)) { log.error("Failed to execute async event " + bundle.getName() + " on listener " + listenerName, e); } if (listener != null) { EventStats stats = Framework.getLocalService(EventStats.class); if (stats != null) { stats.logAsyncExec(listener, System.currentTimeMillis() - getStartTime()); } listener = null; } }
The method should handle the InterruptedException present in the exception cause.
- is required by
-
NXP-23324 Handle interrupted states correctly
- Open