I am using EJB Scheduler to run a task every minute. The task is to stream data (log data) from a few servers (file based server) and then persist that data to MySQL DB.
This set up works fine but on random occasions, EJB scheduler stops to process requests. I looked at the application logs and all the errors are related to JBoss container.
Here is the code which I am using for running the scheduler:
@Singleton
@LocalBean
@TransactionManagement(TransactionManagementType.BEAN)
public class MyApplicationBean {
@Schedule(minute = "*/1", hour = "*", persistent = false)
@AccessTimeout(3600000L)
public void onTimerWakeup() throws SomeApplicationException {
processSomeTask(); // this is the task to stream data from some server and persist in MySQL
}
}
Application Logs when the scheduler is hung:
01:47:38,912 ERROR [org.jboss.as.ejb3] (EJB default - 9) JBAS014122: Error during retrying timeout for timer: [id=a8842a34-90b9-4f5d-bf88-1564ccb3d8cc timedObjectId=myapplication-war-1.0.3-SNAPSHOT.myapplication-war-1.0.3-SNAPSHOT.MyApplicationBean auto-timer?:true persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@a8f72f7 initialExpiration=Fri Dec 18 00:00:00 PST 2015 intervalDuration(in milli sec)=0 nextExpiration=Mon Dec 28 10:53:00 PST 2015 timerState=ACTIVE: javax.ejb.ConcurrentAccessTimeoutException: JBAS014373: EJB 3.1 PFD2 4.8.5.5.1 concurrent access timeout on org.jboss.invocation.InterceptorContext$Invocation@7b28012d - could not obtain lock within 3600000MILLISECONDS
at org.jboss.as.ejb3.concurrency.ContainerManagedConcurrencyInterceptor.processInvocation(ContainerManagedConcurrencyInterceptor.java:100) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.tx.EjbBMTInterceptor.handleInvocation(EjbBMTInterceptor.java:104) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.as.ejb3.tx.BMTInterceptor.processInvocation(BMTInterceptor.java:56) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:52) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:101) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.as.ejb3.timerservice.task.CalendarTimerTask.callTimeout(CalendarTimerTask.java:60) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.as.ejb3.timerservice.task.TimerTask.retryTimeout(TimerTask.java:184) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:140) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0-45]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0-45]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0-45]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0-45]
at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0-45]
at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final-redhat-1.jar:2.1.1.Final-redhat-1]
From above exception, what I understand is since EJB scheduler could not obtain a lock within 3600000 milliseconds, the thread will time out which seems like an expected behavior. But what I am not able to understand is why all the EJB threads come to a complete halt? Can someone please help with this?
Env Details:
Turns out EJB threads were getting halted while creating a connection to the URL where I pull data from. In my code, I was using below code to create connection and fetch data:
InputStream in = new URL("someURL").openStream();
Since I was getting Stream directly using URL.openStream() API, I did not have a way to set connect or read timeouts, the EJB threads were getting halted here if server did not respond to connection or read requests in timely manner. From JDK documentation, I could not find specific connection or read timeout values on URL.openStream() API. It could be possible that there is a really large timeout or no timeout at all, I am not sure on this.
To resolve this problem, I am using URLConnection class to set connection and read timeout values. See below code:
URLConnection urlConnection = new Url("someURL").openConnection();
urlConnection.setConnectTimeout(2000);
urlConnection.setReadTimeout(5000);
BufferedInputStream bIn = new BufferedInputStream(urlConnection.getInputStream());
Here is a related post on timeout issues with URL.openStream() API: https://community.oracle.com/thread/1759067?start=0&tstart=0