Commit d89460ed authored by Paul Eggert's avatar Paul Eggert

Profiler improvements: more-accurate timers, overflow checks.

* profiler.c: Don't include stdio.h, limits.h, sys/time.h,
signal.h, setjmp.h.  Include systime.h instead.
(saturated_add): New function.
(record_backtrace, current_sample_interval): Use EMACS_INT, not size_t.
(record_backtrace, handle_profiler_signal): Saturate on fixnum overflow.
(profiler_timer, profiler_timer_ok) [HAVE_TIMER_SETTIME]:
New static vars.
(enum profiler_cpu_running): New enumn.
(profiler_cpu_running): Now of that enum type, not bool.
All uses changed to store the new value.
(handle_profiler_signal): Rename from sigprof_handler_1,
for consistency with other handlers.  Do not check whether
cpu_log is a hash-table if garbage collecting, since it
doesn't matter in that case.
(deliver_profiler_signal): Rename from sigprof_handler,
for consistency with other handlers.
(setup_cpu_timer): New function, with much of what used to be in
Fprofiler_cpu_start.  Check for out-of-range argument.
Prefer timer_settime if available, and prefer
thread cputime clocks, then process cputime clocks, then
monotonic clocks, to the old realtime clock.  Use make_timeval
to round more-correctly when falling back to setitimer.
(Fprofiler_cpu_start): Use it.
(Fprofiler_cpu_stop): Prefer timer_settime if available.
Don't assume that passing NULL as the 2nd argument of setitimer
is the same as passing a pointer to all-zero storage.
Ignore SIGPROF afterwards.
(malloc_probe): Saturate at MOST_POSITIVE_FIXNUM.
* sysdep.c (emacs_sigaction_init): Also mask out SIGPROF in
non-fatal signal handlers.  Ignore SIGPROF on startup.
* syssignal.h (PROFILER_CPU_SUPPORT): Define this macro here, not
in profiler.c, since sysdep.c now uses it.
parent 65788e2e
2012-09-30 Paul Eggert <eggert@cs.ucla.edu>
Profiler improvements: more-accurate timers, overflow checks.
* profiler.c: Don't include stdio.h, limits.h, sys/time.h,
signal.h, setjmp.h. Include systime.h instead.
(saturated_add): New function.
(record_backtrace, current_sample_interval): Use EMACS_INT, not size_t.
(record_backtrace, handle_profiler_signal): Saturate on fixnum overflow.
(profiler_timer, profiler_timer_ok) [HAVE_TIMER_SETTIME]:
New static vars.
(enum profiler_cpu_running): New enumn.
(profiler_cpu_running): Now of that enum type, not bool.
All uses changed to store the new value.
(handle_profiler_signal): Rename from sigprof_handler_1,
for consistency with other handlers. Do not check whether
cpu_log is a hash-table if garbage collecting, since it
doesn't matter in that case.
(deliver_profiler_signal): Rename from sigprof_handler,
for consistency with other handlers.
(setup_cpu_timer): New function, with much of what used to be in
Fprofiler_cpu_start. Check for out-of-range argument.
Prefer timer_settime if available, and prefer
thread cputime clocks, then process cputime clocks, then
monotonic clocks, to the old realtime clock. Use make_timeval
to round more-correctly when falling back to setitimer.
(Fprofiler_cpu_start): Use it.
(Fprofiler_cpu_stop): Prefer timer_settime if available.
Don't assume that passing NULL as the 2nd argument of setitimer
is the same as passing a pointer to all-zero storage.
Ignore SIGPROF afterwards.
(malloc_probe): Saturate at MOST_POSITIVE_FIXNUM.
* sysdep.c (emacs_sigaction_init): Also mask out SIGPROF in
non-fatal signal handlers. Ignore SIGPROF on startup.
* syssignal.h (PROFILER_CPU_SUPPORT): Define this macro here, not
in profiler.c, since sysdep.c now uses it.
* sysdep.c (handle_fatal_signal): Bump backtrace size to 40.
Suggested by Eli Zaretskii in
<http://lists.gnu.org/archive/html/emacs-devel/2012-09/msg00796.html>.
......
......@@ -18,13 +18,18 @@ 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. */
......@@ -122,14 +127,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: milliseconds for CPU counts, and the allocation
size for memory logs. */
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 +165,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. */
......@@ -195,29 +201,35 @@ record_backtrace (log_t *log, size_t count)
/* Sample 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. */
#if defined SIGPROF && defined HAVE_SETITIMER
#define PROFILER_CPU_SUPPORT
#ifdef PROFILER_CPU_SUPPORT
/* The profiler timer and whether it was properly initialized, if
POSIX timers are available. */
#ifdef HAVE_TIMER_SETTIME
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 sample interval in milliseconds. */
static EMACS_INT current_sample_interval;
/* Signal handler for sample 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,27 +237,90 @@ 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, current_sample_interval);
else
record_backtrace (XHASH_TABLE (cpu_log), current_sample_interval);
{
eassert (HASH_TABLE_P (cpu_log));
record_backtrace (XHASH_TABLE (cpu_log), current_sample_interval);
}
}
static void
sigprof_handler (int signal)
deliver_profiler_signal (int signal)
{
deliver_process_signal (signal, handle_profiler_signal);
}
static enum profiler_cpu_running
setup_cpu_timer (Lisp_Object sample_interval)
{
deliver_process_signal (signal, sigprof_handler_1);
struct sigaction action;
struct itimerval timer;
struct timespec interval;
if (! RANGED_INTEGERP (1, sample_interval,
(TYPE_MAXIMUM (time_t) < EMACS_INT_MAX / 1000
? (EMACS_INT) TYPE_MAXIMUM (time_t) * 1000 + 999
: EMACS_INT_MAX)))
return NOT_RUNNING;
current_sample_interval = XINT (sample_interval);
interval = make_emacs_time (current_sample_interval / 1000,
current_sample_interval % 1000 * 1000000);
emacs_sigaction_init (&action, deliver_profiler_signal);
sigaction (SIGPROF, &action, 0);
#ifdef HAVE_TIMER_SETTIME
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;
timer_settime (profiler_timer, 0, &ispec, 0);
return TIMER_SETTIME_RUNNING;
}
#endif
timer.it_value = timer.it_interval = make_timeval (interval);
setitimer (ITIMER_PROF, &timer, 0);
return SETITIMER_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 SAMPLE-INTERVAL milliseconds.
See also `profiler-log-size' and `profiler-max-stack-depth'. */)
(Lisp_Object sample_interval)
{
struct sigaction sa;
struct itimerval timer;
if (profiler_cpu_running)
error ("Sample profiler is already running");
......@@ -256,19 +331,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 (sample_interval);
if (! profiler_cpu_running)
error ("Invalid sample interval");
return Qt;
}
......@@ -279,12 +344,30 @@ 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;
case TIMER_SETTIME_RUNNING:
{
struct itimerspec disable;
memset (&disable, 0, sizeof disable);
timer_settime (profiler_timer, 0, &disable, 0);
}
break;
setitimer (ITIMER_PROF, 0, 0);
case SETITIMER_RUNNING:
{
struct itimerval disable;
memset (&disable, 0, sizeof disable);
setitimer (ITIMER_PROF, &disable, 0);
}
break;
}
signal (SIGPROF, SIG_IGN);
profiler_cpu_running = NOT_RUNNING;
return Qt;
}
......@@ -307,7 +390,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 +402,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 */
/* Memory profiler. */
......@@ -399,7 +482,7 @@ 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));
}
void
......@@ -415,7 +498,7 @@ to make room for new entries. */);
profiler_log_size = 10000;
#ifdef PROFILER_CPU_SUPPORT
profiler_cpu_running = false;
profiler_cpu_running = NOT_RUNNING;
cpu_log = Qnil;
staticpro (&cpu_log);
defsubr (&Sprofiler_cpu_start);
......
......@@ -1447,6 +1447,9 @@ emacs_sigaction_init (struct sigaction *action, signal_handler_t handler)
#ifdef SIGDANGER
sigaddset (&action->sa_mask, SIGDANGER);
#endif
#ifdef PROFILER_CPU_SUPPORT
sigaddset (&action->sa_mask, SIGPROF);
#endif
#ifdef SIGWINCH
sigaddset (&action->sa_mask, SIGWINCH);
#endif
......@@ -1837,7 +1840,7 @@ init_signals (bool dumping)
#endif
sigaction (SIGTERM, &process_fatal_action, 0);
#ifdef SIGPROF
sigaction (SIGPROF, &process_fatal_action, 0);
signal (SIGPROF, SIG_IGN);
#endif
#ifdef SIGVTALRM
sigaction (SIGVTALRM, &process_fatal_action, 0);
......
......@@ -29,6 +29,10 @@ extern void init_signals (bool);
#define FORWARD_SIGNAL_TO_MAIN_THREAD
#endif
#if defined SIGPROF && (defined HAVE_TIMER_SETTIME || defined HAVE_SETITIMER)
# define PROFILER_CPU_SUPPORT
#endif
extern sigset_t empty_mask;
typedef void (*signal_handler_t) (int);
......
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment