You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@camel.apache.org by da...@apache.org on 2012/02/03 11:33:03 UTC

svn commit: r1240066 - in /camel/branches/camel-2.9.x: ./ components/camel-jms/src/test/resources/ components/camel-jms/src/test/resources/org/apache/camel/component/jms/tx/ components/camel-spring/src/main/java/org/apache/camel/spring/spi/

Author: davsclaus
Date: Fri Feb  3 10:33:03 2012
New Revision: 1240066

URL: http://svn.apache.org/viewvc?rev=1240066&view=rev
Log:
CAMEL-4961: Improved TX commit/rollback logging a bit

Modified:
    camel/branches/camel-2.9.x/   (props changed)
    camel/branches/camel-2.9.x/components/camel-jms/src/test/resources/log4j.properties
    camel/branches/camel-2.9.x/components/camel-jms/src/test/resources/org/apache/camel/component/jms/tx/JMSTransactionIsTransactedRedeliveredTest.xml
    camel/branches/camel-2.9.x/components/camel-spring/src/main/java/org/apache/camel/spring/spi/TransactionErrorHandler.java

Propchange: camel/branches/camel-2.9.x/
------------------------------------------------------------------------------
--- svn:mergeinfo (original)
+++ svn:mergeinfo Fri Feb  3 10:33:03 2012
@@ -1 +1 @@
-/camel/trunk:1235643,1236639,1236667,1237666,1237807,1238225,1238229,1238387,1238463,1238477,1238503,1238937,1238988,1239006,1239045,1239080-1239081,1239470,1239479,1239497
+/camel/trunk:1235643,1236639,1236667,1237666,1237807,1238225,1238229,1238387,1238463,1238477,1238503,1238937,1238988,1239006,1239045,1239080-1239081,1239470,1239479,1239497,1240063

Propchange: camel/branches/camel-2.9.x/
------------------------------------------------------------------------------
Binary property 'svnmerge-integrated' - no diff available.

Modified: camel/branches/camel-2.9.x/components/camel-jms/src/test/resources/log4j.properties
URL: http://svn.apache.org/viewvc/camel/branches/camel-2.9.x/components/camel-jms/src/test/resources/log4j.properties?rev=1240066&r1=1240065&r2=1240066&view=diff
==============================================================================
--- camel/branches/camel-2.9.x/components/camel-jms/src/test/resources/log4j.properties (original)
+++ camel/branches/camel-2.9.x/components/camel-jms/src/test/resources/log4j.properties Fri Feb  3 10:33:03 2012
@@ -27,6 +27,7 @@ log4j.rootLogger=INFO, out
 #log4j.logger.org.apache.camel=DEBUG
 #log4j.logger.org.springframework.jms.listener=TRACE
 #log4j.logger.org.apache.camel.management=DEBUG
+#log4j.logger.org.apache.camel.spring.spi=DEBUG
 
 # CONSOLE appender not used by default
 log4j.appender.stdout=org.apache.log4j.ConsoleAppender

Modified: camel/branches/camel-2.9.x/components/camel-jms/src/test/resources/org/apache/camel/component/jms/tx/JMSTransactionIsTransactedRedeliveredTest.xml
URL: http://svn.apache.org/viewvc/camel/branches/camel-2.9.x/components/camel-jms/src/test/resources/org/apache/camel/component/jms/tx/JMSTransactionIsTransactedRedeliveredTest.xml?rev=1240066&r1=1240065&r2=1240066&view=diff
==============================================================================
--- camel/branches/camel-2.9.x/components/camel-jms/src/test/resources/org/apache/camel/component/jms/tx/JMSTransactionIsTransactedRedeliveredTest.xml (original)
+++ camel/branches/camel-2.9.x/components/camel-jms/src/test/resources/org/apache/camel/component/jms/tx/JMSTransactionIsTransactedRedeliveredTest.xml Fri Feb  3 10:33:03 2012
@@ -54,8 +54,9 @@
       <!-- enable JMX -->
       <jmxAgent id="agent" disabled="false"/>
 
-      <!-- we do not want any exceptions to be logged, neither that a rollback occurred -->
-      <errorHandler id="txEH" type="TransactionErrorHandler" rollbackLoggingLevel="OFF">
+      <!-- we want TX rollbacks to be logged at WARN level -->
+      <errorHandler id="txEH" type="TransactionErrorHandler" rollbackLoggingLevel="WARN">
+        <!-- we do not want any exceptions to be logged with stacktraces -->
         <redeliveryPolicy logStackTrace="false" logExhausted="false"/>
       </errorHandler>
 

Modified: camel/branches/camel-2.9.x/components/camel-spring/src/main/java/org/apache/camel/spring/spi/TransactionErrorHandler.java
URL: http://svn.apache.org/viewvc/camel/branches/camel-2.9.x/components/camel-spring/src/main/java/org/apache/camel/spring/spi/TransactionErrorHandler.java?rev=1240066&r1=1240065&r2=1240066&view=diff
==============================================================================
--- camel/branches/camel-2.9.x/components/camel-spring/src/main/java/org/apache/camel/spring/spi/TransactionErrorHandler.java (original)
+++ camel/branches/camel-2.9.x/components/camel-spring/src/main/java/org/apache/camel/spring/spi/TransactionErrorHandler.java Fri Feb  3 10:33:03 2012
@@ -126,23 +126,17 @@ public class TransactionErrorHandler ext
             // mark the beginning of this transaction boundary
             exchange.getUnitOfWork().beginTransactedBy(transactionKey);
 
-            if (log.isDebugEnabled()) {
-                log.debug("Transaction begin ({}) redelivered({}) for {})", new Object[]{transactionKey, redelivered, ids});
-            }
-
+            // do in transaction
+            logTransactionBegin(redelivered, ids);
             doInTransactionTemplate(exchange);
+            logTransactionCommit(redelivered, ids);
 
-            if (log.isDebugEnabled()) {
-                log.debug("Transaction commit ({}) redelivered({}) for {})", new Object[]{transactionKey, redelivered, ids});
-            }
         } catch (TransactionRollbackException e) {
-            // ignore as its just a dummy exception to force spring TX to rollback
-            if (log.isDebugEnabled()) {
-                log.debug("Transaction rollback ({}) redelivered({}) for {} due exchange was marked for rollbackOnly", new Object[]{transactionKey, redelivered, ids});
-            }
+            // do not set as exception, as its just a dummy exception to force spring TX to rollback
+            logTransactionRollback(redelivered, ids, null, true);
         } catch (Throwable e) {
             exchange.setException(e);
-            logTransactionRollback(redelivered, ids, e);
+            logTransactionRollback(redelivered, ids, e, false);
         } finally {
             // mark the end of this transaction boundary
             exchange.getUnitOfWork().endTransactedBy(transactionKey);
@@ -229,21 +223,68 @@ public class TransactionErrorHandler ext
     }
 
     /**
-     * Logs the transaction rollback
+     * Logs the transaction begin
+     */
+    private void logTransactionBegin(String redelivered, String ids) {
+        if (log.isDebugEnabled()) {
+            log.debug("Transaction begin ({}) redelivered({}) for {})", new Object[]{transactionKey, redelivered, ids});
+        }
+    }
+
+    /**
+     * Logs the transaction commit
      */
-    private void logTransactionRollback(String redelivered, String ids, Throwable e) {
+    private void logTransactionCommit(String redelivered, String ids) {
+        if ("true".equals(redelivered)) {
+            // okay its a redelivered message so log at INFO level if rollbackLoggingLevel is INFO or higher
+            // this allows people to know that the redelivered message was committed this time
+            if (rollbackLoggingLevel == LoggingLevel.INFO || rollbackLoggingLevel == LoggingLevel.WARN || rollbackLoggingLevel == LoggingLevel.ERROR) {
+                log.info("Transaction commit ({}) redelivered({}) for {})", new Object[]{transactionKey, redelivered, ids});
+                // return after we have logged
+                return;
+            }
+        }
+
+        // log non redelivered by default at DEBUG level
+        log.debug("Transaction commit ({}) redelivered({}) for {})", new Object[]{transactionKey, redelivered, ids});
+    }
+
+    /**
+     * Logs the transaction rollback.
+     */
+    private void logTransactionRollback(String redelivered, String ids, Throwable e, boolean rollbackOnly) {
         if (rollbackLoggingLevel == LoggingLevel.OFF) {
             return;
         } else if (rollbackLoggingLevel == LoggingLevel.ERROR && log.isErrorEnabled()) {
-            log.error("Transaction rollback ({}) redelivered({}) for {} caught: {}", new Object[]{transactionKey, redelivered, ids, e.getMessage()});
+            if (rollbackOnly) {
+                log.error("Transaction rollback ({}) redelivered({}) for {} due exchange was marked for rollbackOnly", new Object[]{transactionKey, redelivered, ids});
+            } else {
+                log.error("Transaction rollback ({}) redelivered({}) for {} caught: {}", new Object[]{transactionKey, redelivered, ids, e.getMessage()});
+            }
         } else if (rollbackLoggingLevel == LoggingLevel.WARN && log.isWarnEnabled()) {
-            log.warn("Transaction rollback ({}) redelivered({}) for {} caught: {}", new Object[]{transactionKey, redelivered, ids, e.getMessage()});
+            if (rollbackOnly) {
+                log.warn("Transaction rollback ({}) redelivered({}) for {} due exchange was marked for rollbackOnly", new Object[]{transactionKey, redelivered, ids});
+            } else {
+                log.warn("Transaction rollback ({}) redelivered({}) for {} caught: {}", new Object[]{transactionKey, redelivered, ids, e.getMessage()});
+            }
         } else if (rollbackLoggingLevel == LoggingLevel.INFO && log.isInfoEnabled()) {
-            log.info("Transaction rollback ({}) redelivered({}) for {} caught: {}", new Object[]{transactionKey, redelivered, ids, e.getMessage()});
+            if (rollbackOnly) {
+                log.info("Transaction rollback ({}) redelivered({}) for {} due exchange was marked for rollbackOnly", new Object[]{transactionKey, redelivered, ids});
+            } else {
+                log.info("Transaction rollback ({}) redelivered({}) for {} caught: {}", new Object[]{transactionKey, redelivered, ids, e.getMessage()});
+            }
         } else if (rollbackLoggingLevel == LoggingLevel.DEBUG && log.isDebugEnabled()) {
-            log.debug("Transaction rollback ({}) redelivered({}) for {} caught: {}", new Object[]{transactionKey, redelivered, ids, e.getMessage()});
+            if (rollbackOnly) {
+                log.debug("Transaction rollback ({}) redelivered({}) for {} due exchange was marked for rollbackOnly", new Object[]{transactionKey, redelivered, ids});
+            } else {
+                log.debug("Transaction rollback ({}) redelivered({}) for {} caught: {}", new Object[]{transactionKey, redelivered, ids, e.getMessage()});
+            }
         } else if (rollbackLoggingLevel == LoggingLevel.TRACE && log.isTraceEnabled()) {
-            log.trace("Transaction rollback ({}) redelivered({}) for {} caught: {}", new Object[]{transactionKey, redelivered, ids, e.getMessage()});
+            if (rollbackOnly) {
+                log.trace("Transaction rollback ({}) redelivered({}) for {} due exchange was marked for rollbackOnly", new Object[]{transactionKey, redelivered, ids});
+            } else {
+                log.trace("Transaction rollback ({}) redelivered({}) for {} caught: {}", new Object[]{transactionKey, redelivered, ids, e.getMessage()});
+            }
         }
     }