We have General Filemover Service which is scheduled and file moves from one to other location.
We are migrating from Wildfly 10 to Wildfly 16 and facing this issue in Wildfly 16.
In Wildfly 16, It is giving strange behavior i.e when timer stuck and we disable or undeploy the deployable then servergroup stuck and we need to kill only and restart:
When Timer stuck following warnings come continuously:
2019-12-13 14:00:00,000 WARN [org.jboss.as.ejb3.timer] (EJB default - 10) WFLYEJB0043:
A previous execution of timer [id=51e7977a-722a-4b20-9db1-f3534b2e3cff
timedObjectId=filemover-1.5-SNAPSHOT-wildfly10.filemover-1.5-SNAPSHOT-wildfly10.FileMover
auto-timer?:true
persistent?:false
timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@2ac49ed5
initialExpiration=null
intervalDuration(in milli sec)=0
nextExpiration=Fri Dec 13 14:00:00 CET 2019
timerState=IN_TIMEOUT
info=null]
is still in progress,
skipping this overlapping scheduled execution at: Fri Dec 13 14:00:00 CET 2019.
Then i click on disable or undeploy in Wildfly UI and the process stuck for indefinite time.
Error: There is or more management operations running longer than expected, it may negatively impact the performance of the server. Check the Management Operations view to display the active operations.
After Undeployment or Disable logs show following message:
2019-12-13 14:05:13,225 INFO [org.jboss.modcluster] (ServerService Thread Pool -- 15) MODCLUSTER000021: All pending requests drained from default-host:/filemover-1.5-SNAPSHOT-wildfly10 in 0.0 seconds
2019-12-13 14:05:13,227 INFO [org.wildfly.extension.undertow] (ServerService Thread Pool -- 15) WFLYUT0022: Unregistered web context: '/filemover-1.5-SNAPSHOT-wildfly10' from server 'default-server'
2019-12-13 14:06:00,003 ERROR [org.jboss.as.ejb3.timer] (EJB default - 4) WFLYEJB0020: Error invoking timeout for timer: [id=4416f1bb-1d5a-4992-bfa5-b7d635136f4e timedObjectId=filemover-1.5-SNAPSHOT-wildfly10.filemover-1.5-SNAPSHOT-wildfly10.FileMover auto-timer?:true persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@2ac49ed5 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 13 14:08:00 CET 2019 timerState=IN_TIMEOUT info=null]: org.jboss.as.ejb3.component.EJBComponentUnavailableException: WFLYEJB0421: Invocation cannot proceed as component is shutting down
at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:59)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:618)
at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:99)
at org.jboss.as.ejb3.timerservice.CalendarTimerTask.invokeBeanMethod(CalendarTimerTask.java:64)
at org.jboss.as.ejb3.timerservice.CalendarTimerTask.callTimeout(CalendarTimerTask.java:53)
at org.jboss.as.ejb3.timerservice.TimerTask.run(TimerTask.java:181)
at org.jboss.as.ejb3.timerservice.TimerServiceImpl$Task$1.run(TimerServiceImpl.java:1302)
at org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:494)
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)
at org.jboss.threads.JBossThread.run(JBossThread.java:485)
After few seconds to a few minutes following error appears:
2019-12-13 14:10:13,218 ERROR [org.jboss.as.controller.management-operation] (ServerService Thread Pool -- 90) WFLYCTL0348: Timeout after [300] seconds waiting for service container stability. Operation will roll back. Step that first updated the service container was 'undeploy' at address '[("deployment" => "filemover-1.5-SNAPSHOT-wildfly10.war")]'
2019-12-13 14:10:18,218 INFO [org.jboss.as.protocol] (ServerService Thread Pool -- 93) WFLYPRT0057: cancelled task by interrupting thread Thread[ServerService Thread Pool -- 90,5,ServerService ThreadGroup]
2019-12-13 14:10:23,219 ERROR [org.jboss.as.controller.management-operation] (ServerService Thread Pool -- 90) WFLYCTL0190: Step handler org.jboss.as.server.deployment.DeploymentHandlerUtil$5@13139499 for operation undeploy at address [("deployment" => "filemover-1.5-SNAPSHOT-wildfly10.war")] failed handling operation rollback -- java.lang.IllegalStateException: WFLYCTL0345: Timeout after 5 seconds waiting for existing service service jboss.deployment.unit."filemover-1.5-SNAPSHOT-wildfly10.war".contents to be removed so a new instance can be installed.: java.lang.IllegalStateException: WFLYCTL0345: Timeout after 5 seconds waiting for existing service service jboss.deployment.unit."filemover-1.5-SNAPSHOT-wildfly10.war".contents to be removed so a new instance can be installed.
at org.jboss.as.controller.OperationContextImpl.installService(OperationContextImpl.java:2033)
at org.jboss.as.controller.OperationContextImpl.access$600(OperationContextImpl.java:133)
at org.jboss.as.controller.OperationContextImpl$2$1.installService(OperationContextImpl.java:762)
at org.jboss.as.controller.OperationContextImpl$ContextServiceBuilder.install(OperationContextImpl.java:2171)
at org.jboss.msc.service.DelegatingServiceBuilder.install(DelegatingServiceBuilder.java:104)
at org.jboss.as.server.deployment.ContentServitor.addService(ContentServitor.java:48)
at org.jboss.as.server.deployment.DeploymentHandlerUtil.doDeploy(DeploymentHandlerUtil.java:196)
at org.jboss.as.server.deployment.DeploymentHandlerUtil$5$1.handleResult(DeploymentHandlerUtil.java:388)
at org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
at org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
at org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
at org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1445)
at org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
at org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1412)
at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:423)
at org.jboss.as.controller.ModelControllerImpl.lambda$execute$1(ModelControllerImpl.java:243)
at org.wildfly.security.auth.server.SecurityIdentity.runAs(SecurityIdentity.java:289)
at org.wildfly.security.auth.server.SecurityIdentity.runAs(SecurityIdentity.java:255)
at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:243)
at org.jboss.as.controller.remote.TransactionalProtocolOperationHandler.internalExecute(TransactionalProtocolOperationHandler.java:269)
at org.jboss.as.controller.remote.TransactionalProtocolOperationHandler$ExecuteRequestHandler.doExecute(TransactionalProtocolOperationHandler.java:201)
at org.jboss.as.controller.remote.TransactionalProtocolOperationHandler$ExecuteRequestHandler$1.run(TransactionalProtocolOperationHandler.java:148)
at org.jboss.as.controller.remote.TransactionalProtocolOperationHandler$ExecuteRequestHandler$1.run(TransactionalProtocolOperationHandler.java:144)
at org.wildfly.security.auth.server.SecurityIdentity.runAs(SecurityIdentity.java:289)
at org.wildfly.security.auth.server.SecurityIdentity.runAs(SecurityIdentity.java:255)
at org.jboss.as.controller.AccessAuditContext.doAs(AccessAuditContext.java:198)
at org.jboss.as.controller.remote.TransactionalProtocolOperationHandler$ExecuteRequestHandler$2$1.get(TransactionalProtocolOperationHandler.java:172)
at org.jboss.as.controller.remote.TransactionalProtocolOperationHandler$ExecuteRequestHandler$2$1.get(TransactionalProtocolOperationHandler.java:163)
at org.jboss.as.controller.remote.TransactionalProtocolOperationHandler$Execution$1.execute(TransactionalProtocolOperationHandler.java:677)
at org.jboss.as.controller.remote.TransactionalProtocolOperationHandler$ExecuteRequestHandler$2.execute(TransactionalProtocolOperationHandler.java:177)
at org.jboss.as.protocol.mgmt.ManagementRequestContextImpl$1.doExecute(ManagementRequestContextImpl.java:70)
at org.jboss.as.protocol.mgmt.ManagementRequestContextImpl$AsyncTaskRunner.run(ManagementRequestContextImpl.java:160)
at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
at java.lang.Thread.run(Thread.java:745)
at org.jboss.threads.JBossThread.run(JBossThread.java:485)
2019-12-13 14:10:23,220 ERROR [org.jboss.as.controller.management-operation] (ServerService Thread Pool -- 90) WFLYCTL0027: Operation was interrupted before service container stability could be reached. Process should be restarted. Step that first updated the service container was 'undeploy' at address '[("deployment" => "filemover-1.5-SNAPSHOT-wildfly10.war")]'
and after that timer is stuck and warning at top keep on coming for ages.
Code (It is already according to suggestions found in searches):
@Stateless
public class FileMover {
@Schedule(hour = "*", minute = "*/15", persistent = false)
public void startJob() {
}
Can anyone suggest how to fix this or give any direction to fix this issue?
- The issue was not in Wildfly 10 i.e when timer stuck no issue with undeploy or disable.
- I have removed timer in data/timerservice folder during runtime but not fixed
- I have removed timer when deplyable not there and restart system but still this issue comes.
- This is problem with various other projects too.
- In This project, the thing found is that an exception comes i.e mail not sent and program ends fine and next time exception comes again but this time it stuck. This issue is there in another project where this coming without exception.
Talked to Wildfly Confguration Guys in company and this was purely migration related issue in Mailbox settings of Wildfly Server where recipients were not added so wildfly seems busy in finding recipients.
After adding recipients, Schedulers are working fine as well as Undeploy/Disable application without any issue.