From b3ecad33ae977f9dd0bdd3e0a10cd8603f54a398 Mon Sep 17 00:00:00 2001 From: Paul Eggert Date: Mon, 1 Oct 2012 23:30:40 -0700 Subject: [PATCH] Count overruns when profiling; change units to ns. * lisp/profiler.el (profiler-sampling-interval): Change units from ms to ns, multiplying the default by 1000000 so that it remains 1 ms. (profiler-report-cpu-line-format): Give enough room for the maximum counters on 64-bit hosts. (profiler-report-render-calltree-1): Call them "CPU samples", not "Time (ms)", since they are not milliseconds now (and never really were). * src/profiler.c (handle_profiler_signal): Count sampling intervals, not ms. Give extra weight to samples after overruns, to attempt to count the time more accurately. (setup_cpu_timer): Change sampling interval units from ms to ns, since the underlying primitives nominally do ns. (Fprofiler_cpu_start): Document the change. Mention that the sampling intervals are only approximate. --- lisp/ChangeLog | 12 ++++++++++++ lisp/profiler.el | 10 +++++----- src/ChangeLog | 11 +++++++++++ src/profiler.c | 31 +++++++++++++++++++++---------- 4 files changed, 49 insertions(+), 15 deletions(-) diff --git a/lisp/ChangeLog b/lisp/ChangeLog index 0a305ee64a..1527307f00 100644 --- a/lisp/ChangeLog +++ b/lisp/ChangeLog @@ -1,3 +1,15 @@ +2012-10-02 Paul Eggert + + Change sampling interval units from ms to ns. + * profiler.el (profiler-sampling-interval): Change units + from ms to ns, multiplying the default by 1000000 so that + it remains 1 ms. + (profiler-report-cpu-line-format): Give enough room for + the maximum counters on 64-bit hosts. + (profiler-report-render-calltree-1): Call them "CPU samples", + not "Time (ms)", since they are not milliseconds now (and + never really were). + 2012-10-02 Sergio Durigan Junior (tiny change) * net/eudcb-bbdb.el (eudc-bbdb-format-record-as-result): Fix diff --git a/lisp/profiler.el b/lisp/profiler.el index 55e706ec70..efa23e7aec 100644 --- a/lisp/profiler.el +++ b/lisp/profiler.el @@ -33,8 +33,8 @@ (defconst profiler-version "24.3") -(defcustom profiler-sampling-interval 1 - "Default sampling interval in millisecond." +(defcustom profiler-sampling-interval 1000000 + "Default sampling interval in nanoseconds." :type 'integer :group 'profiler) @@ -323,8 +323,8 @@ function name of a function itself." :group 'profiler) (defvar profiler-report-cpu-line-format - '((60 left) - (14 right ((9 right) + '((50 left) + (24 right ((19 right) (5 right))))) (defvar profiler-report-memory-line-format @@ -551,7 +551,7 @@ otherwise collapse." (cpu (profiler-report-header-line-format profiler-report-cpu-line-format - "Function" (list "Time (ms)" "%"))) + "Function" (list "CPU samples" "%"))) (memory (profiler-report-header-line-format profiler-report-memory-line-format diff --git a/src/ChangeLog b/src/ChangeLog index a199a7b12e..a7b35a8572 100644 --- a/src/ChangeLog +++ b/src/ChangeLog @@ -1,3 +1,14 @@ +2012-10-02 Paul Eggert + + Count overruns when profiling; change units to ns. + * profiler.c (handle_profiler_signal): Count sampling intervals, not ms. + Give extra weight to samples after overruns, to attempt to count + the time more accurately. + (setup_cpu_timer): Change sampling interval units from ms to ns, since + the underlying primitives nominally do ns. + (Fprofiler_cpu_start): Document the change. Mention that + the sampling intervals are only approximate. + 2012-10-02 Stefan Monnier * frame.c (Fmake_terminal_frame): Prefer safer CONSP over !NILP. diff --git a/src/profiler.c b/src/profiler.c index 2f082edc39..3282b8b335 100644 --- a/src/profiler.c +++ b/src/profiler.c @@ -128,8 +128,8 @@ static void evict_lower_half (log_t *log) } /* Record the current backtrace in LOG. COUNT is the weight of this - current backtrace: milliseconds for CPU counts, and the allocation - size for memory logs. */ + current backtrace: interrupt counts for CPU, and the allocation + size for memory. */ static void record_backtrace (log_t *log, EMACS_INT count) @@ -220,7 +220,7 @@ static Lisp_Object cpu_log; /* Separate counter for the time spent in the GC. */ static EMACS_INT cpu_gc_count; -/* The current sampling interval in milliseconds. */ +/* The current sampling interval in nanoseconds. */ static EMACS_INT current_sampling_interval; /* Signal handler for sampling profiler. */ @@ -235,11 +235,20 @@ handle_profiler_signal (int signal) not expect the ARRAY_MARK_FLAG to be set. We could try and harden the hash-table code, but it doesn't seem worth the effort. */ - cpu_gc_count = saturated_add (cpu_gc_count, current_sampling_interval); + cpu_gc_count = saturated_add (cpu_gc_count, 1); else { + EMACS_INT count = 1; +#ifdef HAVE_TIMER_SETTIME + if (profiler_timer_ok) + { + int overruns = timer_getoverrun (profiler_timer); + eassert (0 <= overruns); + count += overruns; + } +#endif eassert (HASH_TABLE_P (cpu_log)); - record_backtrace (XHASH_TABLE (cpu_log), current_sampling_interval); + record_backtrace (XHASH_TABLE (cpu_log), count); } } @@ -255,16 +264,18 @@ setup_cpu_timer (Lisp_Object sampling_interval) struct sigaction action; struct itimerval timer; struct timespec interval; + int billion = 1000000000; if (! RANGED_INTEGERP (1, sampling_interval, - (TYPE_MAXIMUM (time_t) < EMACS_INT_MAX / 1000 - ? (EMACS_INT) TYPE_MAXIMUM (time_t) * 1000 + 999 + (TYPE_MAXIMUM (time_t) < EMACS_INT_MAX / billion + ? ((EMACS_INT) TYPE_MAXIMUM (time_t) * billion + + (billion - 1)) : EMACS_INT_MAX))) return NOT_RUNNING; current_sampling_interval = XINT (sampling_interval); - interval = make_emacs_time (current_sampling_interval / 1000, - current_sampling_interval % 1000 * 1000000); + interval = make_emacs_time (current_sampling_interval / billion, + current_sampling_interval % billion); emacs_sigaction_init (&action, deliver_profiler_signal); sigaction (SIGPROF, &action, 0); @@ -315,7 +326,7 @@ setup_cpu_timer (Lisp_Object sampling_interval) DEFUN ("profiler-cpu-start", Fprofiler_cpu_start, Sprofiler_cpu_start, 1, 1, 0, doc: /* Start or restart the cpu profiler. -It takes call-stack samples each SAMPLING-INTERVAL milliseconds. +It takes call-stack samples each SAMPLING-INTERVAL nanoseconds, approximately. See also `profiler-log-size' and `profiler-max-stack-depth'. */) (Lisp_Object sampling_interval) { -- 2.20.1