[Emacs-diffs] /srv/bzr/emacs/trunk r110342: Count overruns when profiling; change units to ns.

[Paul Eggert]

------------------------------------------------------------
revno: 110342
committer: Paul Eggert <address@hidden>
branch nick: trunk
timestamp: Mon 2012-10-01 23:30:40 -0700
message:
  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.
modified:
  lisp/ChangeLog
  lisp/profiler.el
  src/ChangeLog
  src/profiler.c

=== modified file 'lisp/ChangeLog'
--- a/lisp/ChangeLog    2012-10-02 06:08:36 +0000
+++ b/lisp/ChangeLog    2012-10-02 06:30:40 +0000
@@ -1,3 +1,15 @@
+2012-10-02  Paul Eggert  <address@hidden>
+
+       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  <address@hidden>  (tiny change)
 
        * net/eudcb-bbdb.el (eudc-bbdb-format-record-as-result): Fix

=== modified file 'lisp/profiler.el'
--- a/lisp/profiler.el  2012-10-01 01:46:06 +0000
+++ b/lisp/profiler.el  2012-10-02 06:30:40 +0000
@@ -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 @@
   :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 @@
            (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

=== modified file 'src/ChangeLog'
--- a/src/ChangeLog     2012-10-02 02:43:53 +0000
+++ b/src/ChangeLog     2012-10-02 06:30:40 +0000
@@ -1,3 +1,14 @@
+2012-10-02  Paul Eggert  <address@hidden>
+
+       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  <address@hidden>
 
        * frame.c (Fmake_terminal_frame): Prefer safer CONSP over !NILP.

=== modified file 'src/profiler.c'
--- a/src/profiler.c    2012-09-30 22:21:25 +0000
+++ b/src/profiler.c    2012-10-02 06:30:40 +0000
@@ -128,8 +128,8 @@
 }
 
 /* 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 @@
 /* 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 @@
        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 @@
   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 @@
 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)
 {