001 /*
002 * Copyright 2010-2015 JetBrains s.r.o.
003 *
004 * Licensed under the Apache License, Version 2.0 (the "License");
005 * you may not use this file except in compliance with the License.
006 * You may obtain a copy of the License at
007 *
008 * http://www.apache.org/licenses/LICENSE-2.0
009 *
010 * Unless required by applicable law or agreed to in writing, software
011 * distributed under the License is distributed on an "AS IS" BASIS,
012 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
013 * See the License for the specific language governing permissions and
014 * limitations under the License.
015 */
016
017 package org.jetbrains.kotlin.utils;
018
019 import com.intellij.openapi.diagnostic.Logger;
020 import org.jetbrains.annotations.NotNull;
021
022 import java.io.PrintStream;
023 import java.util.Arrays;
024 import java.util.Stack;
025 import java.util.concurrent.locks.ReentrantLock;
026
027 public class Profiler {
028 // The stack is synchronized here: this is intentional
029 private static final ThreadLocal<Stack<Profiler>> PROFILERS = new ThreadLocal<Stack<Profiler>>() {
030 @Override
031 protected Stack<Profiler> initialValue() {
032 return new Stack<Profiler>();
033 }
034 };
035
036 private static final ReentrantLock OUT_LOCK = new ReentrantLock();
037
038 @NotNull
039 public static Profiler create(@NotNull String name) {
040 //noinspection UseOfSystemOutOrSystemErr
041 return create(name, System.out);
042 }
043
044 @NotNull
045 public static Profiler create(@NotNull String name, @NotNull PrintStream out) {
046 return create(name, new PrintingLogger(out));
047 }
048
049 @NotNull
050 public static Profiler create(@NotNull String name, @NotNull Logger log) {
051 Profiler profiler = new Profiler(name, log);
052 PROFILERS.get().push(profiler);
053 return profiler;
054 }
055
056 public static Profiler getFromContext() {
057 Stack<Profiler> profilers = PROFILERS.get();
058 if (profilers.isEmpty()) {
059 throw new UnsupportedOperationException();
060 }
061 return profilers.peek();
062 }
063
064 private final String name;
065 private final Logger log;
066 private long start = Long.MAX_VALUE;
067 private long cumulative = 0;
068 private boolean paused = true;
069 private StackTraceElement[] stackTrace;
070 private boolean mute;
071 private String formatString;
072
073 private Profiler(@NotNull String name, @NotNull Logger log) {
074 this.name = name;
075 this.log = log;
076 setPrintAccuracy(3);
077 }
078
079 public Profiler recordStackTrace(int depth) {
080 return recordStackTrace(1 /*skipping this frame*/, depth);
081 }
082
083 public Profiler recordStackTrace(int skip, int depth) {
084 StackTraceElement[] trace = new Throwable().getStackTrace();
085
086 int from = 1 + skip;
087 if (from >= trace.length) return this;
088
089 int to;
090 if (depth == -1) {
091 to = trace.length;
092 }
093 else {
094 to = Math.min(skip + depth + 1, trace.length);
095 }
096
097 stackTrace = Arrays.copyOfRange(trace, from, to);
098 return this;
099 }
100
101 public Profiler resetStackTrace() {
102 stackTrace = null;
103 return this;
104 }
105
106 public Profiler printStackTrace() {
107 if (stackTrace != null && log.isDebugEnabled()) {
108 OUT_LOCK.lock();
109 try {
110 for (StackTraceElement element : stackTrace) {
111 println("\tat ", element);
112 }
113 }
114 finally {
115 OUT_LOCK.unlock();
116 }
117 }
118 return this;
119 }
120
121 public Profiler printEntering() {
122 println("Entering ", name);
123 return this;
124 }
125
126 public Profiler printThreadName() {
127 println(Thread.currentThread().getName() + " ", name);
128 return this;
129 }
130
131 public Profiler start() {
132 if (paused) {
133 start = System.nanoTime();
134 paused = false;
135 }
136 return this;
137 }
138
139 public Profiler end() {
140 long result = cumulative;
141 if (!paused) {
142 result += System.nanoTime() - start;
143 }
144 paused = true;
145 cumulative = 0;
146
147 if (!mute && log.isDebugEnabled()) {
148 OUT_LOCK.lock();
149 try {
150 println(name, " took ", format(result));
151 printStackTrace();
152 }
153 finally {
154 OUT_LOCK.unlock();
155 }
156 }
157
158 return this;
159 }
160
161 public Profiler pause() {
162 if (!paused) {
163 cumulative += System.nanoTime() - start;
164 paused = true;
165 }
166 return this;
167 }
168
169 public long getCumulative() {
170 return cumulative;
171 }
172
173 public Profiler mute() {
174 mute = true;
175 return this;
176 }
177
178 public Profiler unmute() {
179 mute = false;
180 return this;
181 }
182
183 public Profiler println(Object message) {
184 if (!mute && log.isDebugEnabled()) {
185 log.debug(String.valueOf(message));
186 }
187 return this;
188 }
189
190 public Profiler println(Object a, Object b) {
191 if (!mute && log.isDebugEnabled()) {
192 OUT_LOCK.lock();
193 try {
194 log.debug(String.valueOf(a) + b);
195 }
196 finally {
197 OUT_LOCK.unlock();
198 }
199 }
200 return this;
201 }
202
203 public Profiler println(Object a, Object b, Object c) {
204 if (!mute && log.isDebugEnabled()) {
205 OUT_LOCK.lock();
206 try {
207 log.debug(String.valueOf(a) + b + c);
208 }
209 finally {
210 OUT_LOCK.unlock();
211 }
212 }
213 return this;
214 }
215
216 public Profiler println(Object a, Object b, Object c, Object... rest) {
217 if (!mute && log.isDebugEnabled()) {
218 OUT_LOCK.lock();
219 try {
220 StringBuilder sb = new StringBuilder();
221 sb.append(a);
222 sb.append(b);
223 sb.append(c);
224 for (Object o : rest) {
225 sb.append(o);
226 }
227 log.debug(sb.toString());
228 }
229 finally {
230 OUT_LOCK.unlock();
231 }
232 }
233 return this;
234 }
235
236 public Profiler setPrintAccuracy(int accuracy) {
237 formatString = "%." + accuracy + "fs";
238 return this;
239 }
240
241 private String format(long delta) {
242 return String.format(formatString, delta / 1e9);
243 }
244 }