dev@shoal.java.net

About GROUP_WARMUP_TIME of the Router.java

From: Bongjae Chang <carryel_at_korea.com>
Date: Thu, 23 Jul 2009 15:31:55 +0900

Hi,

When I set the log level to be FINEST, I could see the following log while 30 seconds.

----
FINEST: SignalHandler : processing a received signal com.sun.enterprise.ee.cms.impl.common.JoinNotificationSignalImpl
Jul 23, 2009 3:11:49 PM com.sun.enterprise.ee.cms.impl.common.SignalHandler analyzeSignal
FINEST: SignalHandler : processing a received signal com.sun.enterprise.ee.cms.impl.common.JoinNotificationSignalImpl
Jul 23, 2009 3:11:49 PM com.sun.enterprise.ee.cms.impl.common.SignalHandler analyzeSignal
FINEST: SignalHandler : processing a received signal com.sun.enterprise.ee.cms.impl.common.JoinNotificationSignalImpl
Jul 23, 2009 3:11:49 PM com.sun.enterprise.ee.cms.impl.common.SignalHandler analyzeSignal
FINEST: SignalHandler : processing a received signal com.sun.enterprise.ee.cms.impl.common.JoinNotificationSignalImpl
Jul 23, 2009 3:11:49 PM com.sun.enterprise.ee.cms.impl.common.SignalHandler analyzeSignal
FINEST: SignalHandler : processing a received signal com.sun.enterprise.ee.cms.impl.common.JoinNotificationSignalImpl
Jul 23, 2009 3:11:49 PM com.sun.enterprise.ee.cms.impl.common.SignalHandler analyzeSignal
FINEST: SignalHandler : processing a received signal com.sun.enterprise.ee.cms.impl.common.JoinNotificationSignalImpl
Jul 23, 2009 3:11:49 PM com.sun.enterprise.ee.cms.impl.common.SignalHandler analyzeSignal
FINEST: SignalHandler : processing a received signal com.sun.enterprise.ee.cms.impl.common.JoinNotificationSignalImpl
Jul 23, 2009 3:11:49 PM com.sun.enterprise.ee.cms.impl.common.SignalHandler analyzeSignal
FINEST: SignalHandler : processing a received signal com.sun.enterprise.ee.cms.impl.common.JoinNotificationSignalImpl
Jul 23, 2009 3:11:49 PM com.sun.enterprise.ee.cms.impl.common.SignalHandler analyzeSignal
FINEST: SignalHandler : processing a received signal com.sun.enterprise.ee.cms.impl.common.JoinNotificationSignalImpl
Jul 23, 2009 3:11:49 PM com.sun.enterprise.ee.cms.impl.common.SignalHandler analyzeSignal
FINEST: SignalHandler : processing a received signal com.sun.enterprise.ee.cms.impl.common.JoinNotificationSignalImpl
Jul 23, 2009 3:11:49 PM com.sun.enterprise.ee.cms.impl.common.SignalHandler analyzeSignal
FINEST: SignalHandler : processing a received signal com.sun.enterprise.ee.cms.impl.common.JoinNotificationSignalImpl
Jul 23, 2009 3:11:49 PM com.sun.enterprise.ee.cms.impl.common.SignalHandler analyzeSignal
...(repeated)
----

Above log was printed from SignalHandler#analyzeSignal(), and the actual reason was caused by Router#notifyJoinNotificationAction().

In Router.java
----
void notifyJoinNotificationAction(...) {
   ...
   if(isJoinNotificationAFRegistered()) {
      ...
   } else if ( System.currentTimeMillis() - startupTime < GROUP_WARMUP_TIME ) {
      // put it back to the queue if it is less than
      // 30 secs since start time. we give 30 secs for join notif
      // registrations to happen until which time, the signals are
      // available in queue
      try {
         queue.put(new SignalPacket(signal));
      } catch(...) {
         ...
      }
   }
}
----

Then, the following logic will be repeated without sleep time if isJoinNotificationAFRegistered() is false.

----
signalQueue#take() -> SignalHandler#handleSignal() -> SignalHandler#analyzeSignal() -> Router#notifyJoinNotificationAction() -> signalQueue.put() -> signalQueue#take() -> SignalHandler#handleSignal() -> ...(repeated) ->
----

So, I think that some sleep time is needed when the signal is put back to the queue and GROUP_WARMUP_TIME is too long.

Here is the examples of the proposed patch.

Index: com/sun/enterprise/ee/cms/core/GroupManagementService.java
===================================================================
RCS file: /cvs/shoal/gms/src/java/com/sun/enterprise/ee/cms/core/GroupManagementService.java,v
retrieving revision 1.17
diff -c -w -u -r1.17 GroupManagementService.java
Index: com/sun/enterprise/ee/cms/impl/common/Router.java
===================================================================
RCS file: /cvs/shoal/gms/src/java/com/sun/enterprise/ee/cms/impl/common/Router.java,v
retrieving revision 1.14
diff -c -w -u -r1.14 Router.java
--- com/sun/enterprise/ee/cms/impl/common/Router.java 8 Jul 2009 15:23:07 -0000 1.14
+++ com/sun/enterprise/ee/cms/impl/common/Router.java 23 Jul 2009 05:56:59 -0000
@@ -88,7 +88,7 @@
     private final Logger logger = GMSLogDomain.getLogger(GMSLogDomain.GMS_LOGGER);
     private final ExecutorService actionPool;
     private long startupTime;
- private static final int GROUP_WARMUP_TIME = 30000;
+ private static final int GROUP_WARMUP_TIME = 5000;
     private static final int BUFSIZE = 100;
     private Thread signalHandlerThread;
 
@@ -394,6 +394,7 @@
             // registrations to happen until which time, the signals are
             // available in queue.
             try {
+ Thread.sleep( 1000 );
                 queue.put(new SignalPacket(signal));
             } catch (InterruptedException e) {
                 logger.log(Level.WARNING, e.getMessage());


What do you think?

--
Bongjae Chang