Wildfly9: cancelled ejb timers persist in data/timer-service-data

[jrwhitley]

I have a Singleton bean whch creates a elb.timer on deployment. Before doing so it cancels any existing timers previously created by the bean for completeness.

In wildfly 8 the cancelled timers were removed from data/timer-service-data/'bean'. In wildfly 9 CR1, they stay in data/timer-service-data/'bean' and appear to be re-instated on re-deployment

This is an example of a timer previously cancelled

2015-06-11 16:04:49,788 INFO  [TravelSingleton] (EJB default - 2) initialise: timer [id=8cd3a667-9a89-4919-99c1-34906a7a1e75 timedObjectId=travel5.travel5-ejb.TravelSingleton auto-timer?:false persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@50b7224f initialExpiration=Tue May 05 15:08:41 BST 2015 intervalDuration(in milli sec)=5000 nextExpiration=Tue May 05 15:47:41 BST 2015 timerState=ACTIVE info=TravelSingleton] TravelSingleton

Since I cancel them, it is not actually interferring with my functionality but is this to be expcted?

[jaikiran]

John Whitley wrote:

This is an example of a timer previously cancelled

2015-06-11 16:04:49,788 INFO  [TravelSingleton] (EJB default - 2) initialise: timer [id=8cd3a667-9a89-4919-99c1-34906a7a1e75 timedObjectId=travel5.travel5-ejb.TravelSingleton auto-timer?:false persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@50b7224f initialExpiration=Tue May 05 15:08:41 BST 2015 intervalDuration(in milli sec)=5000 nextExpiration=Tue May 05 15:47:41 BST 2015 timerState=ACTIVE info=TravelSingleton] TravelSingleton

What API(s) are you using to fetch that information and log? Can you post relevant code?

Also, can you try this against 9.0.0.CR2 which has been released today Announcement: WildFly 9.0.2.Final released and see if it reproducible on that too?

[jrwhitley]

I've switched to 9.0.0.CR2 and the timers are still left in data/timer-service-date.

The code is:

	private final static String TIMERID = "TravelSingleton";
	@Resource
	private SessionContext context;
	public static final int TIMER_TICK = 5;

	@PostConstruct
	@Lock(LockType.WRITE)

	public void initialise() {
	TimerService timerService = context.getTimerService();
	logger.info("initialise: create timerService: " + timerService);
//	maps = Collections.synchronizedMap(new HashMap<Integer, MapObject>(97));

// Timers persist across deployments: cancel any we recognise and create a new one

	Collection<Timer> t = timerService.getTimers();
	for (Timer timer : t) {
	logger.info("initialise: timer " + timer + " " + timer.getInfo());
	String info = (String) timer.getInfo();
	if (info.equals(TIMERID)) {
	timer.cancel();
	logger.info("initialise: kill");
	}
	}
	timerService.createTimer(60000, TIMER_TICK * 1000, TIMERID);   // tick every 5 seconds after 60 seconds
	}

When I deploy this is the relevant part of the log:

2015-06-12 09:42:45,773 INFO  [org.jboss.as.ejb3] (MSC service thread 1-1) WFLYEJB0042: Started message driven bean 'TravelMsgBean' with 'hornetq-ra.rar' resource adapter

2015-06-12 09:42:45,781 INFO  [org.jboss.as.webservices] (MSC service thread 1-8) WFLYWS0003: Starting service jboss.ws.endpoint."travel5.ear"."travel5-ejb.jar".TravelWebService

2015-06-12 09:42:45,995 INFO  [TravelSingleton] (ServerService Thread Pool -- 86) initialise: create timerService: org.jboss.as.ejb3.timerservice.TimerServiceImpl@1dd69111

2015-06-12 09:42:46,000 INFO  [TravelSingleton] (ServerService Thread Pool -- 86) initialise: timer [id=65ab0fa3-abeb-4750-836d-dd594ef99e33 timedObjectId=travel5.travel5-ejb.TravelSingleton auto-timer?:false persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@1dd69111 initialExpiration=Fri Jun 12 09:42:49 BST 2015 intervalDuration(in milli sec)=5000 nextExpiration=Fri Jun 12 09:42:49 BST 2015 timerState=ACTIVE info=TravelSingleton] TravelSingleton

2015-06-12 09:42:46,001 INFO  [TravelSingleton] (ServerService Thread Pool -- 86) initialise: kill

2015-06-12 09:42:46,001 INFO  [TravelSingleton] (ServerService Thread Pool -- 86) initialise: timer [id=6bf6354e-204d-4f30-9071-4c05efb7cd4f timedObjectId=travel5.travel5-ejb.TravelSingleton auto-timer?:false persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@1dd69111 initialExpiration=Thu Jun 11 16:48:14 BST 2015 intervalDuration(in milli sec)=5000 nextExpiration=Fri Jun 12 09:42:49 BST 2015 timerState=IN_TIMEOUT info=TravelSingleton] TravelSingleton

2015-06-12 09:42:46,001 INFO  [TravelSingleton] (ServerService Thread Pool -- 86) initialise: kill

2015-06-12 09:42:46,011 INFO  [org.wildfly.extension.undertow] (ServerService Thread Pool -- 86) WFLYUT0021: Registered web context: /travel5-ejb

and this is in data:

ll /opt/wildfly9/trvj/data/timer-service-data/travel5.travel5-ejb.TravelSingleton/

total 12

-rw-rw-r-- 1 trvj PDEV 394 Jun 12 09:41 65ab0fa3-abeb-4750-836d-dd594ef99e33.xml

-rw-rw-r-- 1 trvj PDEV 394 Jun 11 16:47 6bf6354e-204d-4f30-9071-4c05efb7cd4f.xml

-rw-rw-r-- 1 trvj PDEV 394 Jun 12 09:42 ebdf4e77-e17a-4d5d-8ed5-59f02e784930.xml

I am amending my code to pick up the persisted timer but it just make it a bit more inconvienient if I wish to change the timer parameters

[jaikiran]

So just to understand this completely - you are still seeing those files for those timers that you cancelled, *after* the (transactional) method (@PostConstruct in this case) has completed its execution?

[jrwhitley]

Yes thats true

[jaikiran]

Can you please create a JIRA for this here WildFly - JBoss Issue Tracker and attach a simple application to reproduce this? Someone should then be able to look into it.