1 files changed, 166 insertions, 37 deletions
diff --git a/java/broker/src/test/java/org/apache/qpid/server/TransactionTimeoutHelperTest.java b/java/broker/src/test/java/org/apache/qpid/server/TransactionTimeoutHelperTest.java
index 9081dc49d6..96078d766c 100644
--- a/java/broker/src/test/java/org/apache/qpid/server/TransactionTimeoutHelperTest.java
+++ b/java/broker/src/test/java/org/apache/qpid/server/TransactionTimeoutHelperTest.java
@@ -18,67 +18,131 @@
  */
 package org.apache.qpid.server;
 
-import static org.mockito.Matchers.any;
+import static java.util.concurrent.TimeUnit.SECONDS;
+import static org.apache.qpid.server.logging.messages.ChannelMessages.IDLE_TXN_LOG_HIERARCHY;
+import static org.apache.qpid.server.logging.messages.ChannelMessages.OPEN_TXN_LOG_HIERARCHY;
+import static org.mockito.Matchers.argThat;
 import static org.mockito.Matchers.same;
 import static org.mockito.Mockito.mock;
-import static org.mockito.Mockito.never;
 import static org.mockito.Mockito.verify;
 import static org.mockito.Mockito.verifyZeroInteractions;
 import static org.mockito.Mockito.when;
 
+import org.apache.qpid.server.TransactionTimeoutHelper.CloseAction;
 import org.apache.qpid.server.logging.LogActor;
 import org.apache.qpid.server.logging.LogMessage;
 import org.apache.qpid.server.logging.LogSubject;
-import org.apache.qpid.server.logging.RootMessageLogger;
 import org.apache.qpid.server.logging.actors.CurrentActor;
+import org.apache.qpid.server.txn.ServerTransaction;
 import org.apache.qpid.test.utils.QpidTestCase;
+import org.hamcrest.Description;
+import org.mockito.ArgumentMatcher;
 
 public class TransactionTimeoutHelperTest extends QpidTestCase
 {
-    private final LogMessage _logMessage = mock(LogMessage.class);
     private final LogActor _logActor = mock(LogActor.class);
     private final LogSubject _logSubject = mock(LogSubject.class);
+    private final ServerTransaction _transaction = mock(ServerTransaction.class);
+    private final CloseAction _closeAction = mock(CloseAction.class);
     private TransactionTimeoutHelper _transactionTimeoutHelper;
-    private RootMessageLogger _rootMessageLogger;
+    private long _now;
 
-    public void testLogIfNecessary()
+    public void testNotTransactional() throws Exception
     {
-        _transactionTimeoutHelper.logIfNecessary(99, 100, _logMessage, "");
-        verifyZeroInteractions(_logActor, _logMessage);
+        when(_transaction.isTransactional()).thenReturn(false);
 
-        _transactionTimeoutHelper.logIfNecessary(101, 100, _logMessage, "");
-        verify(_logActor).message(_logSubject, _logMessage);
+        _transactionTimeoutHelper.checkIdleOrOpenTimes(_transaction, 5, 10, 5, 10);
+
+        verifyZeroInteractions(_logActor, _closeAction);
+    }
+
+    public void testOpenTransactionProducesWarningOnly() throws Exception
+    {
+        final long sixtyOneSecondsAgo = _now - SECONDS.toMillis(61);
+
+        configureMockTransaction(sixtyOneSecondsAgo, sixtyOneSecondsAgo);
+
+        _transactionTimeoutHelper.checkIdleOrOpenTimes(_transaction, SECONDS.toMillis(30), 0, 0, 0);
+
+        verify(_logActor).message(same(_logSubject), isLogMessage(OPEN_TXN_LOG_HIERARCHY, "CHN-1007 : Open Transaction : 61,\\d{3} ms"));
+        verifyZeroInteractions(_closeAction);
+    }
+
+    public void testOpenTransactionProducesTimeoutActionOnly() throws Exception
+    {
+        final long sixtyOneSecondsAgo = _now - SECONDS.toMillis(61);
+
+        configureMockTransaction(sixtyOneSecondsAgo, sixtyOneSecondsAgo);
+
+        _transactionTimeoutHelper.checkIdleOrOpenTimes(_transaction, 0, SECONDS.toMillis(30), 0, 0);
+
+        verify(_closeAction).doTimeoutAction("Open transaction timed out");
+        verifyZeroInteractions(_logActor);
     }
 
-    public void testLogIfNecessaryWhenOperationalLoggingDisabled()
+    public void testOpenTransactionProducesWarningAndTimeoutAction() throws Exception
     {
-        //disable the operational logging
-        when(_rootMessageLogger.isMessageEnabled(
-            same(_logActor), any(LogSubject.class), any(String.class)))
-            .thenReturn(false);
-
-        //verify the actor is never asked to log a message
-        _transactionTimeoutHelper.logIfNecessary(101, 100, _logMessage, "");
-        verify(_logActor, never()).message(any(LogMessage.class));
-        verify(_logActor, never()).message(any(LogSubject.class), any(LogMessage.class));
+        final long sixtyOneSecondsAgo = _now - SECONDS.toMillis(61);
+
+        configureMockTransaction(sixtyOneSecondsAgo, sixtyOneSecondsAgo);
+
+        _transactionTimeoutHelper.checkIdleOrOpenTimes(_transaction, SECONDS.toMillis(15), SECONDS.toMillis(30), 0, 0);
+
+        verify(_logActor).message(same(_logSubject), isLogMessage(OPEN_TXN_LOG_HIERARCHY, "CHN-1007 : Open Transaction : 61,\\d{3} ms"));
+        verify(_closeAction).doTimeoutAction("Open transaction timed out");
     }
 
-    public void testIsTimedOut()
+    public void testIdleTransactionProducesWarningOnly() throws Exception
     {
-        assertFalse("Shouldn't have timed out", _transactionTimeoutHelper.isTimedOut(199,200));
-        assertTrue("Should have timed out", _transactionTimeoutHelper.isTimedOut(201,200));
+        final long sixtyOneSecondsAgo = _now - SECONDS.toMillis(61);
+        final long thrityOneSecondsAgo = _now - SECONDS.toMillis(31);
+
+        configureMockTransaction(sixtyOneSecondsAgo, thrityOneSecondsAgo);
+
+        _transactionTimeoutHelper.checkIdleOrOpenTimes(_transaction, 0, 0, SECONDS.toMillis(30), 0);
+
+        verify(_logActor).message(same(_logSubject), isLogMessage(IDLE_TXN_LOG_HIERARCHY, "CHN-1008 : Idle Transaction : 31,\\d{3} ms"));
+        verifyZeroInteractions(_closeAction);
     }
 
-    /**
-     * If TransactionTimeout is disabled, the timeout will be 0. This test verifies
-     * that the helper methods respond negatively in this scenario.
-     */
-    public void testTransactionTimeoutDisabled()
+    public void testIdleTransactionProducesTimeoutActionOnly() throws Exception
     {
-        assertFalse("Shouldn't have timed out", _transactionTimeoutHelper.isTimedOut(201,0));
+        final long sixtyOneSecondsAgo = _now - SECONDS.toMillis(61);
+        final long thrityOneSecondsAgo = _now - SECONDS.toMillis(31);
+
+        configureMockTransaction(sixtyOneSecondsAgo, thrityOneSecondsAgo);
 
-        _transactionTimeoutHelper.logIfNecessary(99, 0, _logMessage, "");
-        verifyZeroInteractions(_logActor, _logMessage);
+        _transactionTimeoutHelper.checkIdleOrOpenTimes(_transaction, 0, 0, 0, SECONDS.toMillis(30));
+
+        verify(_closeAction).doTimeoutAction("Idle transaction timed out");
+        verifyZeroInteractions(_logActor);
+    }
+
+    public void testIdleTransactionProducesWarningAndTimeoutAction() throws Exception
+    {
+        final long sixtyOneSecondsAgo = _now - SECONDS.toMillis(61);
+        final long thrityOneSecondsAgo = _now - SECONDS.toMillis(31);
+
+        configureMockTransaction(sixtyOneSecondsAgo, thrityOneSecondsAgo);
+
+        _transactionTimeoutHelper.checkIdleOrOpenTimes(_transaction, 0, 0, SECONDS.toMillis(15), SECONDS.toMillis(30));
+
+        verify(_logActor).message(same(_logSubject), isLogMessage(IDLE_TXN_LOG_HIERARCHY, "CHN-1008 : Idle Transaction : 31,\\d{3} ms"));
+        verify(_closeAction).doTimeoutAction("Idle transaction timed out");
+    }
+
+    public void testIdleAndOpenWarnings() throws Exception
+    {
+        final long sixtyOneSecondsAgo = _now - SECONDS.toMillis(61);
+        final long thirtyOneSecondsAgo = _now - SECONDS.toMillis(31);
+
+        configureMockTransaction(sixtyOneSecondsAgo, thirtyOneSecondsAgo);
+
+        _transactionTimeoutHelper.checkIdleOrOpenTimes(_transaction, SECONDS.toMillis(60), 0, SECONDS.toMillis(30), 0);
+
+        verify(_logActor).message(same(_logSubject), isLogMessage(IDLE_TXN_LOG_HIERARCHY, "CHN-1008 : Idle Transaction : 31,\\d{3} ms"));
+        verify(_logActor).message(same(_logSubject), isLogMessage(OPEN_TXN_LOG_HIERARCHY, "CHN-1007 : Open Transaction : 61,\\d{3} ms"));
+        verifyZeroInteractions(_closeAction);
     }
 
     @Override
@@ -88,14 +152,79 @@ public class TransactionTimeoutHelperTest extends QpidTestCase
 
         CurrentActor.set(_logActor);
 
-        _rootMessageLogger = mock(RootMessageLogger.class);
-        when(_logActor.getRootMessageLogger()).thenReturn(_rootMessageLogger);
+        _transactionTimeoutHelper = new TransactionTimeoutHelper(_logSubject, _closeAction);
+        _now = System.currentTimeMillis();
+    }
+
+    @Override
+    protected void tearDown() throws Exception
+    {
+        try
+        {
+            super.tearDown();
+        }
+        finally
+        {
+            CurrentActor.remove();
+        }
+    }
 
-        when(_rootMessageLogger.isMessageEnabled(
-                same(_logActor), any(LogSubject.class), any(String.class)))
-                .thenReturn(true);
+    private void configureMockTransaction(final long startTime, final long updateTime)
+    {
+        when(_transaction.isTransactional()).thenReturn(true);
+        when(_transaction.getTransactionStartTime()).thenReturn(startTime);
+        when(_transaction.getTransactionUpdateTime()).thenReturn(updateTime);
+    }
 
-        _transactionTimeoutHelper = new TransactionTimeoutHelper(_logSubject);
+    private LogMessage isLogMessage(String expectedlogHierarchy, String expectedText)
+    {
+        return argThat(new IsLogMessage(expectedlogHierarchy, expectedText));
     }
 
+    class IsLogMessage extends ArgumentMatcher<LogMessage>
+    {
+        private final String _expectedLogHierarchy;
+        private final String _expectedLogMessageMatches;
+        private String _hierarchyMatchesFailure;
+        private String _logMessageMatchesFailure;
+
+        public IsLogMessage(String expectedlogHierarchy, String expectedLogMessageMatches)
+        {
+            _expectedLogHierarchy = expectedlogHierarchy;
+            _expectedLogMessageMatches = expectedLogMessageMatches;
+        }
+
+        public boolean matches(Object arg)
+        {
+            LogMessage logMessage = (LogMessage)arg;
+
+            boolean hierarchyMatches = logMessage.getLogHierarchy().equals(_expectedLogHierarchy);
+            boolean logMessageMatches = logMessage.toString().matches(_expectedLogMessageMatches);
+
+            if (!hierarchyMatches)
+            {
+                _hierarchyMatchesFailure = "LogHierarchy does not match. Expected " + _expectedLogHierarchy + " actual " + logMessage.getLogHierarchy();
+            }
+
+            if (!logMessageMatches)
+            {
+                _logMessageMatchesFailure = "LogMessage does not match. Expected " + _expectedLogMessageMatches + " actual " + logMessage.toString();
+            }
+
+            return hierarchyMatches && logMessageMatches;
+        }
+
+        @Override
+        public void describeTo(Description description)
+        {
+            if (_hierarchyMatchesFailure != null)
+            {
+                description.appendText(_hierarchyMatchesFailure);
+            }
+            if (_logMessageMatchesFailure != null)
+            {
+                description.appendText(_logMessageMatchesFailure);
+            }
+        }
+    }
 }