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 <hls...@apache.org> Authored: Fri Oct 3 17:19:25 2014 -0700 Committer: Howard M. Lewis Ship <hls...@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(); - } - } -}
