001 // Copyright 2008, 2009, 2010, 2011 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 015 package org.apache.tapestry5.ioc.internal; 016 017 import org.apache.tapestry5.ioc.Invokable; 018 import org.apache.tapestry5.ioc.OperationTracker; 019 import org.apache.tapestry5.ioc.internal.util.CollectionFactory; 020 import org.apache.tapestry5.ioc.internal.util.InternalUtils; 021 import org.apache.tapestry5.ioc.util.Stack; 022 import org.slf4j.Logger; 023 024 /** 025 * Core implementation that manages a logger and catches and reports exception. 026 * 027 * @see org.apache.tapestry5.ioc.internal.PerThreadOperationTracker 028 */ 029 public class OperationTrackerImpl implements OperationTracker 030 { 031 private final Logger logger; 032 033 private final Stack<String> operations = CollectionFactory.newStack(); 034 035 private boolean logged; 036 037 public OperationTrackerImpl(Logger logger) 038 { 039 this.logger = logger; 040 } 041 042 public void run(String description, final Runnable operation) 043 { 044 assert InternalUtils.isNonBlank(description); 045 assert operation != null; 046 047 invoke(description, new Invokable<Void>() 048 { 049 public Void invoke() 050 { 051 operation.run(); 052 053 return null; 054 } 055 }); 056 } 057 058 public <T> T invoke(String description, Invokable<T> operation) 059 { 060 assert InternalUtils.isNonBlank(description); 061 assert operation != null; 062 063 long startNanos = System.nanoTime(); 064 065 if (logger.isDebugEnabled()) 066 { 067 logger.debug(String.format("[%3d] --> %s", operations.getDepth() + 1, description)); 068 } 069 070 operations.push(description); 071 072 try 073 { 074 T result = operation.invoke(); 075 076 if (logger.isDebugEnabled()) 077 { 078 long elapsedNanos = System.nanoTime() - startNanos; 079 double elapsedMillis = ((double) elapsedNanos) / 1000000.d; 080 081 logger.debug(String.format("[%3d] <-- %s [%,.2f ms]", operations.getDepth(), description, elapsedMillis)); 082 } 083 084 return result; 085 086 } catch (RuntimeException ex) 087 { 088 logAndRethrow(ex); 089 090 throw ex; 091 } catch (Error ex) 092 { 093 if (!logged) 094 { 095 log(ex); 096 logged = true; 097 } 098 099 throw ex; 100 } finally 101 { 102 operations.pop(); 103 104 // We've finally backed out of the operation stack ... but there may be more to come! 105 106 if (operations.isEmpty()) 107 logged = false; 108 } 109 110 111 } 112 113 private void logAndRethrow(Throwable ex) 114 { 115 if (!logged) 116 { 117 String[] trace = log(ex); 118 119 logged = true; 120 121 throw new OperationException(ex, trace); 122 } 123 } 124 125 private String[] log(Throwable ex) 126 { 127 logger.error(InternalUtils.toMessage(ex)); 128 logger.error("Operations trace:"); 129 130 Object[] snapshot = operations.getSnapshot(); 131 String[] trace = new String[snapshot.length]; 132 133 for (int i = 0; i < snapshot.length; i++) 134 { 135 trace[i] = snapshot[i].toString(); 136 137 logger.error(String.format("[%2d] %s", i + 1, trace[i])); 138 } 139 return trace; 140 } 141 142 boolean isEmpty() 143 { 144 return operations.isEmpty(); 145 } 146 }