Skip to content

Commit

Permalink
Merge branch 'maint'
Browse files Browse the repository at this point in the history
* maint:
  Bug fixes of statistics(wall_clock) and statistics(runtime)

Conflicts:
	erts/emulator/beam/erl_time_sup.c
  • Loading branch information
rickard-green committed Sep 5, 2017
2 parents 7636e28 + 67f6114 commit 4c27e0d
Show file tree
Hide file tree
Showing 8 changed files with 151 additions and 54 deletions.
2 changes: 2 additions & 0 deletions erts/configure.in
Expand Up @@ -1570,6 +1570,8 @@ AC_CHECK_HEADER(sys/resource.h,
[#include <sys/resource.h>])],
[],[])

AC_CHECK_FUNCS([getrusage])

dnl Check if we have kernel poll support
have_kernel_poll=no
AC_CHECK_HEADER(sys/event.h, have_kernel_poll=kqueue)
Expand Down
5 changes: 3 additions & 2 deletions erts/emulator/beam/erl_bif_info.c
Expand Up @@ -48,6 +48,7 @@
#include "erl_map.h"
#define ERTS_PTAB_WANT_DEBUG_FUNCS__
#include "erl_ptab.h"
#include "erl_time.h"
#ifdef HIPE
#include "hipe_arch.h"
#endif
Expand Down Expand Up @@ -3467,7 +3468,7 @@ BIF_RETTYPE statistics_1(BIF_ALIST_1)
ErtsMonotonicTime u1, u2;
Eterm b1, b2;
Uint hsz;
elapsed_time_both(&u1, NULL, &u2, NULL);
erts_runtime_elapsed_both(&u1, NULL, &u2, NULL);
hsz = 3; /* 2-tuple */
(void) erts_bld_monotonic_time(NULL, &hsz, u1);
(void) erts_bld_monotonic_time(NULL, &hsz, u2);
Expand All @@ -3483,7 +3484,7 @@ BIF_RETTYPE statistics_1(BIF_ALIST_1)
ErtsMonotonicTime w1, w2;
Eterm b1, b2;
Uint hsz;
wall_clock_elapsed_time_both(&w1, &w2);
erts_wall_clock_elapsed_both(&w1, &w2);
hsz = 3; /* 2-tuple */
(void) erts_bld_monotonic_time(NULL, &hsz, w1);
(void) erts_bld_monotonic_time(NULL, &hsz, w2);
Expand Down
2 changes: 1 addition & 1 deletion erts/emulator/beam/erl_lock_check.c
Expand Up @@ -160,9 +160,9 @@ static erts_lc_lock_order_t erts_lock_order[] = {
{ "xports_list_pre_alloc_lock", "address" },
{ "inet_buffer_stack_lock", NULL },
{ "system_block", NULL },
{ "timeofday", NULL },
{ "get_time", NULL },
{ "get_corrected_time", NULL },
{ "runtime", NULL },
{ "breakpoints", NULL },
{ "pix_lock", "address" },
{ "run_queues_lists", NULL },
Expand Down
7 changes: 7 additions & 0 deletions erts/emulator/beam/erl_time.h
Expand Up @@ -130,6 +130,13 @@ Eterm erts_get_monotonic_end_time(struct process *c_p);
Eterm erts_monotonic_time_source(struct process*c_p);
Eterm erts_system_time_source(struct process*c_p);

void erts_runtime_elapsed_both(ErtsMonotonicTime *ms_user,
ErtsMonotonicTime *ms_sys,
ErtsMonotonicTime *ms_user_diff,
ErtsMonotonicTime *ms_sys_diff);
void erts_wall_clock_elapsed_both(ErtsMonotonicTime *total,
ErtsMonotonicTime *diff);

#ifdef SYS_CLOCK_RESOLUTION
#define ERTS_CLKTCK_RESOLUTION ((ErtsMonotonicTime) (SYS_CLOCK_RESOLUTION*1000))
#else
Expand Down
147 changes: 103 additions & 44 deletions erts/emulator/beam/erl_time_sup.c
Expand Up @@ -36,12 +36,29 @@
#include "erl_driver.h"
#include "erl_nif.h"

static erts_mtx_t erts_timeofday_mtx;
static erts_mtx_t erts_get_time_mtx;

static SysTimes t_start; /* Used in elapsed_time_both */
static ErtsMonotonicTime prev_wall_clock_elapsed; /* Used in wall_clock_elapsed_time_both */
static ErtsMonotonicTime previous_now; /* Used in get_now */
/* used by erts_runtime_elapsed_both */
typedef struct {
erts_mtx_t mtx;
ErtsMonotonicTime user;
ErtsMonotonicTime sys;
} ErtsRunTimePrevData;

static union {
ErtsRunTimePrevData data;
char align__[ERTS_ALC_CACHE_LINE_ALIGN_SIZE(sizeof(ErtsRunTimePrevData))];
} runtime_prev erts_align_attribute(ERTS_CACHE_LINE_SIZE);

static union {
erts_atomic64_t time;
char align__[ERTS_ALC_CACHE_LINE_ALIGN_SIZE(sizeof(erts_atomic64_t))];
} wall_clock_prev erts_align_attribute(ERTS_CACHE_LINE_SIZE);

static union {
erts_atomic64_t time;
char align__[ERTS_ALC_CACHE_LINE_ALIGN_SIZE(sizeof(erts_atomic64_t))];
} now_prev erts_align_attribute(ERTS_CACHE_LINE_SIZE);

static ErtsMonitor *time_offset_monitors = NULL;
static Uint no_time_offset_monitors = 0;
Expand Down Expand Up @@ -954,10 +971,12 @@ erts_init_time_sup(int time_correction, ErtsTimeWarpMode time_warp_mode)

ASSERT(ERTS_MONOTONIC_TIME_MIN < ERTS_MONOTONIC_TIME_MAX);

erts_mtx_init(&erts_timeofday_mtx, "timeofday", NIL,
ERTS_LOCK_FLAGS_PROPERTY_STATIC | ERTS_LOCK_FLAGS_CATEGORY_GENERIC);
erts_mtx_init(&erts_get_time_mtx, "get_time", NIL,
ERTS_LOCK_FLAGS_PROPERTY_STATIC | ERTS_LOCK_FLAGS_CATEGORY_GENERIC);
erts_mtx_init(&runtime_prev.data.mtx, "runtime", NIL,
ERTS_LOCK_FLAGS_PROPERTY_STATIC | ERTS_LOCK_FLAGS_CATEGORY_GENERIC);
runtime_prev.data.user = 0;
runtime_prev.data.sys = 0;

time_sup.r.o.correction = time_correction;
time_sup.r.o.warp_mode = time_warp_mode;
Expand Down Expand Up @@ -1157,9 +1176,13 @@ erts_init_time_sup(int time_correction, ErtsTimeWarpMode time_warp_mode)
time_sup.f.c.last_not_corrected_time = 0;
}

prev_wall_clock_elapsed = 0;
erts_atomic64_init_nob(&wall_clock_prev.time,
(erts_aint64_t) 0);

erts_atomic64_init_nob(
&now_prev.time,
(erts_aint64_t) ERTS_MONOTONIC_TO_USEC(get_time_offset()));

previous_now = ERTS_MONOTONIC_TO_USEC(get_time_offset());

#ifdef DEBUG
time_sup_initialized = 1;
Expand Down Expand Up @@ -1289,61 +1312,92 @@ erts_finalize_time_offset(void)
/* info functions */

void
elapsed_time_both(ErtsMonotonicTime *ms_user, ErtsMonotonicTime *ms_sys,
ErtsMonotonicTime *ms_user_diff, ErtsMonotonicTime *ms_sys_diff)
erts_runtime_elapsed_both(ErtsMonotonicTime *ms_user, ErtsMonotonicTime *ms_sys,
ErtsMonotonicTime *ms_user_diff, ErtsMonotonicTime *ms_sys_diff)
{
ErtsMonotonicTime prev_total_user, prev_total_sys;
ErtsMonotonicTime total_user, total_sys;
ErtsMonotonicTime prev_user, prev_sys, user, sys;

#ifdef HAVE_GETRUSAGE

struct rusage now;

if (getrusage(RUSAGE_SELF, &now) != 0) {
erts_exit(ERTS_ABORT_EXIT, "getrusage(RUSAGE_SELF, _) failed: %d\n", errno);
return;
}

user = (ErtsMonotonicTime) now.ru_utime.tv_sec;
user *= (ErtsMonotonicTime) 1000000;
user += (ErtsMonotonicTime) now.ru_utime.tv_usec;
user /= (ErtsMonotonicTime) 1000;

sys = (ErtsMonotonicTime) now.ru_stime.tv_sec;
sys *= (ErtsMonotonicTime) 1000000;
sys += (ErtsMonotonicTime) now.ru_stime.tv_usec;
sys /= (ErtsMonotonicTime) 1000;

#else

SysTimes now;

sys_times(&now);
total_user = (ErtsMonotonicTime) ((now.tms_utime * 1000) / SYS_CLK_TCK);
total_sys = (ErtsMonotonicTime) ((now.tms_stime * 1000) / SYS_CLK_TCK);
user = (ErtsMonotonicTime) now.tms_utime;
user *= (ErtsMonotonicTime) 1000;
user /= (ErtsMonotonicTime) SYS_CLK_TCK;

if (ms_user != NULL)
*ms_user = total_user;
if (ms_sys != NULL)
*ms_sys = total_sys;
sys = (ErtsMonotonicTime) now.tms_stime;
sys *= (ErtsMonotonicTime) 1000;
sys /= (ErtsMonotonicTime) SYS_CLK_TCK;

#endif

if (ms_user)
*ms_user = user;
if (ms_sys)
*ms_sys = sys;

if (ms_user_diff || ms_sys_diff) {
erts_mtx_lock(&erts_timeofday_mtx);

prev_total_user = (ErtsMonotonicTime) ((t_start.tms_utime * 1000) / SYS_CLK_TCK);
prev_total_sys = (ErtsMonotonicTime) ((t_start.tms_stime * 1000) / SYS_CLK_TCK);
t_start = now;

erts_mtx_unlock(&erts_timeofday_mtx);

erts_mtx_lock(&runtime_prev.data.mtx);

if (ms_user_diff != NULL)
*ms_user_diff = total_user - prev_total_user;

if (ms_sys_diff != NULL)
*ms_sys_diff = total_sys - prev_total_sys;
prev_user = runtime_prev.data.user;
prev_sys = runtime_prev.data.sys;
runtime_prev.data.user = user;
runtime_prev.data.sys = sys;

erts_mtx_unlock(&runtime_prev.data.mtx);

if (ms_user_diff)
*ms_user_diff = user - prev_user;
if (ms_sys_diff)
*ms_sys_diff = sys - prev_sys;
}
}


/* wall clock routines */

void
wall_clock_elapsed_time_both(ErtsMonotonicTime *ms_total, ErtsMonotonicTime *ms_diff)
erts_wall_clock_elapsed_both(ErtsMonotonicTime *ms_total, ErtsMonotonicTime *ms_diff)
{
ErtsMonotonicTime now, elapsed;

now = time_sup.r.o.get_time();
update_last_mtime(NULL, now);

elapsed = ERTS_MONOTONIC_TO_MSEC(now);
elapsed -= ERTS_MONOTONIC_TO_MSEC(ERTS_MONOTONIC_BEGIN);

*ms_total = elapsed;

if (ms_diff) {
erts_mtx_lock(&erts_timeofday_mtx);
ErtsMonotonicTime prev;

*ms_diff = elapsed - prev_wall_clock_elapsed;
prev_wall_clock_elapsed = elapsed;
prev = ((ErtsMonotonicTime)
erts_atomic64_xchg_mb(&wall_clock_prev.time,
(erts_aint64_t) elapsed));

erts_mtx_unlock(&erts_timeofday_mtx);
*ms_diff = elapsed - prev;
}
}

Expand Down Expand Up @@ -1722,22 +1776,27 @@ univ_to_local(Sint *year, Sint *month, Sint *day,
void
get_now(Uint* megasec, Uint* sec, Uint* microsec)
{
ErtsMonotonicTime now_megasec, now_sec, now, mtime, time_offset;
ErtsMonotonicTime now_megasec, now_sec, now, prev, mtime, time_offset;

mtime = time_sup.r.o.get_time();
time_offset = get_time_offset();
update_last_mtime(NULL, mtime);
now = ERTS_MONOTONIC_TO_USEC(mtime + time_offset);

erts_mtx_lock(&erts_timeofday_mtx);

/* Make sure now time is later than last time */
if (now <= previous_now)
now = previous_now + 1;

previous_now = now;

erts_mtx_unlock(&erts_timeofday_mtx);
prev = erts_atomic64_read_nob(&now_prev.time);
while (1) {
ErtsMonotonicTime act;
if (now <= prev)
now = prev + 1;
act = ((ErtsMonotonicTime)
erts_atomic64_cmpxchg_mb(&now_prev.time,
(erts_aint64_t) now,
(erts_aint64_t) prev));
if (act == prev)
break;
prev = act;
}

now_megasec = now / ERTS_MONOTONIC_TIME_TERA;
now_sec = now / ERTS_MONOTONIC_TIME_MEGA;
Expand Down
4 changes: 0 additions & 4 deletions erts/emulator/beam/sys.h
Expand Up @@ -757,10 +757,6 @@ Preload* sys_preloaded(void);
unsigned char* sys_preload_begin(Preload*);
void sys_preload_end(Preload*);
int sys_get_key(int);
void elapsed_time_both(ErtsMonotonicTime *ms_user, ErtsMonotonicTime *ms_sys,
ErtsMonotonicTime *ms_user_diff, ErtsMonotonicTime *ms_sys_diff);
void wall_clock_elapsed_time_both(ErtsMonotonicTime *ms_total,
ErtsMonotonicTime *ms_diff);
void get_time(int *hour, int *minute, int *second);
void get_date(int *year, int *month, int *day);
void get_localtime(int *year, int *month, int *day,
Expand Down
4 changes: 4 additions & 0 deletions erts/emulator/sys/unix/erl_unix_sys.h
Expand Up @@ -86,6 +86,10 @@

#include <sys/times.h>

#ifdef HAVE_SYS_RESOURCE_H
# include <sys/resource.h>
#endif

#ifdef HAVE_IEEEFP_H
#include <ieeefp.h>
#endif
Expand Down
34 changes: 31 additions & 3 deletions erts/emulator/test/statistics_SUITE.erl
Expand Up @@ -23,8 +23,10 @@
%% Tests the statistics/1 bif.

-export([all/0, suite/0, groups/0,
wall_clock_sanity/1,
wall_clock_zero_diff/1, wall_clock_update/1,
runtime_zero_diff/1,
runtime_sanity/1,
runtime_zero_diff/1,
runtime_update/1, runtime_diff/1,
run_queue_one/1,
scheduler_wall_time/1,
Expand Down Expand Up @@ -54,11 +56,23 @@ all() ->

groups() ->
[{wall_clock, [],
[wall_clock_zero_diff, wall_clock_update]},
[wall_clock_sanity, wall_clock_zero_diff, wall_clock_update]},
{runtime, [],
[runtime_zero_diff, runtime_update, runtime_diff]},
[runtime_sanity, runtime_zero_diff, runtime_update, runtime_diff]},
{run_queue, [], [run_queue_one]}].

wall_clock_sanity(Config) when is_list(Config) ->
erlang:yield(),
{WallClock, _} = statistics(wall_clock),
MT = erlang:monotonic_time(),
Time = erlang:convert_time_unit(MT - erlang:system_info(start_time),
native, millisecond),
io:format("Time=~p WallClock=~p~n",
[Time, WallClock]),
true = WallClock =< Time,
true = Time - 100 =< WallClock,
ok.

%%% Testing statistics(wall_clock).

%% Tests that the 'Wall clock since last call' element of the result
Expand Down Expand Up @@ -102,6 +116,20 @@ wall_clock_update1(0) ->

%%% Test statistics(runtime).

runtime_sanity(Config) when is_list(Config) ->
case erlang:system_info(logical_processors_available) of
unknown ->
{skipped, "Don't know available logical processors"};
LP when is_integer(LP) ->
erlang:yield(),
{RunTime, _} = statistics(runtime),
MT = erlang:monotonic_time(),
Time = erlang:convert_time_unit(MT - erlang:system_info(start_time),
native, millisecond),
io:format("Time=~p RunTime=~p~n",
[Time, RunTime]),
true = RunTime =< Time*LP
end.

%% Tests that the difference between the times returned from two consectuitive
%% calls to statistics(runtime) is zero.
Expand Down

0 comments on commit 4c27e0d

Please sign in to comment.