    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}