[Jboss-cvs] JBoss Messaging SVN: r1320 - in branches/Branch_1_0/src/main/org/jboss/jms: client/container client/remoting server/endpoint

jboss-cvs-commits at lists.jboss.org jboss-cvs-commits at lists.jboss.org
Tue Sep 19 14:44:46 EDT 2006


Author: ovidiu.feodorov at jboss.com
Date: 2006-09-19 14:44:43 -0400 (Tue, 19 Sep 2006)
New Revision: 1320

Modified:
   branches/Branch_1_0/src/main/org/jboss/jms/client/container/ClosedInterceptor.java
   branches/Branch_1_0/src/main/org/jboss/jms/client/remoting/MessageCallbackHandler.java
   branches/Branch_1_0/src/main/org/jboss/jms/server/endpoint/ServerConsumerEndpoint.java
Log:
increased tracing resolution to identify the http://jira.jboss.org/jira/browse/JBMESSAGING-546 deadlock

Modified: branches/Branch_1_0/src/main/org/jboss/jms/client/container/ClosedInterceptor.java
===================================================================
--- branches/Branch_1_0/src/main/org/jboss/jms/client/container/ClosedInterceptor.java	2006-09-19 17:17:53 UTC (rev 1319)
+++ branches/Branch_1_0/src/main/org/jboss/jms/client/container/ClosedInterceptor.java	2006-09-19 18:44:43 UTC (rev 1320)
@@ -39,12 +39,13 @@
 
 /**
  * An interceptor for checking closed state. It waits for other invocations to complete before
- * allowing the close. I.e. it performs the function of a "valve"
+ * allowing the close. I.e. it performs the function of a "valve".
  * 
  * This interceptor is PER_INSTANCE.
  * 
  * @author <a href="mailto:adrian at jboss.org>Adrian Brock</a>
  * @author <a href="mailto:tim.fox at jboss.com>Tim Fox</a>
+ * @author <a href="mailto:ovidiu at jboss.com>Ovidiu Feodorov</a>
  *
  * $Id$
  */
@@ -54,40 +55,51 @@
    
    private static final Logger log = Logger.getLogger(ClosedInterceptor.class);
    
-   /** Not closed */
    private static final int NOT_CLOSED = 0;
-   
-   /** Closing */
    private static final int IN_CLOSING = 1;
-   
-   /** Closing */
    private static final int CLOSING = 2;
-   
-   /** Performing the close */
-   private static final int IN_CLOSE = 3;
-   
-   /** Closed */
+   private static final int IN_CLOSE = 3; // performing the close
    private static final int CLOSED = -1;
    
    // Attributes ----------------------------------------------------
    
    private boolean trace = log.isTraceEnabled();
 
-   /** The state of the object */
+   // The current state of the object guarded by this interceptor
    private int state = NOT_CLOSED;
    
-   /** The inuse count */
-   private int inuseCount = 0;
+   // The inuse count
+   private int inUseCount;
 
+   // The identity of the delegate this interceptor is associated with
+   private Integer id;
+   private String delegateType;
+
    // Static --------------------------------------------------------
    
    // Constructors --------------------------------------------------
 
+   public ClosedInterceptor()
+   {
+      state = NOT_CLOSED;
+      inUseCount = 0;
+      id = null;
+   }
+
    // Public --------------------------------------------------------
 
    public String toString()
    {
-      return "ClosedInterceptor[" + Integer.toHexString(hashCode()) + "]";
+      StringBuffer sb = new StringBuffer("ClosedInterceptor.");
+      if (id == null)
+      {
+         sb.append("UNINITIALIZED");
+      }
+      else
+      {
+         sb.append(delegateType).append("[").append(id.intValue()).append("]");
+      }
+      return sb.toString();
    }
 
    // Interceptor implementation -----------------------------------
@@ -99,12 +111,17 @@
 
    public Object invoke(Invocation invocation) throws Throwable
    {
+      // maintain the identity of the delegate that sends invocation through this interceptor, for
+      // logging purposes. It makes sense, since it's an PER_INSTANCE interceptor
+      if (id == null)
+      {
+         getIdentity(invocation);
+      }
+
       String methodName = ((MethodInvocation) invocation).getMethod().getName();
       boolean isClosing = methodName.equals("closing");
       boolean isClose = methodName.equals("close");
       
-//      if (trace) { log.trace(this + " invoking " + methodName + "()"); }
-
       if (isClosing)
       {         
          if (checkClosingAlreadyDone())
@@ -157,8 +174,7 @@
     * 
     * @return true when already closing or closed
     */
-   protected synchronized boolean checkClosingAlreadyDone()
-      throws Throwable
+   protected synchronized boolean checkClosingAlreadyDone() throws Throwable
    {
       if (state != NOT_CLOSED)
       {
@@ -171,8 +187,7 @@
    /**
     * Closing the object
     */
-   protected synchronized void closing()
-      throws Throwable
+   protected synchronized void closing() throws Throwable
    {
       state = CLOSING;
    }
@@ -183,14 +198,13 @@
     * 
     * @return true when already closed
     */
-   protected synchronized boolean checkCloseAlreadyDone()
-      throws Throwable
+   protected synchronized boolean checkCloseAlreadyDone() throws Throwable
    {
       if (state != CLOSING)
       {
          return true;
       }
-      while (inuseCount > 0)
+      while (inUseCount > 0)
       {
          wait();
       }
@@ -201,33 +215,31 @@
    /**
     * Closed the object
     */
-   protected synchronized void closed()
-      throws Throwable
+   protected synchronized void closed() throws Throwable
    {
       state = CLOSED;
-      if (trace) { log.trace("closed"); }
+      log.debug(this + " closed");
    }
    
    /**
     * Mark the object as inuse
     */
-   protected synchronized void inuse()
-      throws Throwable
+   protected synchronized void inuse() throws Throwable
    {
       if (state == IN_CLOSE || state == CLOSED)
       {
+         log.error(this + " is closed");
          throw new IllegalStateException("The object is closed");
       }
-      ++inuseCount;
+      ++inUseCount;
    }
    
    /**
     * Mark the object as no longer inuse 
     */
-   protected synchronized void done()
-      throws Throwable
+   protected synchronized void done() throws Throwable
    {
-      if (--inuseCount == 0)
+      if (--inUseCount == 0)
       {
          notifyAll();
       }
@@ -242,8 +254,8 @@
    {                  
       HierarchicalState state = ((DelegateSupport)invocation.getTargetObject()).getState();
             
-      //We use a clone to avoid a deadlock where requests
-      //are made to close parent and child concurrently
+      // We use a clone to avoid a deadlock where requests are made to close parent and child
+      // concurrently
       
       Set clone;
 
@@ -251,7 +263,7 @@
       
       if (children == null)
       {
-         if (trace) { log.trace("No children"); }
+         if (trace) { log.trace(this + " has no children"); }
          return;
       }
       
@@ -260,8 +272,7 @@
          clone = new HashSet(children);
       }
       
-      // Cycle through the children this will do a depth
-      // first close
+      // Cycle through the children this will do a depth first close
       for (Iterator i = clone.iterator(); i.hasNext();)
       {
          HierarchicalState child = (HierarchicalState)i.next();      
@@ -290,7 +301,14 @@
 
    // Private --------------------------------------------------------
 
- 
+   private void getIdentity(Invocation i)
+   {
+      DelegateSupport ds = (DelegateSupport)i.getTargetObject();
+      id = new Integer(ds.getID());
+      delegateType = ds.getClass().getName();
+      delegateType = delegateType.substring(delegateType.lastIndexOf('.') + 1);
+   }
+
    // Inner Classes --------------------------------------------------
 
 }

Modified: branches/Branch_1_0/src/main/org/jboss/jms/client/remoting/MessageCallbackHandler.java
===================================================================
--- branches/Branch_1_0/src/main/org/jboss/jms/client/remoting/MessageCallbackHandler.java	2006-09-19 17:17:53 UTC (rev 1319)
+++ branches/Branch_1_0/src/main/org/jboss/jms/client/remoting/MessageCallbackHandler.java	2006-09-19 18:44:43 UTC (rev 1320)
@@ -359,6 +359,7 @@
 
          if (trace) { log.trace("blocking wait for Closer execution"); }
          result.getResult();
+         if (trace) { log.trace("got Closer result"); }
       }
       catch (InterruptedException e)
       {
@@ -661,7 +662,10 @@
       
       public void run()
       {
+         if (trace) { log.trace("Closer starts running"); }
+
          result.setResult(null);
+         
          if (trace) { log.trace("Closer finished run"); }
       }
    }

Modified: branches/Branch_1_0/src/main/org/jboss/jms/server/endpoint/ServerConsumerEndpoint.java
===================================================================
--- branches/Branch_1_0/src/main/org/jboss/jms/server/endpoint/ServerConsumerEndpoint.java	2006-09-19 17:17:53 UTC (rev 1319)
+++ branches/Branch_1_0/src/main/org/jboss/jms/server/endpoint/ServerConsumerEndpoint.java	2006-09-19 18:44:43 UTC (rev 1320)
@@ -235,7 +235,9 @@
 
             return null;
          }
-            
+
+         if (trace) { log.trace(this + " has the main lock, preparing the message for delivery"); }
+
          MessageReference ref = (MessageReference)reference;
                      
          JBossMessage message = (JBossMessage)ref.getMessage();
@@ -275,6 +277,7 @@
          {            
             try
             {
+               if (trace) { log.trace(this + " scheduling a new Deliverer"); }
                this.executor.execute(new Deliverer());
             }
             catch (InterruptedException e)
@@ -348,15 +351,17 @@
             // it. This is because it may still contain deliveries that may well be acknowledged
             // after the consumer has closed. This is perfectly valid.
 
-            //FIXME - The deliveries should really be stored in the session endpoint, not here
-            //that is their natural place, that would mean we wouldn't have to mess around with keeping
-            //deliveries after this is closed
+            // FIXME - The deliveries should really be stored in the session endpoint, not here
+            // that is their natural place, that would mean we wouldn't have to mess around with
+            // keeping deliveries after this is closed.
+
+            if (trace) { log.trace(this + " grabbed the main lock in close()"); }
                   
             disconnect(); 
             
             JMSDispatcher.instance.unregisterTarget(new Integer(id));
             
-            //If it's a subscription, remove it
+            // If it's a subscription, remove it
             if (channel instanceof Subscription)
             {
                Subscription sub = (Subscription)channel;
@@ -367,8 +372,9 @@
                }            
             } 
             
-            //If it's non recoverable, i.e. it's a non durable sub or a temporary queue
-            //then remove all it's references
+            // If it's non recoverable, i.e. it's a non durable sub or a temporary queue then remove
+            // all its references
+
             if (!channel.isRecoverable())
             {
                channel.removeAllReferences();
@@ -669,7 +675,6 @@
     */
    private void disconnect()
    {
-
       boolean removed = channel.remove(this);
       
       if (removed)
@@ -713,23 +718,23 @@
       public void run()
       {
          // Is there anything to deliver?
-         // This is ok outside lock - is volatile
+         // This is ok outside lock - is volatile.
          if (clientConsumerFull)
          {
-            // Do nothing
+            if (trace) { log.trace(this + " client consumer full, do nothing"); }
             return;
          }
          
          List list = null;
              
          synchronized (lock)
-         {           
+         {
+            if (trace) { log.trace(this + " has the main lock, attempting delivery"); }
+
             if (!toDeliver.isEmpty())
             {
                list = new ArrayList(toDeliver);
-               
                toDeliver.clear();
-               
                bufferFull = false;
             }
          }




More information about the jboss-cvs-commits mailing list