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.commons.util.CollectionFactory;
018import org.apache.tapestry5.commons.util.ExceptionUtils;
019import org.apache.tapestry5.commons.util.Stack;
020import org.apache.tapestry5.ioc.IOOperation;
021import org.apache.tapestry5.ioc.Invokable;
022import org.apache.tapestry5.ioc.OperationTracker;
023import org.apache.tapestry5.ioc.internal.util.InternalUtils;
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    @Override
047    public void run(String description, final Runnable operation)
048    {
049        assert InternalUtils.isNonBlank(description);
050        assert operation != null;
051
052        long startNanos = start(description);
053
054        try
055        {
056            operation.run();
057
058            finish(description, startNanos);
059
060        } catch (RuntimeException ex)
061        {
062            logAndRethrow(ex);
063        } catch (Error ex)
064        {
065            handleError(ex);
066        } finally
067        {
068            handleFinally();
069        }
070    }
071
072    @Override
073    public <T> T invoke(String description, Invokable<T> operation)
074    {
075        assert InternalUtils.isNonBlank(description);
076        assert operation != null;
077
078        long startNanos = start(description);
079
080        try
081        {
082            T result = operation.invoke();
083
084            finish(description, startNanos);
085
086            return result;
087
088        } catch (RuntimeException ex)
089        {
090            return logAndRethrow(ex);
091        } catch (Error ex)
092        {
093            return handleError(ex);
094        } finally
095        {
096            handleFinally();
097        }
098    }
099
100    @Override
101    public <T> T perform(String description, IOOperation<T> operation) throws IOException
102    {
103        InternalUtils.isNonBlank(description);
104        assert operation != null;
105
106        long startNanos = start(description);
107
108        try
109        {
110            T result = operation.perform();
111
112            finish(description, startNanos);
113
114            return result;
115
116        } catch (RuntimeException ex)
117        {
118            return logAndRethrow(ex);
119        } catch (Error ex)
120        {
121            return handleError(ex);
122        } catch (IOException ex)
123        {
124            return logAndRethrow(ex);
125        } finally
126        {
127            handleFinally();
128        }
129    }
130
131    private void handleFinally()
132    {
133        operations.pop();
134        // We've finally backed out of the operation stack ... but there may be more to come!
135
136        if (operations.isEmpty())
137        {
138            logged = false;
139        }
140    }
141
142    private <T> T handleError(Error error)
143    {
144        if (!logged)
145        {
146            log(error);
147            logged = true;
148        }
149
150        throw error;
151    }
152
153    private void finish(String description, long startNanos)
154    {
155        if (logger.isDebugEnabled())
156        {
157            long elapsedNanos = System.nanoTime() - startNanos;
158            double elapsedMillis = ((double) elapsedNanos) / 1000000.d;
159
160            logger.debug(String.format("[%3d] <-- %s [%,.2f ms]", operations.getDepth(), description, elapsedMillis));
161        }
162    }
163
164    private long start(String description)
165    {
166        long startNanos = -1l;
167
168        if (logger.isDebugEnabled())
169        {
170            startNanos = System.nanoTime();
171            logger.debug(String.format("[%3d] --> %s", operations.getDepth() + 1, description));
172        }
173
174        operations.push(description);
175        return startNanos;
176    }
177
178    private <T> T logAndRethrow(RuntimeException ex)
179    {
180        if (!logged)
181        {
182            String[] trace = log(ex);
183
184            logged = true;
185
186            throw new OperationException(ex, trace);
187        }
188
189        throw ex;
190    }
191
192    private <T> T logAndRethrow(IOException ex) throws IOException
193    {
194        if (!logged)
195        {
196            String[] trace = log(ex);
197
198            logged = true;
199
200            throw new OperationException(ex, trace);
201        }
202
203        throw ex;
204    }
205
206    private String[] log(Throwable ex)
207    {
208        logger.error(ExceptionUtils.toMessage(ex));
209        logger.error("Operations trace:");
210
211        Object[] snapshot = operations.getSnapshot();
212        String[] trace = new String[snapshot.length];
213
214        for (int i = 0; i < snapshot.length; i++)
215        {
216            trace[i] = snapshot[i].toString();
217
218            logger.error(String.format("[%2d] %s", i + 1, trace[i]));
219        }
220
221        return trace;
222    }
223
224    boolean isEmpty()
225    {
226        return operations.isEmpty();
227    }
228}