[jboss-jira] [JBoss JIRA] (WFLY-3953) @Schedule annotation produces "Cannot invoke timeout method because method null is not a timeout method"

Jaap Reitsma (JIRA) issues at jboss.org
Sun Jan 18 17:14:49 EST 2015 

    [ https://issues.jboss.org/browse/WFLY-3953?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13033340#comment-13033340 ] 

Jaap Reitsma edited comment on WFLY-3953 at 1/18/15 5:14 PM:
-------------------------------------------------------------

I have the same issue in Wildfly 8.1.0. I have tried several configurations with the @Schedule annotation. What I noted was that the error always happens once in an hour. I suspect some idle bean removal thread is interfering? I also noted that the error message does not print the info attribute and persistence attribute correctly. My timer is set to be not persistent.

A piece of log:
{noformat} 20:45:00,048 DEBUG [nl.novay.buzzcuit.core.logging.DebugLogger] (EJB default - 9) Call: CachedItemDaoImpl.removeStaleItems(Date Sat Jan 17 20:45:00 CET 2015)
21:00:00,041 DEBUG [nl.novay.buzzcuit.core.bean.impl.CacheManagerBean] (EJB default - 10) Cache cleanup all objects before Sat Jan 17 21:00:00 CET 2015
21:00:00,045 DEBUG [nl.novay.buzzcuit.core.logging.DebugLogger] (EJB default - 10) Call: CachedItemDaoImpl.removeStaleItems(Date Sat Jan 17 21:00:00 CET 2015)
21:00:00,695 ERROR [org.jboss.as.ejb3] (EJB default - 1) JBAS014120: Error invoking timeout for timer: [id=cdec4a35-0b50-4732-9485-9e07528037a7 timedObjectId=CoreEAR.CoreEJB.cached
ItemBean auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at 39c722c6 initialExpiration=Fri Jan 16 02:00:00 CET 2015 intervalDuration(in
 milli sec)=3600000 nextExpiration=Sun Jan 18 22:00:00 CET 2015 timerState=IN_TIMEOUT info=null: java.lang.RuntimeException: JBAS014481: Cannot invoke timeout method because method
 null is not a timeout method
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:84) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:114) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.callTimeout(TimerTask.java:196) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:168) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_51]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51]
        at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]
        at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final.jar:2.1.1.Final]

21:00:00,702 INFO  [org.jboss.as.ejb3] (EJB default - 1) JBAS014121: Timer: [id=cdec4a35-0b50-4732-9485-9e07528037a7 timedObjectId=CoreEAR.CoreEJB.cachedItemBean auto-timer?:false
persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at 39c722c6 initialExpiration=Fri Jan 16 02:00:00 CET 2015 intervalDuration(in milli sec)=3600000 nextExp
iration=Sun Jan 18 22:00:00 CET 2015 timerState=IN_TIMEOUT info=null will be retried
21:00:00,703 INFO  [org.jboss.as.ejb3] (EJB default - 1) JBAS014123: Retrying timeout for timer: [id=cdec4a35-0b50-4732-9485-9e07528037a7 timedObjectId=CoreEAR.CoreEJB.cachedItemBe
an auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at 39c722c6 initialExpiration=Fri Jan 16 02:00:00 CET 2015 intervalDuration(in milli
 sec)=3600000 nextExpiration=Sun Jan 18 22:00:00 CET 2015 timerState=IN_TIMEOUT info=null
21:00:00,712 ERROR [org.jboss.as.ejb3] (EJB default - 1) JBAS014122: Error during retrying timeout for timer: [id=cdec4a35-0b50-4732-9485-9e07528037a7 timedObjectId=CoreEAR.CoreEJB
.cachedItemBean auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at 39c722c6 initialExpiration=Fri Jan 16 02:00:00 CET 2015 intervalDura
tion(in milli sec)=3600000 nextExpiration=Sun Jan 18 22:00:00 CET 2015 timerState=RETRY_TIMEOUT info=null: java.lang.RuntimeException: JBAS014481: Cannot invoke timeout method beca
use method null is not a timeout method
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:84) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:114) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.callTimeout(TimerTask.java:196) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.retryTimeout(TimerTask.java:219) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:176) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_51]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51]
        at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]
        at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final.jar:2.1.1.Final]

21:15:00,003 DEBUG [nl.novay.buzzcuit.core.bean.impl.CacheManagerBean] (EJB default - 2) Cache cleanup all objects before Sat Jan 17 21:15:00 CET 2015
21:15:00,006 DEBUG [nl.novay.buzzcuit.core.logging.DebugLogger] (EJB default - 2) Call: CachedItemDaoImpl.removeStaleItems(Date Sat Jan 17 21:15:00 CET 2015)
21:30:00,068 DEBUG [nl.novay.buzzcuit.core.bean.impl.CacheManagerBean] (EJB default - 3) Cache cleanup all objects before Sat Jan 17 21:30:00 CET 2015
21:30:00,070 DEBUG [nl.novay.buzzcuit.core.logging.DebugLogger] (EJB default - 3) Call: CachedItemDaoImpl.removeStaleItems(Date Sat Jan 17 21:30:00 CET 2015)
21:45:00,096 DEBUG [nl.novay.buzzcuit.core.bean.impl.CacheManagerBean] (EJB default - 4) Cache cleanup all objects before Sat Jan 17 21:45:00 CET 2015
21:45:00,097 DEBUG [nl.novay.buzzcuit.core.logging.DebugLogger] (EJB default - 4) Call: CachedItemDaoImpl.removeStaleItems(Date Sat Jan 17 21:45:00 CET 2015)
22:00:00,042 DEBUG [nl.novay.buzzcuit.core.bean.impl.CacheManagerBean] (EJB default - 5) Cache cleanup all objects before Sat Jan 17 22:00:00 CET 2015
22:00:00,044 DEBUG [nl.novay.buzzcuit.core.logging.DebugLogger] (EJB default - 5) Call: CachedItemDaoImpl.removeStaleItems(Date Sat Jan 17 22:00:00 CET 2015)
22:00:00,697 ERROR [org.jboss.as.ejb3] (EJB default - 6) JBAS014120: Error invoking timeout for timer: [id=cdec4a35-0b50-4732-9485-9e07528037a7 timedObjectId=CoreEAR.CoreEJB.cached
ItemBean auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at 39c722c6 initialExpiration=Fri Jan 16 02:00:00 CET 2015 intervalDuration(in
 milli sec)=3600000 nextExpiration=Sun Jan 18 23:00:00 CET 2015 timerState=IN_TIMEOUT info=null: java.lang.RuntimeException: JBAS014481: Cannot invoke timeout method because method
 null is not a timeout method
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:84) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:114) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.callTimeout(TimerTask.java:196) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:168) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
{noformat}


was (Author: reitsmaj):
I have the same issue in Wildfly 8.1.0. I have tried several configurations with the @Schedule annotation. What I noted was that the error always happens once in an hour. I suspect some idle bean removal thread is interfering? I also noted that the error message does not print the info attribute and persistence attribute correctly. My timer is set to be not persistent.

A piece of log:
{{ 20:45:00,048 DEBUG [nl.novay.buzzcuit.core.logging.DebugLogger] (EJB default - 9) Call: CachedItemDaoImpl.removeStaleItems(Date Sat Jan 17 20:45:00 CET 2015)
21:00:00,041 DEBUG [nl.novay.buzzcuit.core.bean.impl.CacheManagerBean] (EJB default - 10) Cache cleanup all objects before Sat Jan 17 21:00:00 CET 2015
21:00:00,045 DEBUG [nl.novay.buzzcuit.core.logging.DebugLogger] (EJB default - 10) Call: CachedItemDaoImpl.removeStaleItems(Date Sat Jan 17 21:00:00 CET 2015)
21:00:00,695 ERROR [org.jboss.as.ejb3] (EJB default - 1) JBAS014120: Error invoking timeout for timer: [id=cdec4a35-0b50-4732-9485-9e07528037a7 timedObjectId=CoreEAR.CoreEJB.cached
ItemBean auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at 39c722c6 initialExpiration=Fri Jan 16 02:00:00 CET 2015 intervalDuration(in
 milli sec)=3600000 nextExpiration=Sun Jan 18 22:00:00 CET 2015 timerState=IN_TIMEOUT info=null: java.lang.RuntimeException: JBAS014481: Cannot invoke timeout method because method
 null is not a timeout method
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:84) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:114) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.callTimeout(TimerTask.java:196) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:168) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_51]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51]
        at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]
        at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final.jar:2.1.1.Final]

21:00:00,702 INFO  [org.jboss.as.ejb3] (EJB default - 1) JBAS014121: Timer: [id=cdec4a35-0b50-4732-9485-9e07528037a7 timedObjectId=CoreEAR.CoreEJB.cachedItemBean auto-timer?:false
persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at 39c722c6 initialExpiration=Fri Jan 16 02:00:00 CET 2015 intervalDuration(in milli sec)=3600000 nextExp
iration=Sun Jan 18 22:00:00 CET 2015 timerState=IN_TIMEOUT info=null will be retried
21:00:00,703 INFO  [org.jboss.as.ejb3] (EJB default - 1) JBAS014123: Retrying timeout for timer: [id=cdec4a35-0b50-4732-9485-9e07528037a7 timedObjectId=CoreEAR.CoreEJB.cachedItemBe
an auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at 39c722c6 initialExpiration=Fri Jan 16 02:00:00 CET 2015 intervalDuration(in milli
 sec)=3600000 nextExpiration=Sun Jan 18 22:00:00 CET 2015 timerState=IN_TIMEOUT info=null
21:00:00,712 ERROR [org.jboss.as.ejb3] (EJB default - 1) JBAS014122: Error during retrying timeout for timer: [id=cdec4a35-0b50-4732-9485-9e07528037a7 timedObjectId=CoreEAR.CoreEJB
.cachedItemBean auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at 39c722c6 initialExpiration=Fri Jan 16 02:00:00 CET 2015 intervalDura
tion(in milli sec)=3600000 nextExpiration=Sun Jan 18 22:00:00 CET 2015 timerState=RETRY_TIMEOUT info=null: java.lang.RuntimeException: JBAS014481: Cannot invoke timeout method beca
use method null is not a timeout method
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:84) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:114) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.callTimeout(TimerTask.java:196) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.retryTimeout(TimerTask.java:219) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:176) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_51]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51]
        at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]
        at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final.jar:2.1.1.Final]

21:15:00,003 DEBUG [nl.novay.buzzcuit.core.bean.impl.CacheManagerBean] (EJB default - 2) Cache cleanup all objects before Sat Jan 17 21:15:00 CET 2015
21:15:00,006 DEBUG [nl.novay.buzzcuit.core.logging.DebugLogger] (EJB default - 2) Call: CachedItemDaoImpl.removeStaleItems(Date Sat Jan 17 21:15:00 CET 2015)
21:30:00,068 DEBUG [nl.novay.buzzcuit.core.bean.impl.CacheManagerBean] (EJB default - 3) Cache cleanup all objects before Sat Jan 17 21:30:00 CET 2015
21:30:00,070 DEBUG [nl.novay.buzzcuit.core.logging.DebugLogger] (EJB default - 3) Call: CachedItemDaoImpl.removeStaleItems(Date Sat Jan 17 21:30:00 CET 2015)
21:45:00,096 DEBUG [nl.novay.buzzcuit.core.bean.impl.CacheManagerBean] (EJB default - 4) Cache cleanup all objects before Sat Jan 17 21:45:00 CET 2015
21:45:00,097 DEBUG [nl.novay.buzzcuit.core.logging.DebugLogger] (EJB default - 4) Call: CachedItemDaoImpl.removeStaleItems(Date Sat Jan 17 21:45:00 CET 2015)
22:00:00,042 DEBUG [nl.novay.buzzcuit.core.bean.impl.CacheManagerBean] (EJB default - 5) Cache cleanup all objects before Sat Jan 17 22:00:00 CET 2015
22:00:00,044 DEBUG [nl.novay.buzzcuit.core.logging.DebugLogger] (EJB default - 5) Call: CachedItemDaoImpl.removeStaleItems(Date Sat Jan 17 22:00:00 CET 2015)
22:00:00,697 ERROR [org.jboss.as.ejb3] (EJB default - 6) JBAS014120: Error invoking timeout for timer: [id=cdec4a35-0b50-4732-9485-9e07528037a7 timedObjectId=CoreEAR.CoreEJB.cached
ItemBean auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at 39c722c6 initialExpiration=Fri Jan 16 02:00:00 CET 2015 intervalDuration(in
 milli sec)=3600000 nextExpiration=Sun Jan 18 23:00:00 CET 2015 timerState=IN_TIMEOUT info=null: java.lang.RuntimeException: JBAS014481: Cannot invoke timeout method because method
 null is not a timeout method
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:84) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:114) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.callTimeout(TimerTask.java:196) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
        at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:168) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final] }}

> @Schedule annotation produces "Cannot invoke timeout method because method null is not a timeout method"
> --------------------------------------------------------------------------------------------------------
>
>                 Key: WFLY-3953
>                 URL: https://issues.jboss.org/browse/WFLY-3953
>             Project: WildFly
>          Issue Type: Bug
>          Components: EJB
>    Affects Versions: 8.1.0.Final
>            Reporter: Andrei Tchijov
>            Assignee: Stuart Douglas
>
> Please take a look at this gist : https://gist.github.com/leapingbytes/01838d9534638cb04200
> In case of @Schedule second and all consecutive invocations produce this 
> {code}
> 13:19:30,635 ERROR U(       ) [org.jboss.as.ejb3] (EJB default - 8) JBAS014120: Error invoking timeout for timer: [id=ba9f1c67-5a91-42ff-8276-f715efaa3723 timedObjectId=ChumbaServer-2.0-SNAPSHOT.ChumbaServer-2.0-SNAPSHOT.SettingsManagerImpl auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at 5a898863 initialExpiration=Wed Oct 08 13:17:30 EEST 2014 intervalDuration(in milli sec)=60000 nextExpiration=Wed Oct 08 13:20:30 EEST 2014 timerState=IN_TIMEOUT info=null: java.lang.RuntimeException: JBAS014481: Cannot invoke timeout method because method null is not a timeout method
> 	at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:84) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
> 	at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:114) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
> 	at org.jboss.as.ejb3.timerservice.task.TimerTask.callTimeout(TimerTask.java:196) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
> 	at org.jboss.as.ejb3.timerservice.task.TimerTask.run(TimerTask.java:168) [wildfly-ejb3-8.1.0.Final.jar:8.1.0.Final]
> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_67]
> 	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_67]
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_67]
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_67]
> 	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_67]
> 	at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final.jar:2.1.1.Final]
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.11#6341)

More information about the jboss-jira mailing list