001package org.javasimon.callback.calltree; 002 003import static org.javasimon.callback.logging.LogTemplates.toSLF4J; 004import static org.javasimon.callback.logging.LogTemplates.whenSplitLongerThanMilliseconds; 005 006import org.javasimon.Split; 007import org.javasimon.Stopwatch; 008import org.javasimon.StopwatchSample; 009import org.javasimon.callback.CallbackSkeleton; 010import org.javasimon.callback.logging.LogTemplate; 011import org.javasimon.callback.logging.SplitThresholdLogTemplate; 012 013/** 014 * Callback which logs the call tree when the main call is bigger than specified threshold. 015 * This callback can give good results only if interceptors/filters have been 016 * placed a different level of the application (web/business/data tiers for 017 * instance). 018 * <p/> 019 * Call tree looks like this: 020 * <pre> 021 * org.javasimon.web.Controller.execute 123ms 022 * org.javasimon.business.FirstService.work 75ms, 75% 023 * org.javasimon.data.FirstDAO.findAll 50 ms, 82% 024 * org.javasimon.data.SecondDAO.findByRelation 20ms, 10%, 3 025 * org.javasimon.business.SecondService.do 10ms, 5% 026 * </pre> 027 * 028 * @author gquintana 029 * @see CallTree 030 * @since 3.2 031 */ 032public class CallTreeCallback extends CallbackSkeleton { 033 034 /** Call tree of current thread. */ 035 private final ThreadLocal<CallTree> threadCallTree = new ThreadLocal<>(); 036 037 /** Log template used for printing call tree. */ 038 private LogTemplate<Split> callTreeLogTemplate; 039 040 /** Simon attribute name used to store last significant call tree. */ 041 public static final String ATTR_NAME_LAST = "lastCallTree"; 042 043 /** Duration threshold used to trigger logging and remembering. */ 044 private Long logThreshold; 045 046 /** Default constructor. */ 047 public CallTreeCallback() { 048 initLogThreshold(500L); 049 } 050 051 /** 052 * Constructor with logging duration threshold. 053 * 054 * @param threshold Threshold 055 */ 056 public CallTreeCallback(long threshold) { 057 initLogThreshold(threshold); 058 } 059 060 /** 061 * Constructor with log template. 062 * 063 * @param callTreeLogTemplate Log template 064 */ 065 public CallTreeCallback(LogTemplate<Split> callTreeLogTemplate) { 066 this.callTreeLogTemplate = callTreeLogTemplate; 067 } 068 069 /** Configures {@link #callTreeLogTemplate} with a {@link SplitThresholdLogTemplate}. */ 070 private void initLogThreshold(Long threshold) { 071 this.logThreshold = threshold; 072 final LogTemplate<Split> toLogger = toSLF4J(getClass().getName(), "debug"); 073 if (threshold == null) { 074 callTreeLogTemplate = toLogger; 075 } else { 076 callTreeLogTemplate = whenSplitLongerThanMilliseconds(toLogger, threshold); 077 } 078 } 079 080 /** Returns log threshold when {@link #callTreeLogTemplate} is a {@link SplitThresholdLogTemplate}. */ 081 public Long getLogThreshold() { 082 return logThreshold; 083 } 084 085 /** 086 * Sets log threshold. 087 * Configure {@link #callTreeLogTemplate} with a {@link SplitThresholdLogTemplate}. 088 */ 089 public void setLogThreshold(Long logThreshold) { 090 initLogThreshold(logThreshold); 091 } 092 093 /** 094 * Returns call tree for current thread. 095 * 096 * @return Thread call tree 097 */ 098 private CallTree getCallTree() { 099 return threadCallTree.get(); 100 } 101 102 /** 103 * Initializes the call tree for current thread. 104 * 105 * @return Created call tree 106 */ 107 private CallTree initCallTree() { 108 final CallTree callTree = new CallTree(logThreshold) { 109 @Override 110 protected void onRootStopwatchStop(CallTreeNode rootNode, Split split) { 111 CallTreeCallback.this.onRootStopwatchStop(this, split); 112 } 113 }; 114 threadCallTree.set(callTree); 115 return callTree; 116 } 117 118 /** Removes call tree for current thread. */ 119 private void removeCallTree() { 120 threadCallTree.remove(); 121 } 122 123 @Override 124 public void onStopwatchStart(Split split) { 125 CallTree callTree = getCallTree(); 126 if (callTree == null) { 127 // New tree root 128 callTree = initCallTree(); 129 } 130 callTree.onStopwatchStart(split); 131 } 132 133 @Override 134 public void onStopwatchStop(Split split, StopwatchSample sample) { 135 getCallTree().onStopwatchStop(split); 136 } 137 138 /** 139 * When stopwatch corresponding to root tree node is stopped, this method is called. 140 * Logs call tree when split is longer than threshold. 141 * 142 * @param callTree call tree to log 143 * @param split stopped split 144 */ 145 public void onRootStopwatchStop(CallTree callTree, Split split) { 146 callTreeLogTemplate.log(split, callTree); 147 if (logThreshold != null && split.runningFor() > logThreshold) { 148 split.getStopwatch().setAttribute(ATTR_NAME_LAST, callTree); 149 } 150 removeCallTree(); 151 } 152 153 /** 154 * Returns last call tree stored in stopwatch attributes. 155 * 156 * @param stopwatch Stopwatch 157 * @return Last call tree or {@code null} if any 158 */ 159 public static CallTree getLastCallTree(Stopwatch stopwatch) { 160 return (CallTree) stopwatch.getAttribute(ATTR_NAME_LAST); 161 } 162}