1 Reply Latest reply on Mar 30, 2004 9:00 AM by keesvandieren

    Bug in EJB 2.1 Timed Services

    keesvandieren

      Hello,

      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