Merge from trunk + rename the event. Not tested yet.
[bpt/emacs.git] / src / profiler.c
index 44a12fc..3d8f724 100644 (file)
@@ -18,18 +18,26 @@ You should have received a copy of the GNU General Public License
 along with GNU Emacs.  If not, see <http://www.gnu.org/licenses/>.  */
 
 #include <config.h>
-#include <stdio.h>
-#include <limits.h>
-#include <sys/time.h>
-#include <signal.h>
-#include <setjmp.h>
 #include "lisp.h"
 #include "syssignal.h"
+#include "systime.h"
+
+/* Return A + B, but return the maximum fixnum if the result would overflow.
+   Assume A and B are nonnegative and in fixnum range.  */
+
+static EMACS_INT
+saturated_add (EMACS_INT a, EMACS_INT b)
+{
+  return min (a + b, MOST_POSITIVE_FIXNUM);
+}
 
 /* Logs.  */
 
 typedef struct Lisp_Hash_Table log_t;
 
+static Lisp_Object Qprofiler_backtrace_equal;
+static struct hash_table_test hashtest_profiler;
+
 static Lisp_Object
 make_log (int heap_size, int max_stack_depth)
 {
@@ -37,10 +45,11 @@ make_log (int heap_size, int max_stack_depth)
      a special way.  This is OK as long as the object is not exposed
      to Elisp, i.e. until it is returned by *-profiler-log, after which
      it can't be used any more.  */
-  Lisp_Object log = make_hash_table (Qequal, make_number (heap_size),
+  Lisp_Object log = make_hash_table (hashtest_profiler,
+                                    make_number (heap_size),
                                     make_float (DEFAULT_REHASH_SIZE),
                                     make_float (DEFAULT_REHASH_THRESHOLD),
-                                    Qnil, Qnil, Qnil);
+                                    Qnil);
   struct Lisp_Hash_Table *h = XHASH_TABLE (log);
 
   /* What is special about our hash-tables is that the keys are pre-filled
@@ -122,14 +131,12 @@ static void evict_lower_half (log_t *log)
       }
 }
 
-/* Record the current backtrace in LOG. BASE is a special name for
-   describing which the backtrace come from. BASE can be nil. COUNT is
-   a number how many times the profiler sees the backtrace at the
-   time.  ELAPSED is a elapsed time in millisecond that the backtrace
-   took.  */
+/* Record the current backtrace in LOG.  COUNT is the weight of this
+   current backtrace: interrupt counts for CPU, and the allocation
+   size for memory.  */
 
 static void
-record_backtrace (log_t *log, size_t count)
+record_backtrace (log_t *log, EMACS_INT count)
 {
   struct backtrace *backlist = backtrace_list;
   Lisp_Object backtrace;
@@ -162,8 +169,11 @@ record_backtrace (log_t *log, size_t count)
     EMACS_UINT hash;
     ptrdiff_t j = hash_lookup (log, backtrace, &hash);
     if (j >= 0)
-      set_hash_value_slot (log, j,
-                          make_number (count + XINT (HASH_VALUE (log, j))));
+      {
+       EMACS_INT old_val = XINT (HASH_VALUE (log, j));
+       EMACS_INT new_val = saturated_add (old_val, count);
+       set_hash_value_slot (log, j, make_number (new_val));
+      }
     else
       { /* BEWARE!  hash_put in general can allocate memory.
           But currently it only does that if log->next_free is nil.  */
@@ -192,32 +202,36 @@ record_backtrace (log_t *log, size_t count)
   }
 }
 \f
-/* Sample profiler.  */
+/* Sampling profiler.  */
 
-/* FIXME: Add support for the CPU profiler in W32.  */
-/* FIXME: the sigprof_handler suffers from race-conditions if the signal
-   is delivered to a thread other than the main Emacs thread.  */
+#ifdef PROFILER_CPU_SUPPORT
 
-#if defined SIGPROF && defined HAVE_SETITIMER
-#define PROFILER_CPU_SUPPORT
+/* The profiler timer and whether it was properly initialized, if
+   POSIX timers are available.  */
+#ifdef HAVE_ITIMERSPEC
+static timer_t profiler_timer;
+static bool profiler_timer_ok;
+#endif
 
-/* True if sampling profiler is running.  */
-static bool profiler_cpu_running;
+/* Status of sampling profiler.  */
+static enum profiler_cpu_running
+  { NOT_RUNNING, TIMER_SETTIME_RUNNING, SETITIMER_RUNNING }
+  profiler_cpu_running;
 
+/* Hash-table log of CPU profiler.  */
 static Lisp_Object cpu_log;
+
 /* Separate counter for the time spent in the GC.  */
 static EMACS_INT cpu_gc_count;
 
-/* The current sample interval in millisecond.  */
-
-static int current_sample_interval;
+/* The current sampling interval in nanoseconds.  */
+static EMACS_INT current_sampling_interval;
 
-/* Signal handler for sample profiler.  */
+/* Signal handler for sampling profiler.  */
 
 static void
-sigprof_handler_1 (int signal)
+handle_profiler_signal (int signal)
 {
-  eassert (HASH_TABLE_P (cpu_log));
   if (backtrace_list && EQ (backtrace_list->function, Qautomatic_gc))
     /* Special case the time-count inside GC because the hash-table
        code is not prepared to be used while the GC is running.
@@ -225,29 +239,107 @@ sigprof_handler_1 (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 += current_sample_interval;
+    cpu_gc_count = saturated_add (cpu_gc_count, 1);
   else
-    record_backtrace (XHASH_TABLE (cpu_log), current_sample_interval);
+    {
+      EMACS_INT count = 1;
+#ifdef HAVE_ITIMERSPEC
+      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), count);
+    }
 }
 
 static void
-sigprof_handler (int signal)
+deliver_profiler_signal (int signal)
 {
-  deliver_process_signal (signal, sigprof_handler_1);
+  deliver_process_signal (signal, handle_profiler_signal);
+}
+
+static enum profiler_cpu_running
+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 / 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 / billion,
+                             current_sampling_interval % billion);
+  emacs_sigaction_init (&action, deliver_profiler_signal);
+  sigaction (SIGPROF, &action, 0);
+
+#ifdef HAVE_ITIMERSPEC
+  if (! profiler_timer_ok)
+    {
+      /* System clocks to try, in decreasing order of desirability.  */
+      static clockid_t const system_clock[] = {
+#ifdef CLOCK_THREAD_CPUTIME_ID
+       CLOCK_THREAD_CPUTIME_ID,
+#endif
+#ifdef CLOCK_PROCESS_CPUTIME_ID
+       CLOCK_PROCESS_CPUTIME_ID,
+#endif
+#ifdef CLOCK_MONOTONIC
+       CLOCK_MONOTONIC,
+#endif
+       CLOCK_REALTIME
+      };
+      int i;
+      struct sigevent sigev;
+      sigev.sigev_value.sival_ptr = &profiler_timer;
+      sigev.sigev_signo = SIGPROF;
+      sigev.sigev_notify = SIGEV_SIGNAL;
+
+      for (i = 0; i < sizeof system_clock / sizeof *system_clock; i++)
+       if (timer_create (system_clock[i], &sigev, &profiler_timer) == 0)
+         {
+           profiler_timer_ok = 1;
+           break;
+         }
+    }
+
+  if (profiler_timer_ok)
+    {
+      struct itimerspec ispec;
+      ispec.it_value = ispec.it_interval = interval;
+      if (timer_settime (profiler_timer, 0, &ispec, 0) == 0)
+       return TIMER_SETTIME_RUNNING;
+    }
+#endif
+
+#ifdef HAVE_SETITIMER
+  timer.it_value = timer.it_interval = make_timeval (interval);
+  if (setitimer (ITIMER_PROF, &timer, 0) == 0)
+    return SETITIMER_RUNNING;
+#endif
+
+  return NOT_RUNNING;
 }
 
 DEFUN ("profiler-cpu-start", Fprofiler_cpu_start, Sprofiler_cpu_start,
        1, 1, 0,
        doc: /* Start or restart the cpu profiler.
-The cpu profiler will take call-stack samples each SAMPLE-INTERVAL (expressed in milliseconds).
+It takes call-stack samples each SAMPLING-INTERVAL nanoseconds, approximately.
 See also `profiler-log-size' and `profiler-max-stack-depth'.  */)
-  (Lisp_Object sample_interval)
+  (Lisp_Object sampling_interval)
 {
-  struct sigaction sa;
-  struct itimerval timer;
-
   if (profiler_cpu_running)
-    error ("Sample profiler is already running");
+    error ("CPU profiler is already running");
 
   if (NILP (cpu_log))
     {
@@ -256,19 +348,9 @@ See also `profiler-log-size' and `profiler-max-stack-depth'.  */)
                          profiler_max_stack_depth);
     }
 
-  current_sample_interval = XINT (sample_interval);
-
-  sa.sa_handler = sigprof_handler;
-  sa.sa_flags = SA_RESTART;
-  sigemptyset (&sa.sa_mask);
-  sigaction (SIGPROF, &sa, 0);
-
-  timer.it_interval.tv_sec = 0;
-  timer.it_interval.tv_usec = current_sample_interval * 1000;
-  timer.it_value = timer.it_interval;
-  setitimer (ITIMER_PROF, &timer, 0);
-
-  profiler_cpu_running = true;
+  profiler_cpu_running = setup_cpu_timer (sampling_interval);
+  if (! profiler_cpu_running)
+    error ("Invalid sampling interval");
 
   return Qt;
 }
@@ -279,12 +361,34 @@ DEFUN ("profiler-cpu-stop", Fprofiler_cpu_stop, Sprofiler_cpu_stop,
 Return non-nil if the profiler was running.  */)
   (void)
 {
-  if (!profiler_cpu_running)
-    return Qnil;
-  profiler_cpu_running = false;
+  switch (profiler_cpu_running)
+    {
+    case NOT_RUNNING:
+      return Qnil;
 
-  setitimer (ITIMER_PROF, 0, 0);
+#ifdef HAVE_ITIMERSPEC
+    case TIMER_SETTIME_RUNNING:
+      {
+       struct itimerspec disable;
+       memset (&disable, 0, sizeof disable);
+       timer_settime (profiler_timer, 0, &disable, 0);
+      }
+      break;
+#endif
 
+#ifdef HAVE_SETITIMER
+    case SETITIMER_RUNNING:
+      {
+       struct itimerval disable;
+       memset (&disable, 0, sizeof disable);
+       setitimer (ITIMER_PROF, &disable, 0);
+      }
+      break;
+#endif
+    }
+
+  signal (SIGPROF, SIG_IGN);
+  profiler_cpu_running = NOT_RUNNING;
   return Qt;
 }
 
@@ -307,7 +411,7 @@ Before returning, a new log is allocated for future samples.  */)
   (void)
 {
   Lisp_Object result = cpu_log;
-  /* Here we're making the log visible to Elisp , so it's not safe any
+  /* Here we're making the log visible to Elisp, so it's not safe any
      more for our use afterwards since we can't rely on its special
      pre-allocated keys anymore.  So we have to allocate a new one.  */
   cpu_log = (profiler_cpu_running
@@ -319,7 +423,7 @@ Before returning, a new log is allocated for future samples.  */)
   cpu_gc_count = 0;
   return result;
 }
-#endif /* not defined PROFILER_CPU_SUPPORT */
+#endif /* PROFILER_CPU_SUPPORT */
 \f
 /* Memory profiler.  */
 
@@ -399,7 +503,67 @@ void
 malloc_probe (size_t size)
 {
   eassert (HASH_TABLE_P (memory_log));
-  record_backtrace (XHASH_TABLE (memory_log), size);
+  record_backtrace (XHASH_TABLE (memory_log), min (size, MOST_POSITIVE_FIXNUM));
+}
+
+DEFUN ("function-equal", Ffunction_equal, Sfunction_equal, 2, 2, 0,
+       doc: /* Return non-nil if F1 and F2 come from the same source.
+Used to determine if different closures are just different instances of
+the same lambda expression, or are really unrelated function.  */)
+     (Lisp_Object f1, Lisp_Object f2)
+{
+  bool res;
+  if (EQ (f1, f2))
+    res = true;
+  else if (COMPILEDP (f1) && COMPILEDP (f2))
+    res = EQ (AREF (f1, COMPILED_BYTECODE), AREF (f2, COMPILED_BYTECODE));
+  else if (CONSP (f1) && CONSP (f2) && CONSP (XCDR (f1)) && CONSP (XCDR (f2))
+          && EQ (Qclosure, XCAR (f1))
+          && EQ (Qclosure, XCAR (f2)))
+    res = EQ (XCDR (XCDR (f1)), XCDR (XCDR (f2)));
+  else
+    res = false;
+  return res ? Qt : Qnil;
+}
+
+static bool
+cmpfn_profiler (struct hash_table_test *t,
+               Lisp_Object bt1, Lisp_Object bt2)
+{
+  if (VECTORP (bt1) && VECTORP (bt2))
+    {
+      ptrdiff_t i, l = ASIZE (bt1);
+      if (l != ASIZE (bt2))
+       return false;
+      for (i = 0; i < l; i++)
+       if (NILP (Ffunction_equal (AREF (bt1, i), AREF (bt2, i))))
+         return false;
+      return true;
+    }
+  else
+    return EQ (bt1, bt2);
+}
+
+static EMACS_UINT
+hashfn_profiler (struct hash_table_test *ht, Lisp_Object bt)
+{
+  if (VECTORP (bt))
+    {
+      EMACS_UINT hash = 0;
+      ptrdiff_t i, l = ASIZE (bt);
+      for (i = 0; i < l; i++)
+       {
+         Lisp_Object f = AREF (bt, i);
+         EMACS_UINT hash1
+           = (COMPILEDP (f) ? XHASH (AREF (f, COMPILED_BYTECODE))
+              : (CONSP (f) && CONSP (XCDR (f)) && EQ (Qclosure, XCAR (f)))
+              ? XHASH (XCDR (XCDR (f))) : XHASH (f));
+         hash = sxhash_combine (hash, hash1);
+       }
+      return (hash & INTMASK);
+    }
+  else
+    return XHASH (bt);
 }
 
 void
@@ -414,8 +578,18 @@ If the log gets full, some of the least-seen call-stacks will be evicted
 to make room for new entries.  */);
   profiler_log_size = 10000;
 
+  DEFSYM (Qprofiler_backtrace_equal, "profiler-backtrace-equal");
+  {
+    struct hash_table_test test
+      = { Qprofiler_backtrace_equal, Qnil, Qnil,
+         cmpfn_profiler, hashfn_profiler };
+    hashtest_profiler = test;
+  }
+
+  defsubr (&Sfunction_equal);
+
 #ifdef PROFILER_CPU_SUPPORT
-  profiler_cpu_running = false;
+  profiler_cpu_running = NOT_RUNNING;
   cpu_log = Qnil;
   staticpro (&cpu_log);
   defsubr (&Sprofiler_cpu_start);