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    @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        } finally
123        {
124            handleFinally();
125        }
126    }
127
128    private void handleFinally()
129    {
130        operations.pop();
131
132        // We've finally backed out of the operation stack ... but there may be more to come!
133
134        if (operations.isEmpty())
135        {
136            logged = false;
137        }
138    }
139
140    private <T> T handleError(Error error)
141    {
142        if (!logged)
143        {
144            log(error);
145            logged = true;
146        }
147
148        throw error;
149    }
150
151    private void finish(String description, long startNanos)
152    {
153        if (logger.isDebugEnabled())
154        {
155            long elapsedNanos = System.nanoTime() - startNanos;
156            double elapsedMillis = ((double) elapsedNanos) / 1000000.d;
157
158            logger.debug(String.format("[%3d] <-- %s [%,.2f ms]", operations.getDepth(), description, elapsedMillis));
159        }
160    }
161
162    private long start(String description)
163    {
164        long startNanos = -1l;
165
166        if (logger.isDebugEnabled())
167        {
168            startNanos = System.nanoTime();
169            logger.debug(String.format("[%3d] --> %s", operations.getDepth() + 1, description));
170        }
171
172        operations.push(description);
173        return startNanos;
174    }
175
176    private <T> T logAndRethrow(RuntimeException ex)
177    {
178        if (!logged)
179        {
180            String[] trace = log(ex);
181
182            logged = true;
183
184            throw new OperationException(ex, trace);
185        }
186
187        throw ex;
188    }
189
190    private String[] log(Throwable ex)
191    {
192        logger.error(ExceptionUtils.toMessage(ex));
193        logger.error("Operations trace:");
194
195        Object[] snapshot = operations.getSnapshot();
196        String[] trace = new String[snapshot.length];
197
198        for (int i = 0; i < snapshot.length; i++)
199        {
200            trace[i] = snapshot[i].toString();
201
202            logger.error(String.format("[%2d] %s", i + 1, trace[i]));
203        }
204
205        return trace;
206    }
207
208    boolean isEmpty()
209    {
210        return operations.isEmpty();
211    }
212}