001// Copyright 2008-2013 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
015package org.apache.tapestry5.ioc.internal;
016
017import org.apache.tapestry5.ioc.IOOperation;
018import org.apache.tapestry5.ioc.Invokable;
019import org.apache.tapestry5.ioc.OperationTracker;
020import org.apache.tapestry5.ioc.internal.util.CollectionFactory;
021import org.apache.tapestry5.ioc.internal.util.InternalUtils;
022import org.apache.tapestry5.ioc.util.ExceptionUtils;
023import org.apache.tapestry5.ioc.util.Stack;
024import org.slf4j.Logger;
025
026import java.io.IOException;
027
028/**
029 * Core implementation that manages a logger and catches and reports exception.
030 *
031 * @see org.apache.tapestry5.ioc.internal.PerThreadOperationTracker
032 */
033public class OperationTrackerImpl implements OperationTracker
034{
035    private final Logger logger;
036
037    private final Stack<String> operations = CollectionFactory.newStack();
038
039    private boolean logged;
040
041    public OperationTrackerImpl(Logger logger)
042    {
043        this.logger = logger;
044    }
045
046    public void run(String description, final Runnable operation)
047    {
048        assert InternalUtils.isNonBlank(description);
049        assert operation != null;
050
051        long startNanos = start(description);
052
053        try
054        {
055            operation.run();
056
057            finish(description, startNanos);
058
059        } catch (RuntimeException ex)
060        {
061            logAndRethrow(ex);
062        } catch (Error ex)
063        {
064            handleError(ex);
065        } finally
066        {
067            handleFinally();
068        }
069    }
070
071    public <T> T invoke(String description, Invokable<T> operation)
072    {
073        assert InternalUtils.isNonBlank(description);
074        assert operation != null;
075
076        long startNanos = start(description);
077
078        try
079        {
080            T result = operation.invoke();
081
082            finish(description, startNanos);
083
084            return result;
085
086        } catch (RuntimeException ex)
087        {
088            return logAndRethrow(ex);
089        } catch (Error ex)
090        {
091            return handleError(ex);
092        } finally
093        {
094            handleFinally();
095        }
096    }
097
098    public <T> T perform(String description, IOOperation<T> operation) throws IOException
099    {
100        InternalUtils.isNonBlank(description);
101        assert operation != null;
102
103        long startNanos = start(description);
104
105        try
106        {
107            T result = operation.perform();
108
109            finish(description, startNanos);
110
111            return result;
112
113        } catch (RuntimeException ex)
114        {
115            return logAndRethrow(ex);
116        } catch (Error ex)
117        {
118            return handleError(ex);
119        } finally
120        {
121            handleFinally();
122        }
123    }
124
125    private void handleFinally()
126    {
127        operations.pop();
128
129        // We've finally backed out of the operation stack ... but there may be more to come!
130
131        if (operations.isEmpty())
132        {
133            logged = false;
134        }
135    }
136
137    private <T> T handleError(Error error)
138    {
139        if (!logged)
140        {
141            log(error);
142            logged = true;
143        }
144
145        throw error;
146    }
147
148    private void finish(String description, long startNanos)
149    {
150        if (logger.isDebugEnabled())
151        {
152            long elapsedNanos = System.nanoTime() - startNanos;
153            double elapsedMillis = ((double) elapsedNanos) / 1000000.d;
154
155            logger.debug(String.format("[%3d] <-- %s [%,.2f ms]", operations.getDepth(), description, elapsedMillis));
156        }
157    }
158
159    private long start(String description)
160    {
161        long startNanos = System.nanoTime();
162
163        if (logger.isDebugEnabled())
164        {
165            logger.debug(String.format("[%3d] --> %s", operations.getDepth() + 1, description));
166        }
167
168        operations.push(description);
169        return startNanos;
170    }
171
172    private <T> T logAndRethrow(RuntimeException ex)
173    {
174        if (!logged)
175        {
176            String[] trace = log(ex);
177
178            logged = true;
179
180            throw new OperationException(ex, trace);
181        }
182
183        throw ex;
184    }
185
186    private String[] log(Throwable ex)
187    {
188        logger.error(ExceptionUtils.toMessage(ex));
189        logger.error("Operations trace:");
190
191        Object[] snapshot = operations.getSnapshot();
192        String[] trace = new String[snapshot.length];
193
194        for (int i = 0; i < snapshot.length; i++)
195        {
196            trace[i] = snapshot[i].toString();
197
198            logger.error(String.format("[%2d] %s", i + 1, trace[i]));
199        }
200
201        return trace;
202    }
203
204    boolean isEmpty()
205    {
206        return operations.isEmpty();
207    }
208}