Bug in EJB 2.1 Timed Services
keesvandieren Mar 30, 2004 8:54 AMHello,
I am using the timer service from the EJB 2.1 spec, using Jboss 4 DR 3. It works, as far as the ejbtimeout is called, but after that, an exception with a very big exception trace occurs.
I know it is a development release, I post this because it might have some added value for the developer.
May Timed Bean:
/** * *SkuTimerBean.java * *Created on 30-mrt-2004 * * * Copyright (c) MP Objects * All rights reserved * @author Kees van Dieren * $Id: $ */ package com.mpobjects.ime.core.ejb; import java.rmi.RemoteException; import javax.ejb.CreateException; import javax.ejb.EJBException; import javax.ejb.SessionBean; import javax.ejb.SessionContext; import javax.ejb.TimedObject; import javax.ejb.Timer; /** * @ejb.bean name="SkuTimer" * jndi-name="SkuTimerBean" * type="Stateless" * **/ public class SkuTimerBean implements SessionBean, TimedObject { private SessionContext theContext; private Timer theTimer; /** * @ejb.create-method * view-type="local" **/ public void ejbCreate() throws CreateException {} /** * @ejb.interface-method * view-type="local" **/ public void startTimer() { System.out.println("SkuTimerBean.startTimer called"); this.theTimer = this.theContext.getTimerService().createTimer(10 * 1000, "Created the timer"); System.out.println("SkuTimerBean.startTimer: timer started"); } /** * @ejb.interface-method * view-type="local" **/ public void stopTimer(){ if (this.theTimer != null) this.theTimer.cancel(); } public void ejbTimeout(Timer aTimer) { System.out.println("SkuTimerBean.ejbTimeout called"); } public void ejbActivate() throws EJBException, RemoteException { System.out.println("skuTimerBean.ejbActivate"); } public void ejbPassivate() throws EJBException, RemoteException { System.out.println("skuTimerBean.ejbPassivate"); } public void ejbRemove() throws EJBException, RemoteException { } public void setSessionContext(SessionContext aContext) throws EJBException, RemoteException { this.theContext = aContext; } }
[hr/]
Call of the bean (using localhome interface):
try { (SkuTimerUtil.getLocalHome().create()).startTimer(); } catch(Throwable myEx) { myEx.printStackTrace(); }
The code of SkuTimerUtil:
/** * *SkuTimerUtil.java * *Created on 30-mrt-2004 * * * Copyright (c) MP Objects * All rights reserved * @author Kees van Dieren * $Id: $ */ package com.mpobjects.ime.core.ejb; /** * Created on 30-mrt-2004 * * Copyright (c) MP Objects 1999 - 2004 * All rights reserved * @author Kees van Dieren <kees.vandieren@mp-objects.com> * com.mpobjects.ime.core.ejb.SkuTimerUtil * * @todo add documentation for com.mpobjects.ime.core.ejb.SkuTimerUtil */ public class SkuTimerUtil { /** Cached remote home (EJBHome). Uses lazy loading to obtain its value (loaded by getHome() methods). */ private static com.mpobjects.ime.core.ejb.SkuTimerHome cachedRemoteHome = null; /** Cached local home (EJBLocalHome). Uses lazy loading to obtain its value (loaded by getLocalHome() methods). */ private static com.mpobjects.ime.core.ejb.SkuTimerLocalHome cachedLocalHome = null; // Home interface lookup methods /** * Obtain remote home interface from default initial context * @return Home interface for SkuTimer. Lookup using COMP_NAME */ public static com.mpobjects.ime.core.ejb.SkuTimerHome getHome() throws javax.naming.NamingException { if (cachedRemoteHome == null) { // Obtain initial context javax.naming.InitialContext initialContext = new javax.naming.InitialContext(); try { java.lang.Object objRef = initialContext.lookup(com.mpobjects.ime.core.ejb.SkuTimerHome.COMP_NAME); cachedRemoteHome = (com.mpobjects.ime.core.ejb.SkuTimerHome) javax.rmi.PortableRemoteObject.narrow(objRef, com.mpobjects.ime.core.ejb.SkuTimerHome.class); } finally { initialContext.close(); } } return cachedRemoteHome; } /** * Obtain remote home interface from parameterised initial context * @param environment Parameters to use for creating initial context * @return Home interface for SkuTimer. Lookup using COMP_NAME */ public static com.mpobjects.ime.core.ejb.SkuTimerHome getHome( java.util.Hashtable environment ) throws javax.naming.NamingException { // Obtain initial context javax.naming.InitialContext initialContext = new javax.naming.InitialContext(environment); try { java.lang.Object objRef = initialContext.lookup(com.mpobjects.ime.core.ejb.SkuTimerHome.COMP_NAME); return (com.mpobjects.ime.core.ejb.SkuTimerHome) javax.rmi.PortableRemoteObject.narrow(objRef, com.mpobjects.ime.core.ejb.SkuTimerHome.class); } finally { initialContext.close(); } } /** * Obtain local home interface from default initial context * @return Local home interface for SkuTimer. Lookup using COMP_NAME */ public static com.mpobjects.ime.core.ejb.SkuTimerLocalHome getLocalHome() throws javax.naming.NamingException { // Local homes shouldn't be narrowed, as there is no RMI involved. if (cachedLocalHome == null) { // Obtain initial context javax.naming.InitialContext initialContext = new javax.naming.InitialContext(); try { cachedLocalHome = (com.mpobjects.ime.core.ejb.SkuTimerLocalHome) initialContext.lookup(com.mpobjects.ime.core.ejb.SkuTimerLocalHome.JNDI_NAME); } finally { initialContext.close(); } } return cachedLocalHome; } /** Cached per JVM server IP. */ private static String hexServerIP = null; // initialise the secure random instance private static final java.security.SecureRandom seeder = new java.security.SecureRandom(); /** * A 32 byte GUID generator (Globally Unique ID). These artificial keys SHOULD <strong>NOT </strong> be seen by the user, * not even touched by the DBA but with very rare exceptions, just manipulated by the database and the programs. * * Usage: Add an id field (type java.lang.String) to your EJB, and add setId(XXXUtil.generateGUID(this)); to the ejbCreate method. */ public static final String generateGUID(Object o) { StringBuffer tmpBuffer = new StringBuffer(16); if (hexServerIP == null) { java.net.InetAddress localInetAddress = null; try { // get the inet address localInetAddress = java.net.InetAddress.getLocalHost(); } catch (java.net.UnknownHostException uhe) { System.err.println("SkuTimerUtil: Could not get the local IP address using InetAddress.getLocalHost()!"); // todo: find better way to get around this... uhe.printStackTrace(); return null; } byte serverIP[] = localInetAddress.getAddress(); hexServerIP = hexFormat(getInt(serverIP), 8); } String hashcode = hexFormat(System.identityHashCode(o), 8); tmpBuffer.append(hexServerIP); tmpBuffer.append(hashcode); long timeNow = System.currentTimeMillis(); int timeLow = (int)timeNow & 0xFFFFFFFF; int node = seeder.nextInt(); StringBuffer guid = new StringBuffer(32); guid.append(hexFormat(timeLow, 8)); guid.append(tmpBuffer.toString()); guid.append(hexFormat(node, 8)); return guid.toString(); } private static int getInt(byte bytes[]) { int i = 0; int j = 24; for (int k = 0; j >= 0; k++) { int l = bytes[k] & 0xff; i += l << j; j -= 8; } return i; } private static String hexFormat(int i, int j) { String s = Integer.toHexString(i); return padHex(s, j) + s; } private static String padHex(String s, int i) { StringBuffer tmpBuffer = new StringBuffer(); if (s.length() < i) { for (int j = 0; j < i - s.length(); j++) { tmpBuffer.append('0'); } } return tmpBuffer.toString(); } }
Code of LocalHome interface:
/* * Generated by XDoclet - Do not edit! */ package com.mpobjects.ime.core.ejb; /** * Local home interface for SkuTimer. * @lomboz generated */ public interface SkuTimerLocalHome extends javax.ejb.EJBLocalHome { public static final String COMP_NAME="java:comp/env/ejb/SkuTimerLocal"; public static final String JNDI_NAME="SkuTimerLocal"; public com.mpobjects.ime.core.ejb.SkuTimerLocal create() throws javax.ejb.CreateException; }
The exception stacktrace (from server.log file):
2004-03-30 16:36:28,775 DEBUG [javax.management.timer.Timer] new RegisteredNotification: [timer=jboss:service=Timer,id=1,startDate=Tue Mar 30 16:36:38 CEST 2004,periode=0,occurences=1,nextDate=Tue Mar 30 16:36:38 CEST 2004] 2004-03-30 16:36:28,785 DEBUG [org.jboss.varia.scheduler.ScheduleManager$ScheduleInstance] start(), add Notification to Timer with ID: 1 2004-03-30 16:36:28,785 DEBUG [org.jboss.ejb.timer.SchedulerTimerSource] Call add() on : jboss:service=TimePersistenceManager,type=File, container id: jboss.j2ee:jndiName=SkuTimerBean,service=EJB, id: 0 2004-03-30 16:36:28,795 INFO [org.jboss.ejb.timer.FilePersistenceManager] Create Output file: 0, for container: jboss.j2ee:jndiName=SkuTimerBean,service=EJB 2004-03-30 16:36:28,795 DEBUG [org.jboss.ejb.timer.FilePersistenceManager] Write Timer Item to output file: FilePersistenceManager.TimerItem [ , type: ADD, timer rep: ContainerTimerRepresentative [ Id: 0, key: null, start date: Tue Mar 30 16:36:38 CEST 2004, interval: single timer, info: Created the timer ] ] 2004-03-30 16:36:38,770 DEBUG [javax.management.timer.Timer] sendNotification: RegisteredNotification: [timer=jboss:service=Timer,id=1,startDate=Tue Mar 30 16:36:38 CEST 2004,periode=0,occurences=1,nextDate=Tue Mar 30 16:36:38 CEST 2004] 2004-03-30 16:36:38,770 DEBUG [org.jboss.varia.scheduler.ScheduleManager$MBeanListener] MBeanListener.handleNotification(), notification: javax.management.timer.TimerNotification: type=Schedule source=jboss:service=Timer sequence=1 time=1080657398765 message=Scheduler Notification id=1 userData=0 2004-03-30 16:36:38,770 DEBUG [org.jboss.varia.scheduler.ScheduleManager$MBeanListener] Scheduler is started: true 2004-03-30 16:36:38,770 DEBUG [org.jboss.varia.scheduler.ScheduleManager$MBeanListener] MBean Arguments are: [0, Tue Mar 30 16:36:38 CEST 2004] 2004-03-30 16:36:38,770 DEBUG [org.jboss.varia.scheduler.ScheduleManager$MBeanListener] MBean Arguments Types are: [java.lang.Integer, java.util.Date] 2004-03-30 16:36:38,770 DEBUG [org.jboss.varia.scheduler.ScheduleManager$MBeanListener] invoke(jboss:service=EJBTimerService, handleTimedEvent 2004-03-30 16:36:38,770 DEBUG [org.jboss.ejb.timer.ContainerTimerService] handleTimedEvent(), this: org.jboss.ejb.timer.ContainerTimerService@9cd006, call timer: org.jboss.ejb.timer.ContainerTimer@11d75b9, container: org.jboss.ejb.StatelessSessionContainer@11bf785 2004-03-30 16:36:38,770 INFO [STDOUT] SkuTimerBean.ejbTimeout called 2004-03-30 16:36:38,770 DEBUG [org.jboss.ejb.timer.ContainerTimerService] cancel(), cancel timer: 0 2004-03-30 16:36:38,770 DEBUG [org.jboss.ejb.timer.SchedulerTimerSource] Remove timer: 0, of container: jboss.j2ee:jndiName=SkuTimerBean,service=EJB 2004-03-30 16:36:38,770 DEBUG [org.jboss.ejb.timer.FilePersistenceManager] remove(), container: jboss.j2ee:jndiName=SkuTimerBean,service=EJB, id: 0, timer list: {0=FilePersistenceManager.TimerItem [ , type: ADD, timer rep: ContainerTimerRepresentative [ Id: 0, key: null, start date: Tue Mar 30 16:36:38 CEST 2004, interval: single timer, info: Created the timer ] ], 4=FilePersistenceManager.TimerItem [ , type: ADD, timer rep: ContainerTimerRepresentative [ Id: 4, key: [B@189c036, start date: Tue Mar 30 16:19:29 CEST 2004, interval: single timer, info: [B@1f01a29 ] ], 5=FilePersistenceManager.TimerItem [ , type: ADD, timer rep: ContainerTimerRepresentative [ Id: 5, key: [B@458f41, start date: Tue Mar 30 16:19:29 CEST 2004, interval: single timer, info: [B@c01e99 ] ], 6=FilePersistenceManager.TimerItem [ , type: ADD, timer rep: ContainerTimerRepresentative [ Id: 6, key: [B@118fa47, start date: Tue Mar 30 16:26:04 CEST 2004, interval: single timer, info: [B@d75415 ] ], 7=FilePersistenceManager.TimerItem [ , type: ADD, timer rep: ContainerTimerRepresentative [ Id: 7, key: [B@d16fc1, start date: Tue Mar 30 16:26:04 CEST 2004, interval: single timer, info: [B@1eb0 ] ], 8=FilePersistenceManager.TimerItem [ , type: ADD, timer rep: ContainerTimerRepresentative [ Id: 8, key: [B@1dee400, start date: Tue Mar 30 16:31:20 CEST 2004, interval: single timer, info: [B@4ac216 ] ], 9=FilePersistenceManager.TimerItem [ , type: ADD, timer rep: ContainerTimerRepresentative [ Id: 9, key: [B@c5e9c, start date: Tue Mar 30 16:33:29 CEST 2004, interval: single timer, info: [B@1777b1 ] ]}, output: org.jboss.ejb.timer.FilePersistenceManager$MyObjectOutputStream@1346812 2004-03-30 16:36:38,780 INFO [org.jboss.ejb.timer.FilePersistenceManager] Write remove timer to file: FilePersistenceManager.TimerItem [ , type: REMOVE, timer rep: null ] 2004-03-30 16:36:38,850 DEBUG [org.jboss.varia.scheduler.ScheduleManager$ScheduleInstance] stopSchedule(), notification id: 1 2004-03-30 16:36:38,850 DEBUG [javax.management.timer.Timer] removeNotification: jboss:service=Timer,id=1 2004-03-30 16:36:38,850 DEBUG [org.jboss.varia.scheduler.ScheduleManager$MBeanListener] Remaining Repititions: 0, wait for next call to stop: false 2004-03-30 16:36:38,850 DEBUG [org.jboss.varia.scheduler.ScheduleManager$ScheduleInstance] stopSchedule(), notification id: 1 2004-03-30 16:36:38,850 ERROR [org.jboss.varia.scheduler.ScheduleManager$MBeanListener] Handling a Scheduler call failed javax.management.ListenerNotFoundException: Listener not found org.jboss.varia.scheduler.ScheduleManager$MBeanListener@128ed5f for object name jboss:service=Timer at org.jboss.mx.notification.MBeanServerListenerRegistry.remove(MBeanServerListenerRegistry.java:139) at org.jboss.mx.server.MBeanServerImpl.removeNotificationListener(MBeanServerImpl.java:603) at org.jboss.varia.scheduler.ScheduleManager$ScheduleInstance.stop(ScheduleManager.java:835) at org.jboss.varia.scheduler.ScheduleManager$MBeanListener.handleNotification(ScheduleManager.java:612) at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at org.jboss.mx.notification.NotificationListenerProxy.invoke(NotificationListenerProxy.java:138) at $Proxy9.handleNotification(Unknown Source) at javax.management.NotificationBroadcasterSupport.handleNotification(NotificationBroadcasterSupport.java:98) at javax.management.NotificationBroadcasterSupport.sendNotification(NotificationBroadcasterSupport.java:83) at javax.management.timer.Timer.sendNotifications(Timer.java:496) at javax.management.timer.Timer.access$100(Timer.java:32) at javax.management.timer.Timer$RegisteredNotification.doRun(Timer.java:666) at org.jboss.mx.util.SchedulableRunnable.run(SchedulableRunnable.java:175) at org.jboss.mx.util.ThreadPool$Worker.run(ThreadPool.java:238) 2004-03-30 16:36:38,850 DEBUG [javax.management.timer.Timer] remove: RegisteredNotification: [timer=jboss:service=Timer,id=1,startDate=Tue Mar 30 16:36:38 CEST 2004,periode=0,occurences=1,nextDate=Thu Jan 01 01:00:00 CET 1970] 2004-03-30 16:43:37,253 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000