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}