aboutsummaryrefslogtreecommitdiffstats
path: root/src/profiler.c
diff options
context:
space:
mode:
Diffstat (limited to 'src/profiler.c')
-rw-r--r--src/profiler.c232
1 files changed, 174 insertions, 58 deletions
diff --git a/src/profiler.c b/src/profiler.c
index 877a42cc98e..461aae3e09f 100644
--- a/src/profiler.c
+++ b/src/profiler.c
@@ -18,12 +18,18 @@ You should have received a copy of the GNU General Public License
18along with GNU Emacs. If not, see <http://www.gnu.org/licenses/>. */ 18along with GNU Emacs. If not, see <http://www.gnu.org/licenses/>. */
19 19
20#include <config.h> 20#include <config.h>
21#include <stdio.h>
22#include <limits.h>
23#include <sys/time.h>
24#include <signal.h>
25#include <setjmp.h>
26#include "lisp.h" 21#include "lisp.h"
22#include "syssignal.h"
23#include "systime.h"
24
25/* Return A + B, but return the maximum fixnum if the result would overflow.
26 Assume A and B are nonnegative and in fixnum range. */
27
28static EMACS_INT
29saturated_add (EMACS_INT a, EMACS_INT b)
30{
31 return min (a + b, MOST_POSITIVE_FIXNUM);
32}
27 33
28/* Logs. */ 34/* Logs. */
29 35
@@ -121,14 +127,12 @@ static void evict_lower_half (log_t *log)
121 } 127 }
122} 128}
123 129
124/* Record the current backtrace in LOG. BASE is a special name for 130/* Record the current backtrace in LOG. COUNT is the weight of this
125 describing which the backtrace come from. BASE can be nil. COUNT is 131 current backtrace: interrupt counts for CPU, and the allocation
126 a number how many times the profiler sees the backtrace at the 132 size for memory. */
127 time. ELAPSED is a elapsed time in millisecond that the backtrace
128 took. */
129 133
130static void 134static void
131record_backtrace (log_t *log, size_t count) 135record_backtrace (log_t *log, EMACS_INT count)
132{ 136{
133 struct backtrace *backlist = backtrace_list; 137 struct backtrace *backlist = backtrace_list;
134 Lisp_Object backtrace; 138 Lisp_Object backtrace;
@@ -148,7 +152,7 @@ record_backtrace (log_t *log, size_t count)
148 /* Copy the backtrace contents into working memory. */ 152 /* Copy the backtrace contents into working memory. */
149 for (; i < asize && backlist; i++, backlist = backlist->next) 153 for (; i < asize && backlist; i++, backlist = backlist->next)
150 /* FIXME: For closures we should ignore the environment. */ 154 /* FIXME: For closures we should ignore the environment. */
151 ASET (backtrace, i, *backlist->function); 155 ASET (backtrace, i, backlist->function);
152 156
153 /* Make sure that unused space of working memory is filled with nil. */ 157 /* Make sure that unused space of working memory is filled with nil. */
154 for (; i < asize; i++) 158 for (; i < asize; i++)
@@ -161,8 +165,11 @@ record_backtrace (log_t *log, size_t count)
161 EMACS_UINT hash; 165 EMACS_UINT hash;
162 ptrdiff_t j = hash_lookup (log, backtrace, &hash); 166 ptrdiff_t j = hash_lookup (log, backtrace, &hash);
163 if (j >= 0) 167 if (j >= 0)
164 set_hash_value_slot (log, j, 168 {
165 make_number (count + XINT (HASH_VALUE (log, j)))); 169 EMACS_INT old_val = XINT (HASH_VALUE (log, j));
170 EMACS_INT new_val = saturated_add (old_val, count);
171 set_hash_value_slot (log, j, make_number (new_val));
172 }
166 else 173 else
167 { /* BEWARE! hash_put in general can allocate memory. 174 { /* BEWARE! hash_put in general can allocate memory.
168 But currently it only does that if log->next_free is nil. */ 175 But currently it only does that if log->next_free is nil. */
@@ -191,56 +198,153 @@ record_backtrace (log_t *log, size_t count)
191 } 198 }
192} 199}
193 200
194/* Sample profiler. */ 201/* Sampling profiler. */
195 202
196/* FIXME: Add support for the CPU profiler in W32. */ 203#ifdef PROFILER_CPU_SUPPORT
197/* FIXME: the sigprof_handler suffers from race-conditions if the signal
198 is delivered to a thread other than the main Emacs thread. */
199 204
200#if defined SIGPROF && defined HAVE_SETITIMER 205/* The profiler timer and whether it was properly initialized, if
201#define PROFILER_CPU_SUPPORT 206 POSIX timers are available. */
207#ifdef HAVE_ITIMERSPEC
208static timer_t profiler_timer;
209static bool profiler_timer_ok;
210#endif
202 211
203/* True if sampling profiler is running. */ 212/* Status of sampling profiler. */
204static bool profiler_cpu_running; 213static enum profiler_cpu_running
214 { NOT_RUNNING, TIMER_SETTIME_RUNNING, SETITIMER_RUNNING }
215 profiler_cpu_running;
205 216
217/* Hash-table log of CPU profiler. */
206static Lisp_Object cpu_log; 218static Lisp_Object cpu_log;
219
207/* Separate counter for the time spent in the GC. */ 220/* Separate counter for the time spent in the GC. */
208static EMACS_INT cpu_gc_count; 221static EMACS_INT cpu_gc_count;
209 222
210/* The current sample interval in millisecond. */ 223/* The current sampling interval in nanoseconds. */
224static EMACS_INT current_sampling_interval;
211 225
212static int current_sample_interval; 226/* Signal handler for sampling profiler. */
213
214/* Signal handler for sample profiler. */
215 227
216static void 228static void
217sigprof_handler (int signal) 229handle_profiler_signal (int signal)
218{ 230{
219 eassert (HASH_TABLE_P (cpu_log)); 231 if (backtrace_list && EQ (backtrace_list->function, Qautomatic_gc))
220 if (backtrace_list && EQ (*backtrace_list->function, Qautomatic_gc))
221 /* Special case the time-count inside GC because the hash-table 232 /* Special case the time-count inside GC because the hash-table
222 code is not prepared to be used while the GC is running. 233 code is not prepared to be used while the GC is running.
223 More specifically it uses ASIZE at many places where it does 234 More specifically it uses ASIZE at many places where it does
224 not expect the ARRAY_MARK_FLAG to be set. We could try and 235 not expect the ARRAY_MARK_FLAG to be set. We could try and
225 harden the hash-table code, but it doesn't seem worth the 236 harden the hash-table code, but it doesn't seem worth the
226 effort. */ 237 effort. */
227 cpu_gc_count += current_sample_interval; 238 cpu_gc_count = saturated_add (cpu_gc_count, 1);
228 else 239 else
229 record_backtrace (XHASH_TABLE (cpu_log), current_sample_interval); 240 {
241 Lisp_Object oquit;
242 EMACS_INT count = 1;
243#ifdef HAVE_ITIMERSPEC
244 if (profiler_timer_ok)
245 {
246 int overruns = timer_getoverrun (profiler_timer);
247 eassert (0 <= overruns);
248 count += overruns;
249 }
250#endif
251 /* record_backtrace uses hash functions that call Fequal, which
252 uses QUIT, which can call malloc, which can cause disaster in
253 a signal handler. So inhibit QUIT. */
254 oquit = Vinhibit_quit;
255 Vinhibit_quit = Qt;
256
257 eassert (HASH_TABLE_P (cpu_log));
258 record_backtrace (XHASH_TABLE (cpu_log), count);
259
260 Vinhibit_quit = oquit;
261 }
262}
263
264static void
265deliver_profiler_signal (int signal)
266{
267 deliver_process_signal (signal, handle_profiler_signal);
268}
269
270static enum profiler_cpu_running
271setup_cpu_timer (Lisp_Object sampling_interval)
272{
273 struct sigaction action;
274 struct itimerval timer;
275 struct timespec interval;
276 int billion = 1000000000;
277
278 if (! RANGED_INTEGERP (1, sampling_interval,
279 (TYPE_MAXIMUM (time_t) < EMACS_INT_MAX / billion
280 ? ((EMACS_INT) TYPE_MAXIMUM (time_t) * billion
281 + (billion - 1))
282 : EMACS_INT_MAX)))
283 return NOT_RUNNING;
284
285 current_sampling_interval = XINT (sampling_interval);
286 interval = make_emacs_time (current_sampling_interval / billion,
287 current_sampling_interval % billion);
288 emacs_sigaction_init (&action, deliver_profiler_signal);
289 sigaction (SIGPROF, &action, 0);
290
291#ifdef HAVE_ITIMERSPEC
292 if (! profiler_timer_ok)
293 {
294 /* System clocks to try, in decreasing order of desirability. */
295 static clockid_t const system_clock[] = {
296#ifdef CLOCK_THREAD_CPUTIME_ID
297 CLOCK_THREAD_CPUTIME_ID,
298#endif
299#ifdef CLOCK_PROCESS_CPUTIME_ID
300 CLOCK_PROCESS_CPUTIME_ID,
301#endif
302#ifdef CLOCK_MONOTONIC
303 CLOCK_MONOTONIC,
304#endif
305 CLOCK_REALTIME
306 };
307 int i;
308 struct sigevent sigev;
309 sigev.sigev_value.sival_ptr = &profiler_timer;
310 sigev.sigev_signo = SIGPROF;
311 sigev.sigev_notify = SIGEV_SIGNAL;
312
313 for (i = 0; i < sizeof system_clock / sizeof *system_clock; i++)
314 if (timer_create (system_clock[i], &sigev, &profiler_timer) == 0)
315 {
316 profiler_timer_ok = 1;
317 break;
318 }
319 }
320
321 if (profiler_timer_ok)
322 {
323 struct itimerspec ispec;
324 ispec.it_value = ispec.it_interval = interval;
325 if (timer_settime (profiler_timer, 0, &ispec, 0) == 0)
326 return TIMER_SETTIME_RUNNING;
327 }
328#endif
329
330#ifdef HAVE_SETITIMER
331 timer.it_value = timer.it_interval = make_timeval (interval);
332 if (setitimer (ITIMER_PROF, &timer, 0) == 0)
333 return SETITIMER_RUNNING;
334#endif
335
336 return NOT_RUNNING;
230} 337}
231 338
232DEFUN ("profiler-cpu-start", Fprofiler_cpu_start, Sprofiler_cpu_start, 339DEFUN ("profiler-cpu-start", Fprofiler_cpu_start, Sprofiler_cpu_start,
233 1, 1, 0, 340 1, 1, 0,
234 doc: /* Start or restart the cpu profiler. 341 doc: /* Start or restart the cpu profiler.
235The cpu profiler will take call-stack samples each SAMPLE-INTERVAL (expressed in milliseconds). 342It takes call-stack samples each SAMPLING-INTERVAL nanoseconds, approximately.
236See also `profiler-log-size' and `profiler-max-stack-depth'. */) 343See also `profiler-log-size' and `profiler-max-stack-depth'. */)
237 (Lisp_Object sample_interval) 344 (Lisp_Object sampling_interval)
238{ 345{
239 struct sigaction sa;
240 struct itimerval timer;
241
242 if (profiler_cpu_running) 346 if (profiler_cpu_running)
243 error ("Sample profiler is already running"); 347 error ("CPU profiler is already running");
244 348
245 if (NILP (cpu_log)) 349 if (NILP (cpu_log))
246 { 350 {
@@ -249,19 +353,9 @@ See also `profiler-log-size' and `profiler-max-stack-depth'. */)
249 profiler_max_stack_depth); 353 profiler_max_stack_depth);
250 } 354 }
251 355
252 current_sample_interval = XINT (sample_interval); 356 profiler_cpu_running = setup_cpu_timer (sampling_interval);
253 357 if (! profiler_cpu_running)
254 sa.sa_handler = sigprof_handler; 358 error ("Invalid sampling interval");
255 sa.sa_flags = SA_RESTART;
256 sigemptyset (&sa.sa_mask);
257 sigaction (SIGPROF, &sa, 0);
258
259 timer.it_interval.tv_sec = 0;
260 timer.it_interval.tv_usec = current_sample_interval * 1000;
261 timer.it_value = timer.it_interval;
262 setitimer (ITIMER_PROF, &timer, 0);
263
264 profiler_cpu_running = true;
265 359
266 return Qt; 360 return Qt;
267} 361}
@@ -272,12 +366,34 @@ DEFUN ("profiler-cpu-stop", Fprofiler_cpu_stop, Sprofiler_cpu_stop,
272Return non-nil if the profiler was running. */) 366Return non-nil if the profiler was running. */)
273 (void) 367 (void)
274{ 368{
275 if (!profiler_cpu_running) 369 switch (profiler_cpu_running)
276 return Qnil; 370 {
277 profiler_cpu_running = false; 371 case NOT_RUNNING:
372 return Qnil;
278 373
279 setitimer (ITIMER_PROF, 0, 0); 374#ifdef HAVE_ITIMERSPEC
375 case TIMER_SETTIME_RUNNING:
376 {
377 struct itimerspec disable;
378 memset (&disable, 0, sizeof disable);
379 timer_settime (profiler_timer, 0, &disable, 0);
380 }
381 break;
382#endif
280 383
384#ifdef HAVE_SETITIMER
385 case SETITIMER_RUNNING:
386 {
387 struct itimerval disable;
388 memset (&disable, 0, sizeof disable);
389 setitimer (ITIMER_PROF, &disable, 0);
390 }
391 break;
392#endif
393 }
394
395 signal (SIGPROF, SIG_IGN);
396 profiler_cpu_running = NOT_RUNNING;
281 return Qt; 397 return Qt;
282} 398}
283 399
@@ -300,7 +416,7 @@ Before returning, a new log is allocated for future samples. */)
300 (void) 416 (void)
301{ 417{
302 Lisp_Object result = cpu_log; 418 Lisp_Object result = cpu_log;
303 /* Here we're making the log visible to Elisp , so it's not safe any 419 /* Here we're making the log visible to Elisp, so it's not safe any
304 more for our use afterwards since we can't rely on its special 420 more for our use afterwards since we can't rely on its special
305 pre-allocated keys anymore. So we have to allocate a new one. */ 421 pre-allocated keys anymore. So we have to allocate a new one. */
306 cpu_log = (profiler_cpu_running 422 cpu_log = (profiler_cpu_running
@@ -312,7 +428,7 @@ Before returning, a new log is allocated for future samples. */)
312 cpu_gc_count = 0; 428 cpu_gc_count = 0;
313 return result; 429 return result;
314} 430}
315#endif /* not defined PROFILER_CPU_SUPPORT */ 431#endif /* PROFILER_CPU_SUPPORT */
316 432
317/* Memory profiler. */ 433/* Memory profiler. */
318 434
@@ -392,7 +508,7 @@ void
392malloc_probe (size_t size) 508malloc_probe (size_t size)
393{ 509{
394 eassert (HASH_TABLE_P (memory_log)); 510 eassert (HASH_TABLE_P (memory_log));
395 record_backtrace (XHASH_TABLE (memory_log), size); 511 record_backtrace (XHASH_TABLE (memory_log), min (size, MOST_POSITIVE_FIXNUM));
396} 512}
397 513
398void 514void
@@ -408,7 +524,7 @@ to make room for new entries. */);
408 profiler_log_size = 10000; 524 profiler_log_size = 10000;
409 525
410#ifdef PROFILER_CPU_SUPPORT 526#ifdef PROFILER_CPU_SUPPORT
411 profiler_cpu_running = false; 527 profiler_cpu_running = NOT_RUNNING;
412 cpu_log = Qnil; 528 cpu_log = Qnil;
413 staticpro (&cpu_log); 529 staticpro (&cpu_log);
414 defsubr (&Sprofiler_cpu_start); 530 defsubr (&Sprofiler_cpu_start);