Spring Framework
  1. Spring Framework
  2. SPR-5987

SingleConnectionFactory's resetConnection is causing deadlocks with underlying OracleAQ's JMS connection

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.5.6
    • Fix Version/s: 3.0 M4
    • Component/s: JMS
    • Labels:
      None
    • Last commented by a User:
      true

      Description

      We had encountered below deadlock using the Spring 2.5.6 jar.

      "DefaultMessageListenerContainer-303263" prio=10 tid=0x081be000 nid=0x5e74 waiting for monitor entry [0xb0698000..0xb0698ea0]
      java.lang.Thread.State: BLOCKED (on object monitor)
      at oracle.jms.AQjmsExceptionListener.resumeExceptionListener(AQjmsExceptionListener.java:235)

      • waiting to lock <0x56154178> (a oracle.jms.AQjmsExceptionListener)
        at oracle.jms.AQjmsConnection.start(AQjmsConnection.java:498)
      • locked <0x5614ec28> (a oracle.jms.AQjmsConnection)
        at org.springframework.jms.connection.SingleConnectionFactory$SharedConnectionInvocationHandler.invoke(SingleConnectionFactory.java:514)
        at $Proxy29.start(Unknown Source)
        at org.springframework.jms.connection.ConnectionFactoryUtils.doGetTransactionalSession(ConnectionFactoryUtils.java:277)
        at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.doReceiveAndExecute(AbstractPollingMessageListenerContainer.java:286)
        at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:241)
        at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:982)
        at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:881)
        at java.lang.Thread.run(Thread.java:619)

      "Thread-336" prio=10 tid=0x0852e800 nid=0x489e waiting for monitor entry [0xaf0b0000..0xaf0b10a0]
      java.lang.Thread.State: BLOCKED (on object monitor)
      at oracle.jms.AQjmsConnection.stop(AQjmsConnection.java:520)

      • waiting to lock <0x5614ec28> (a oracle.jms.AQjmsConnection)
        at org.springframework.jms.connection.SingleConnectionFactory.closeConnection(SingleConnectionFactory.java:423)
        at org.springframework.jms.connection.SingleConnectionFactory.resetConnection(SingleConnectionFactory.java:322)
      • locked <0x5556c840> (a java.lang.Object)
        at org.springframework.jms.connection.CachingConnectionFactory.resetConnection(CachingConnectionFactory.java:199)
        at org.springframework.jms.connection.SingleConnectionFactory.onException(SingleConnectionFactory.java:303)
        at org.springframework.jms.connection.ChainedExceptionListener.onException(ChainedExceptionListener.java:60)
        at oracle.jms.AQjmsExceptionListener.onException(AQjmsExceptionListener.java:148)
      • locked <0x56154178> (a oracle.jms.AQjmsExceptionListener)
        at oracle.jms.AQjmsExceptionListener.run(AQjmsExceptionListener.java:223)

      We then patched SingleConnectionFactory.java for the change made in Revision 1500 (https://fisheye.springsource.org/browse/spring-framework/trunk/org.springframework.jms/src/main/java/org/springframework/jms/connection/SingleConnectionFactory.java?r2=1500&r1=674) of this class in truck in our project. I will attach the patched file to this issue as well. This patch we did also includes an additional log statement in "onException" method to log the JMSException. It would be nice if you can add that log statement for next release.

      Even after the patch of moving the "this.target.start()" statement inside the synchronized block, we still encountered deadlock as below:

      Name: DefaultMessageListenerContainer-43803
      State: BLOCKED on oracle.jms.AQjmsExceptionListener@a77e20 owned by: Thread-92
      Total blocked: 1 Total waited: 0

      Stack trace:
      oracle.jms.AQjmsExceptionListener.resumeExceptionListener(AQjmsExceptionListener.java:235)
      oracle.jms.AQjmsConnection.start(AQjmsConnection.java:498)

      • locked oracle.jms.AQjmsConnection@1c15642
        org.springframework.jms.connection.SingleConnectionFactory$SharedConnectionInvocationHandler.invoke(SingleConnectionFactory.java:517)
      • locked java.lang.Object@91d649
        $Proxy29.start(Unknown Source)
        org.springframework.jms.connection.ConnectionFactoryUtils.doGetTransactionalSession(ConnectionFactoryUtils.java:277)
        org.springframework.jms.listener.AbstractPollingMessageListenerContainer.doReceiveAndExecute(AbstractPollingMessageListenerContainer.java:286)
        org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:241)
        org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:982)
        org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:881)
        java.lang.Thread.run(Thread.java:619)

      Name: Thread-92
      State: BLOCKED on java.lang.Object@91d649 owned by: DefaultMessageListenerContainer-43803
      Total blocked: 1 Total waited: 42

      Stack trace:
      org.springframework.jms.connection.SingleConnectionFactory.resetConnection(SingleConnectionFactory.java:322)
      org.springframework.jms.connection.CachingConnectionFactory.resetConnection(CachingConnectionFactory.java:199)
      org.springframework.jms.connection.SingleConnectionFactory.onException(SingleConnectionFactory.java:304)
      org.springframework.jms.connection.ChainedExceptionListener.onException(ChainedExceptionListener.java:60)
      oracle.jms.AQjmsExceptionListener.onException(AQjmsExceptionListener.java:148)

      • locked oracle.jms.AQjmsExceptionListener@a77e20
        oracle.jms.AQjmsExceptionListener.run(AQjmsExceptionListener.java:223)

      My suggestion is to make the call to target's start method only if it wasn't already started. The code would like below:

      synchronized (connectionMonitor) {
      if (!started)

      { //if condition added to avoid possible deadlocks when trying to reset the target connection this.target.start(); started = true; }

      }

      Please look into this and let me know what you think of the change and address it accordingly in the next release.

        Activity

        Hide
        Rajani Chennamaneni added a comment -

        Attaching the patch we used that caused the second set of deadlock traces I mentioned in the description.

        Also, My fix suggestion code block didn't render correctly in the description above.

        synchronized (connectionMonitor) {
        //if condition added to avoid possible deadlocks when trying to reset the target connection
        if (!started)

        { this.target.start(); started = true; }

        }

        Show
        Rajani Chennamaneni added a comment - Attaching the patch we used that caused the second set of deadlock traces I mentioned in the description. Also, My fix suggestion code block didn't render correctly in the description above. synchronized (connectionMonitor) { //if condition added to avoid possible deadlocks when trying to reset the target connection if (!started) { this.target.start(); started = true; } }
        Hide
        Juergen Hoeller added a comment -

        Good point - we can certainly call start just when actually necessary there. I changed this as of 3.0 M4.

        Juergen

        Show
        Juergen Hoeller added a comment - Good point - we can certainly call start just when actually necessary there. I changed this as of 3.0 M4. Juergen
        Hide
        Rajani Chennamaneni added a comment -

        Thanks Juergen for fixing this so soon .

        Can you also consider adding a log statement in "SingleConnectionFactory.onException" method to log the JMSException it receives. Currently its eating it up making it impossible to see what caused the resetConnection.

        Thanks.

        Show
        Rajani Chennamaneni added a comment - Thanks Juergen for fixing this so soon . Can you also consider adding a log statement in "SingleConnectionFactory.onException" method to log the JMSException it receives. Currently its eating it up making it impossible to see what caused the resetConnection. Thanks.

          People

          • Assignee:
            Juergen Hoeller
            Reporter:
            Rajani Chennamaneni
            Last updater:
            Trevor Marshall
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:
              Days since last comment:
              4 years, 37 weeks, 5 days ago