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}