tapestry-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Howard Lewis Ship <hls...@gmail.com>
Subject Re: git commit: TAP5-2333: Optimize OperationTracker logging for normal (success, no logging) case
Date Sun, 05 Oct 2014 18:30:34 GMT
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, <hlship@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

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message