001    // Copyright 2008, 2009, 2010, 2011 The Apache Software Foundation
002    //
003    // Licensed under the Apache License, Version 2.0 (the "License");
004    // you may not use this file except in compliance with the License.
005    // You may obtain a copy of the License at
006    //
007    // http://www.apache.org/licenses/LICENSE-2.0
008    //
009    // Unless required by applicable law or agreed to in writing, software
010    // distributed under the License is distributed on an "AS IS" BASIS,
011    // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
012    // See the License for the specific language governing permissions and
013    // limitations under the License.
014    
015    package org.apache.tapestry5.ioc.internal;
016    
017    import org.apache.tapestry5.ioc.Invokable;
018    import org.apache.tapestry5.ioc.OperationTracker;
019    import org.apache.tapestry5.ioc.internal.util.CollectionFactory;
020    import org.apache.tapestry5.ioc.internal.util.InternalUtils;
021    import org.apache.tapestry5.ioc.util.Stack;
022    import org.slf4j.Logger;
023    
024    /**
025     * Core implementation that manages a logger and catches and reports exception.
026     *
027     * @see org.apache.tapestry5.ioc.internal.PerThreadOperationTracker
028     */
029    public class OperationTrackerImpl implements OperationTracker
030    {
031        private final Logger logger;
032    
033        private final Stack<String> operations = CollectionFactory.newStack();
034    
035        private boolean logged;
036    
037        public OperationTrackerImpl(Logger logger)
038        {
039            this.logger = logger;
040        }
041    
042        public void run(String description, final Runnable operation)
043        {
044            assert InternalUtils.isNonBlank(description);
045            assert operation != null;
046    
047            invoke(description, new Invokable<Void>()
048            {
049                public Void invoke()
050                {
051                    operation.run();
052    
053                    return null;
054                }
055            });
056        }
057    
058        public <T> T invoke(String description, Invokable<T> operation)
059        {
060            assert InternalUtils.isNonBlank(description);
061            assert operation != null;
062    
063            long startNanos = System.nanoTime();
064    
065            if (logger.isDebugEnabled())
066            {
067                logger.debug(String.format("[%3d] --> %s", operations.getDepth() + 1, description));
068            }
069    
070            operations.push(description);
071    
072            try
073            {
074                T result = operation.invoke();
075    
076                if (logger.isDebugEnabled())
077                {
078                    long elapsedNanos = System.nanoTime() - startNanos;
079                    double elapsedMillis = ((double) elapsedNanos) / 1000000.d;
080    
081                    logger.debug(String.format("[%3d] <-- %s [%,.2f ms]", operations.getDepth(), description, elapsedMillis));
082                }
083    
084                return result;
085    
086            } catch (RuntimeException ex)
087            {
088                logAndRethrow(ex);
089    
090                throw ex;
091            } catch (Error ex)
092            {
093                if (!logged)
094                {
095                    log(ex);
096                    logged = true;
097                }
098    
099                throw ex;
100            } finally
101            {
102                operations.pop();
103    
104                // We've finally backed out of the operation stack ... but there may be more to come!
105    
106                if (operations.isEmpty())
107                    logged = false;
108            }
109    
110    
111        }
112    
113        private void logAndRethrow(Throwable ex)
114        {
115            if (!logged)
116            {
117                String[] trace = log(ex);
118    
119                logged = true;
120    
121                throw new OperationException(ex, trace);
122            }
123        }
124    
125        private String[] log(Throwable ex)
126        {
127            logger.error(InternalUtils.toMessage(ex));
128            logger.error("Operations trace:");
129    
130            Object[] snapshot = operations.getSnapshot();
131            String[] trace = new String[snapshot.length];
132    
133            for (int i = 0; i < snapshot.length; i++)
134            {
135                trace[i] = snapshot[i].toString();
136    
137                logger.error(String.format("[%2d] %s", i + 1, trace[i]));
138            }
139            return trace;
140        }
141    
142        boolean isEmpty()
143        {
144            return operations.isEmpty();
145        }
146    }