You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tapestry.apache.org by hl...@apache.org on 2014/10/04 02:19:34 UTC

git commit: TAP5-2333: Optimize OperationTracker logging for normal (success, no logging) case

Repository: tapestry-5
Updated Branches:
  refs/heads/master 265d23fcb -> 1cb63a12b


TAP5-2333: Optimize OperationTracker logging for normal (success, no logging) case

This avoids the use of a per-thread variable.


Project: http://git-wip-us.apache.org/repos/asf/tapestry-5/repo
Commit: http://git-wip-us.apache.org/repos/asf/tapestry-5/commit/1cb63a12
Tree: http://git-wip-us.apache.org/repos/asf/tapestry-5/tree/1cb63a12
Diff: http://git-wip-us.apache.org/repos/asf/tapestry-5/diff/1cb63a12

Branch: refs/heads/master
Commit: 1cb63a12b4887b54210d91fe4a9863cf3dad93b5
Parents: 265d23f
Author: Howard M. Lewis Ship <hl...@apache.org>
Authored: Fri Oct 3 17:19:25 2014 -0700
Committer: Howard M. Lewis Ship <hl...@apache.org>
Committed: Fri Oct 3 17:19:25 2014 -0700

----------------------------------------------------------------------
 .../apache/tapestry5/ioc/RegistryBuilder.java   |   2 +-
 .../ioc/internal/OperationException.java        |  29 +++-
 .../ioc/internal/OperationTrackerImpl.java      | 144 +++++++++----------
 .../ioc/internal/PerThreadOperationTracker.java |  90 ------------
 4 files changed, 93 insertions(+), 172 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/tapestry-5/blob/1cb63a12/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/RegistryBuilder.java
----------------------------------------------------------------------
diff --git a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/RegistryBuilder.java b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/RegistryBuilder.java
index d68b2da..493ea3b 100644
--- a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/RegistryBuilder.java
+++ b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/RegistryBuilder.java
@@ -176,7 +176,7 @@ public final class RegistryBuilder
     {
         lock.lock();
 
-        PerThreadOperationTracker tracker = new PerThreadOperationTracker(loggerSource.getLogger(Registry.class));
+        OperationTracker tracker = new OperationTrackerImpl(loggerSource.getLogger(Registry.class));
 
         RegistryImpl registry = new RegistryImpl(modules, proxyFactory, loggerSource, tracker);
 

http://git-wip-us.apache.org/repos/asf/tapestry-5/blob/1cb63a12/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationException.java
----------------------------------------------------------------------
diff --git a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationException.java b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationException.java
index d8b97e0..695fc91 100644
--- a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationException.java
+++ b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationException.java
@@ -1,5 +1,3 @@
-// Copyright 2008, 2010 The Apache Software Foundation
-//
 // Licensed under the Apache License, Version 2.0 (the "License");
 // you may not use this file except in compliance with the License.
 // You may obtain a copy of the License at
@@ -14,7 +12,9 @@
 
 package org.apache.tapestry5.ioc.internal;
 
+import org.apache.tapestry5.ioc.internal.util.CollectionFactory;
 import org.apache.tapestry5.ioc.internal.util.TapestryException;
+import org.apache.tapestry5.ioc.util.Stack;
 
 /**
  * An exception caught and reported by an {@link org.apache.tapestry5.ioc.OperationTracker}; the trace property
@@ -24,17 +24,36 @@ public class OperationException extends TapestryException
 {
     private static final long serialVersionUID = -7555673473832355909L;
 
-    private final String[] trace;
+    private final Stack<String> operations = CollectionFactory.newStack();
 
-    public OperationException(Throwable cause, String[] trace)
+    public OperationException(Throwable cause, String description)
     {
         super(cause.getMessage(), cause);
 
-        this.trace = trace;
+        operations.push(description);
     }
 
     public String[] getTrace()
     {
+        Object[] snapshot = operations.getSnapshot();
+
+        String[] trace = new String[snapshot.length];
+
+        for (int i = 0; i < snapshot.length; i++)
+        {
+            trace[i] = snapshot[i].toString();
+        }
+
         return trace;
     }
+
+    /**
+     * Invoked while unwinding the stack to add descriptions for each OperationTracker run/invoke/perform
+     * operation.
+     *
+     */
+    public void push(String description)
+    {
+        operations.push(description);
+    }
 }

http://git-wip-us.apache.org/repos/asf/tapestry-5/blob/1cb63a12/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationTrackerImpl.java
----------------------------------------------------------------------
diff --git a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationTrackerImpl.java b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationTrackerImpl.java
index 6bc462b..ca6c8a1 100644
--- a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationTrackerImpl.java
+++ b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationTrackerImpl.java
@@ -1,5 +1,3 @@
-// Copyright 2008-2013 The Apache Software Foundation
-//
 // Licensed under the Apache License, Version 2.0 (the "License");
 // you may not use this file except in compliance with the License.
 // You may obtain a copy of the License at
@@ -17,26 +15,24 @@ package org.apache.tapestry5.ioc.internal;
 import org.apache.tapestry5.ioc.IOOperation;
 import org.apache.tapestry5.ioc.Invokable;
 import org.apache.tapestry5.ioc.OperationTracker;
-import org.apache.tapestry5.ioc.internal.util.CollectionFactory;
 import org.apache.tapestry5.ioc.internal.util.InternalUtils;
 import org.apache.tapestry5.ioc.util.ExceptionUtils;
-import org.apache.tapestry5.ioc.util.Stack;
 import org.slf4j.Logger;
 
 import java.io.IOException;
+import java.util.Arrays;
+import java.util.List;
 
 /**
  * Core implementation that manages a logger and catches and reports exception.
- *
- * @see org.apache.tapestry5.ioc.internal.PerThreadOperationTracker
  */
 public class OperationTrackerImpl implements OperationTracker
 {
-    private final Logger logger;
+    private static final String CLASS_NAME = OperationTrackerImpl.class.getName();
 
-    private final Stack<String> operations = CollectionFactory.newStack();
+    private static final List<String> OPERATIONS = Arrays.asList("run", "invoke", "perform");
 
-    private boolean logged;
+    private final Logger logger;
 
     public OperationTrackerImpl(Logger logger)
     {
@@ -57,15 +53,12 @@ public class OperationTrackerImpl implements OperationTracker
 
             finish(description, startNanos);
 
-        } catch (RuntimeException ex)
-        {
-            logAndRethrow(ex);
-        } catch (Error ex)
+        } catch (OperationException oe)
         {
-            handleError(ex);
-        } finally
+            captureDescription(oe, description);
+        } catch (Throwable ex)
         {
-            handleFinally();
+            throwNewOperationException(ex, description);
         }
     }
 
@@ -85,15 +78,12 @@ public class OperationTrackerImpl implements OperationTracker
 
             return result;
 
-        } catch (RuntimeException ex)
+        } catch (OperationException oe)
         {
-            return logAndRethrow(ex);
-        } catch (Error ex)
+            return captureDescription(oe, description);
+        } catch (Throwable ex)
         {
-            return handleError(ex);
-        } finally
-        {
-            handleFinally();
+            return throwNewOperationException(ex, description);
         }
     }
 
@@ -113,39 +103,13 @@ public class OperationTrackerImpl implements OperationTracker
 
             return result;
 
-        } catch (RuntimeException ex)
-        {
-            return logAndRethrow(ex);
-        } catch (Error ex)
+        } catch (OperationException oe)
         {
-            return handleError(ex);
-        } finally
-        {
-            handleFinally();
-        }
-    }
-
-    private void handleFinally()
-    {
-        operations.pop();
-
-        // We've finally backed out of the operation stack ... but there may be more to come!
-
-        if (operations.isEmpty())
-        {
-            logged = false;
-        }
-    }
-
-    private <T> T handleError(Error error)
-    {
-        if (!logged)
+            return captureDescription(oe, description);
+        } catch (Throwable ex)
         {
-            log(error);
-            logged = true;
+            return throwNewOperationException(ex, description);
         }
-
-        throw error;
     }
 
     private void finish(String description, long startNanos)
@@ -155,7 +119,7 @@ public class OperationTrackerImpl implements OperationTracker
             long elapsedNanos = System.nanoTime() - startNanos;
             double elapsedMillis = ((double) elapsedNanos) / 1000000.d;
 
-            logger.debug(String.format("[%3d] <-- %s [%,.2f ms]", operations.getDepth(), description, elapsedMillis));
+            logger.debug(String.format("[%3d] <-- %s [%,.2f ms]", getDepth(), description, elapsedMillis));
         }
     }
 
@@ -165,48 +129,76 @@ public class OperationTrackerImpl implements OperationTracker
 
         if (logger.isDebugEnabled())
         {
+            logger.debug(String.format("[%3d] --> %s", getDepth(), description));
             startNanos = System.nanoTime();
-            logger.debug(String.format("[%3d] --> %s", operations.getDepth() + 1, description));
         }
 
-        operations.push(description);
         return startNanos;
     }
 
-    private <T> T logAndRethrow(RuntimeException ex)
+    private <T> T captureDescription(OperationException oe, String description)
     {
-        if (!logged)
-        {
-            String[] trace = log(ex);
+        oe.push(description);
 
-            logged = true;
+        return logOrRethrow(oe);
+    }
 
-            throw new OperationException(ex, trace);
-        }
+    private <T> T throwNewOperationException(Throwable ex, String description)
+    {
+        OperationException oe = new OperationException(ex, description);
 
-        throw ex;
+        return logOrRethrow(oe);
     }
 
-    private String[] log(Throwable ex)
+    /**
+     * So, when an exception occurs, at the deepest level, an OperationException is thrown via
+     * {@link #throwNewOperationException(Throwable, String)}. Each perform/run/invoke call
+     * catches the OperationException, invokes {@link #captureDescription(OperationException, String)} to
+     * add a message to it, and rethrows it. This method checks to see if it is the first invocation
+     * of perform/run/invoke on the stack and, if so, it logs the operation trace (this is a difference
+     * from 5.3, which logged the trace much earlier). After logging, the OperationException, or
+     * the cause of the OE, is rethrown.
+     *
+     * @param oe
+     * @param <T>
+     * @return
+     */
+    private <T> T logOrRethrow(OperationException oe)
     {
-        logger.error(ExceptionUtils.toMessage(ex));
-        logger.error("Operations trace:");
+        if (getDepth() == 1)
+        {
+            logger.error(ExceptionUtils.toMessage(oe.getCause()));
+            logger.error("Operations trace:");
 
-        Object[] snapshot = operations.getSnapshot();
-        String[] trace = new String[snapshot.length];
+            String[] trace = oe.getTrace();
 
-        for (int i = 0; i < snapshot.length; i++)
-        {
-            trace[i] = snapshot[i].toString();
+            for (int i = 0; i < trace.length; i++)
+            {
+                logger.error(String.format("[%2d] %s", i + 1, trace[i]));
+            }
 
-            logger.error(String.format("[%2d] %s", i + 1, trace[i]));
+            if (oe.getCause() instanceof Error)
+            {
+                throw (Error) oe.getCause();
+            }
         }
 
-        return trace;
+        throw oe;
     }
 
-    boolean isEmpty()
+    private int getDepth()
     {
-        return operations.isEmpty();
+        int result = 0;
+
+        for (StackTraceElement ste : new Throwable().getStackTrace())
+        {
+            if (ste.getClassName().equals(CLASS_NAME) && OPERATIONS.contains(ste.getMethodName()))
+            {
+                ++result;
+            }
+        }
+
+        return result;
     }
+
 }

http://git-wip-us.apache.org/repos/asf/tapestry-5/blob/1cb63a12/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/PerThreadOperationTracker.java
----------------------------------------------------------------------
diff --git a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/PerThreadOperationTracker.java b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/PerThreadOperationTracker.java
deleted file mode 100644
index db2d310..0000000
--- a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/PerThreadOperationTracker.java
+++ /dev/null
@@ -1,90 +0,0 @@
-//  Copyright 2008-2013 The Apache Software Foundation
-//
-// Licensed under the Apache License, Version 2.0 (the "License");
-// you may not use this file except in compliance with the License.
-// You may obtain a copy of the License at
-//
-//     http://www.apache.org/licenses/LICENSE-2.0
-//
-// Unless required by applicable law or agreed to in writing, software
-// distributed under the License is distributed on an "AS IS" BASIS,
-// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
-// See the License for the specific language governing permissions and
-// limitations under the License.
-
-package org.apache.tapestry5.ioc.internal;
-
-import org.apache.tapestry5.ioc.IOOperation;
-import org.apache.tapestry5.ioc.Invokable;
-import org.apache.tapestry5.ioc.OperationTracker;
-import org.slf4j.Logger;
-
-import java.io.IOException;
-
-/**
- * Manages a per-thread OperationTracker using a ThreadLocal.
- */
-public class PerThreadOperationTracker implements OperationTracker
-{
-    private final Logger logger;
-
-    private final ThreadLocal<OperationTrackerImpl> perThread = new ThreadLocal<OperationTrackerImpl>()
-    {
-        @Override
-        protected OperationTrackerImpl initialValue()
-        {
-            return new OperationTrackerImpl(logger);
-        }
-    };
-
-    public PerThreadOperationTracker(Logger logger)
-    {
-        this.logger = logger;
-    }
-
-    OperationTracker get()
-    {
-        return perThread.get();
-    }
-
-    void cleanup()
-    {
-        if (perThread.get().isEmpty()) perThread.remove();
-    }
-
-    @Override
-    public void run(String description, Runnable operation)
-    {
-        try
-        {
-            get().run(description, operation);
-        } finally
-        {
-            cleanup();
-        }
-    }
-
-    @Override
-    public <T> T invoke(String description, Invokable<T> operation)
-    {
-        try
-        {
-            return get().invoke(description, operation);
-        } finally
-        {
-            cleanup();
-        }
-    }
-
-    @Override
-    public <T> T perform(String description, IOOperation<T> operation) throws IOException
-    {
-        try
-        {
-            return get().perform(description, operation);
-        } finally
-        {
-            cleanup();
-        }
-    }
-}


Re: git commit: TAP5-2333: Optimize OperationTracker logging for normal (success, no logging) case

Posted by Howard Lewis Ship <hl...@gmail.com>.
on reflection, I'll be backing this out. It works fine for tests, but can
only produce the full operation trace if the exception is allowed to flow
all tge way back to the outermost level, which only happens in tests.

On Friday, October 3, 2014, <hl...@apache.org> wrote:

> Repository: tapestry-5
> Updated Branches:
>   refs/heads/master 265d23fcb -> 1cb63a12b
>
>
> TAP5-2333: Optimize OperationTracker logging for normal (success, no
> logging) case
>
> This avoids the use of a per-thread variable.
>
>
> Project: http://git-wip-us.apache.org/repos/asf/tapestry-5/repo
> Commit: http://git-wip-us.apache.org/repos/asf/tapestry-5/commit/1cb63a12
> Tree: http://git-wip-us.apache.org/repos/asf/tapestry-5/tree/1cb63a12
> Diff: http://git-wip-us.apache.org/repos/asf/tapestry-5/diff/1cb63a12
>
> Branch: refs/heads/master
> Commit: 1cb63a12b4887b54210d91fe4a9863cf3dad93b5
> Parents: 265d23f
> Author: Howard M. Lewis Ship <hlship@apache.org <javascript:;>>
> Authored: Fri Oct 3 17:19:25 2014 -0700
> Committer: Howard M. Lewis Ship <hlship@apache.org <javascript:;>>
> Committed: Fri Oct 3 17:19:25 2014 -0700
>
> ----------------------------------------------------------------------
>  .../apache/tapestry5/ioc/RegistryBuilder.java   |   2 +-
>  .../ioc/internal/OperationException.java        |  29 +++-
>  .../ioc/internal/OperationTrackerImpl.java      | 144 +++++++++----------
>  .../ioc/internal/PerThreadOperationTracker.java |  90 ------------
>  4 files changed, 93 insertions(+), 172 deletions(-)
> ----------------------------------------------------------------------
>
>
>
> http://git-wip-us.apache.org/repos/asf/tapestry-5/blob/1cb63a12/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/RegistryBuilder.java
> ----------------------------------------------------------------------
> diff --git
> a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/RegistryBuilder.java
> b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/RegistryBuilder.java
> index d68b2da..493ea3b 100644
> ---
> a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/RegistryBuilder.java
> +++
> b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/RegistryBuilder.java
> @@ -176,7 +176,7 @@ public final class RegistryBuilder
>      {
>          lock.lock();
>
> -        PerThreadOperationTracker tracker = new
> PerThreadOperationTracker(loggerSource.getLogger(Registry.class));
> +        OperationTracker tracker = new
> OperationTrackerImpl(loggerSource.getLogger(Registry.class));
>
>          RegistryImpl registry = new RegistryImpl(modules, proxyFactory,
> loggerSource, tracker);
>
>
>
> http://git-wip-us.apache.org/repos/asf/tapestry-5/blob/1cb63a12/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationException.java
> ----------------------------------------------------------------------
> diff --git
> a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationException.java
> b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationException.java
> index d8b97e0..695fc91 100644
> ---
> a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationException.java
> +++
> b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationException.java
> @@ -1,5 +1,3 @@
> -// Copyright 2008, 2010 The Apache Software Foundation
> -//
>  // Licensed under the Apache License, Version 2.0 (the "License");
>  // you may not use this file except in compliance with the License.
>  // You may obtain a copy of the License at
> @@ -14,7 +12,9 @@
>
>  package org.apache.tapestry5.ioc.internal;
>
> +import org.apache.tapestry5.ioc.internal.util.CollectionFactory;
>  import org.apache.tapestry5.ioc.internal.util.TapestryException;
> +import org.apache.tapestry5.ioc.util.Stack;
>
>  /**
>   * An exception caught and reported by an {@link
> org.apache.tapestry5.ioc.OperationTracker}; the trace property
> @@ -24,17 +24,36 @@ public class OperationException extends
> TapestryException
>  {
>      private static final long serialVersionUID = -7555673473832355909L;
>
> -    private final String[] trace;
> +    private final Stack<String> operations = CollectionFactory.newStack();
>
> -    public OperationException(Throwable cause, String[] trace)
> +    public OperationException(Throwable cause, String description)
>      {
>          super(cause.getMessage(), cause);
>
> -        this.trace = trace;
> +        operations.push(description);
>      }
>
>      public String[] getTrace()
>      {
> +        Object[] snapshot = operations.getSnapshot();
> +
> +        String[] trace = new String[snapshot.length];
> +
> +        for (int i = 0; i < snapshot.length; i++)
> +        {
> +            trace[i] = snapshot[i].toString();
> +        }
> +
>          return trace;
>      }
> +
> +    /**
> +     * Invoked while unwinding the stack to add descriptions for each
> OperationTracker run/invoke/perform
> +     * operation.
> +     *
> +     */
> +    public void push(String description)
> +    {
> +        operations.push(description);
> +    }
>  }
>
>
> http://git-wip-us.apache.org/repos/asf/tapestry-5/blob/1cb63a12/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationTrackerImpl.java
> ----------------------------------------------------------------------
> diff --git
> a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationTrackerImpl.java
> b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationTrackerImpl.java
> index 6bc462b..ca6c8a1 100644
> ---
> a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationTrackerImpl.java
> +++
> b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/OperationTrackerImpl.java
> @@ -1,5 +1,3 @@
> -// Copyright 2008-2013 The Apache Software Foundation
> -//
>  // Licensed under the Apache License, Version 2.0 (the "License");
>  // you may not use this file except in compliance with the License.
>  // You may obtain a copy of the License at
> @@ -17,26 +15,24 @@ package org.apache.tapestry5.ioc.internal;
>  import org.apache.tapestry5.ioc.IOOperation;
>  import org.apache.tapestry5.ioc.Invokable;
>  import org.apache.tapestry5.ioc.OperationTracker;
> -import org.apache.tapestry5.ioc.internal.util.CollectionFactory;
>  import org.apache.tapestry5.ioc.internal.util.InternalUtils;
>  import org.apache.tapestry5.ioc.util.ExceptionUtils;
> -import org.apache.tapestry5.ioc.util.Stack;
>  import org.slf4j.Logger;
>
>  import java.io.IOException;
> +import java.util.Arrays;
> +import java.util.List;
>
>  /**
>   * Core implementation that manages a logger and catches and reports
> exception.
> - *
> - * @see org.apache.tapestry5.ioc.internal.PerThreadOperationTracker
>   */
>  public class OperationTrackerImpl implements OperationTracker
>  {
> -    private final Logger logger;
> +    private static final String CLASS_NAME =
> OperationTrackerImpl.class.getName();
>
> -    private final Stack<String> operations = CollectionFactory.newStack();
> +    private static final List<String> OPERATIONS = Arrays.asList("run",
> "invoke", "perform");
>
> -    private boolean logged;
> +    private final Logger logger;
>
>      public OperationTrackerImpl(Logger logger)
>      {
> @@ -57,15 +53,12 @@ public class OperationTrackerImpl implements
> OperationTracker
>
>              finish(description, startNanos);
>
> -        } catch (RuntimeException ex)
> -        {
> -            logAndRethrow(ex);
> -        } catch (Error ex)
> +        } catch (OperationException oe)
>          {
> -            handleError(ex);
> -        } finally
> +            captureDescription(oe, description);
> +        } catch (Throwable ex)
>          {
> -            handleFinally();
> +            throwNewOperationException(ex, description);
>          }
>      }
>
> @@ -85,15 +78,12 @@ public class OperationTrackerImpl implements
> OperationTracker
>
>              return result;
>
> -        } catch (RuntimeException ex)
> +        } catch (OperationException oe)
>          {
> -            return logAndRethrow(ex);
> -        } catch (Error ex)
> +            return captureDescription(oe, description);
> +        } catch (Throwable ex)
>          {
> -            return handleError(ex);
> -        } finally
> -        {
> -            handleFinally();
> +            return throwNewOperationException(ex, description);
>          }
>      }
>
> @@ -113,39 +103,13 @@ public class OperationTrackerImpl implements
> OperationTracker
>
>              return result;
>
> -        } catch (RuntimeException ex)
> -        {
> -            return logAndRethrow(ex);
> -        } catch (Error ex)
> +        } catch (OperationException oe)
>          {
> -            return handleError(ex);
> -        } finally
> -        {
> -            handleFinally();
> -        }
> -    }
> -
> -    private void handleFinally()
> -    {
> -        operations.pop();
> -
> -        // We've finally backed out of the operation stack ... but there
> may be more to come!
> -
> -        if (operations.isEmpty())
> -        {
> -            logged = false;
> -        }
> -    }
> -
> -    private <T> T handleError(Error error)
> -    {
> -        if (!logged)
> +            return captureDescription(oe, description);
> +        } catch (Throwable ex)
>          {
> -            log(error);
> -            logged = true;
> +            return throwNewOperationException(ex, description);
>          }
> -
> -        throw error;
>      }
>
>      private void finish(String description, long startNanos)
> @@ -155,7 +119,7 @@ public class OperationTrackerImpl implements
> OperationTracker
>              long elapsedNanos = System.nanoTime() - startNanos;
>              double elapsedMillis = ((double) elapsedNanos) / 1000000.d;
>
> -            logger.debug(String.format("[%3d] <-- %s [%,.2f ms]",
> operations.getDepth(), description, elapsedMillis));
> +            logger.debug(String.format("[%3d] <-- %s [%,.2f ms]",
> getDepth(), description, elapsedMillis));
>          }
>      }
>
> @@ -165,48 +129,76 @@ public class OperationTrackerImpl implements
> OperationTracker
>
>          if (logger.isDebugEnabled())
>          {
> +            logger.debug(String.format("[%3d] --> %s", getDepth(),
> description));
>              startNanos = System.nanoTime();
> -            logger.debug(String.format("[%3d] --> %s",
> operations.getDepth() + 1, description));
>          }
>
> -        operations.push(description);
>          return startNanos;
>      }
>
> -    private <T> T logAndRethrow(RuntimeException ex)
> +    private <T> T captureDescription(OperationException oe, String
> description)
>      {
> -        if (!logged)
> -        {
> -            String[] trace = log(ex);
> +        oe.push(description);
>
> -            logged = true;
> +        return logOrRethrow(oe);
> +    }
>
> -            throw new OperationException(ex, trace);
> -        }
> +    private <T> T throwNewOperationException(Throwable ex, String
> description)
> +    {
> +        OperationException oe = new OperationException(ex, description);
>
> -        throw ex;
> +        return logOrRethrow(oe);
>      }
>
> -    private String[] log(Throwable ex)
> +    /**
> +     * So, when an exception occurs, at the deepest level, an
> OperationException is thrown via
> +     * {@link #throwNewOperationException(Throwable, String)}. Each
> perform/run/invoke call
> +     * catches the OperationException, invokes {@link
> #captureDescription(OperationException, String)} to
> +     * add a message to it, and rethrows it. This method checks to see if
> it is the first invocation
> +     * of perform/run/invoke on the stack and, if so, it logs the
> operation trace (this is a difference
> +     * from 5.3, which logged the trace much earlier). After logging, the
> OperationException, or
> +     * the cause of the OE, is rethrown.
> +     *
> +     * @param oe
> +     * @param <T>
> +     * @return
> +     */
> +    private <T> T logOrRethrow(OperationException oe)
>      {
> -        logger.error(ExceptionUtils.toMessage(ex));
> -        logger.error("Operations trace:");
> +        if (getDepth() == 1)
> +        {
> +            logger.error(ExceptionUtils.toMessage(oe.getCause()));
> +            logger.error("Operations trace:");
>
> -        Object[] snapshot = operations.getSnapshot();
> -        String[] trace = new String[snapshot.length];
> +            String[] trace = oe.getTrace();
>
> -        for (int i = 0; i < snapshot.length; i++)
> -        {
> -            trace[i] = snapshot[i].toString();
> +            for (int i = 0; i < trace.length; i++)
> +            {
> +                logger.error(String.format("[%2d] %s", i + 1, trace[i]));
> +            }
>
> -            logger.error(String.format("[%2d] %s", i + 1, trace[i]));
> +            if (oe.getCause() instanceof Error)
> +            {
> +                throw (Error) oe.getCause();
> +            }
>          }
>
> -        return trace;
> +        throw oe;
>      }
>
> -    boolean isEmpty()
> +    private int getDepth()
>      {
> -        return operations.isEmpty();
> +        int result = 0;
> +
> +        for (StackTraceElement ste : new Throwable().getStackTrace())
> +        {
> +            if (ste.getClassName().equals(CLASS_NAME) &&
> OPERATIONS.contains(ste.getMethodName()))
> +            {
> +                ++result;
> +            }
> +        }
> +
> +        return result;
>      }
> +
>  }
>
>
> http://git-wip-us.apache.org/repos/asf/tapestry-5/blob/1cb63a12/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/PerThreadOperationTracker.java
> ----------------------------------------------------------------------
> diff --git
> a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/PerThreadOperationTracker.java
> b/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/PerThreadOperationTracker.java
> deleted file mode 100644
> index db2d310..0000000
> ---
> a/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/PerThreadOperationTracker.java
> +++ /dev/null
> @@ -1,90 +0,0 @@
> -//  Copyright 2008-2013 The Apache Software Foundation
> -//
> -// Licensed under the Apache License, Version 2.0 (the "License");
> -// you may not use this file except in compliance with the License.
> -// You may obtain a copy of the License at
> -//
> -//     http://www.apache.org/licenses/LICENSE-2.0
> -//
> -// Unless required by applicable law or agreed to in writing, software
> -// distributed under the License is distributed on an "AS IS" BASIS,
> -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or
> implied.
> -// See the License for the specific language governing permissions and
> -// limitations under the License.
> -
> -package org.apache.tapestry5.ioc.internal;
> -
> -import org.apache.tapestry5.ioc.IOOperation;
> -import org.apache.tapestry5.ioc.Invokable;
> -import org.apache.tapestry5.ioc.OperationTracker;
> -import org.slf4j.Logger;
> -
> -import java.io.IOException;
> -
> -/**
> - * Manages a per-thread OperationTracker using a ThreadLocal.
> - */
> -public class PerThreadOperationTracker implements OperationTracker
> -{
> -    private final Logger logger;
> -
> -    private final ThreadLocal<OperationTrackerImpl> perThread = new
> ThreadLocal<OperationTrackerImpl>()
> -    {
> -        @Override
> -        protected OperationTrackerImpl initialValue()
> -        {
> -            return new OperationTrackerImpl(logger);
> -        }
> -    };
> -
> -    public PerThreadOperationTracker(Logger logger)
> -    {
> -        this.logger = logger;
> -    }
> -
> -    OperationTracker get()
> -    {
> -        return perThread.get();
> -    }
> -
> -    void cleanup()
> -    {
> -        if (perThread.get().isEmpty()) perThread.remove();
> -    }
> -
> -    @Override
> -    public void run(String description, Runnable operation)
> -    {
> -        try
> -        {
> -            get().run(description, operation);
> -        } finally
> -        {
> -            cleanup();
> -        }
> -    }
> -
> -    @Override
> -    public <T> T invoke(String description, Invokable<T> operation)
> -    {
> -        try
> -        {
> -            return get().invoke(description, operation);
> -        } finally
> -        {
> -            cleanup();
> -        }
> -    }
> -
> -    @Override
> -    public <T> T perform(String description, IOOperation<T> operation)
> throws IOException
> -    {
> -        try
> -        {
> -            return get().perform(description, operation);
> -        } finally
> -        {
> -            cleanup();
> -        }
> -    }
> -}
>
>

-- 
Howard M. Lewis Ship

Creator of Apache Tapestry

The source for Tapestry training, mentoring and support. Contact me to
learn how I can get you up and productive in Tapestry fast!

(971) 678-5210
http://howardlewisship.com
@hlship