diff options
Diffstat (limited to 'erts/emulator')
31 files changed, 1658 insertions, 828 deletions
diff --git a/erts/emulator/beam/atom.names b/erts/emulator/beam/atom.names index fb3368eae2..07f6492948 100644 --- a/erts/emulator/beam/atom.names +++ b/erts/emulator/beam/atom.names @@ -370,6 +370,7 @@ atom monitor atom monitor_nodes atom monitors atom monotonic +atom monotonic_timestamp atom more atom multi_scheduling atom multiline @@ -559,6 +560,7 @@ atom static atom stderr_to_stdout atom stop atom stream +atom strict_monotonic_timestamp atom sunrm atom suspend atom suspended diff --git a/erts/emulator/beam/beam_bp.c b/erts/emulator/beam/beam_bp.c index 016d0aaa32..9860968687 100644 --- a/erts/emulator/beam/beam_bp.c +++ b/erts/emulator/beam/beam_bp.c @@ -75,6 +75,16 @@ extern BeamInstr beam_return_time_trace[1]; /* OpCode(i_return_time_trace) */ erts_smp_atomic32_t erts_active_bp_index; erts_smp_atomic32_t erts_staging_bp_index; +/* + * Inlined helpers + */ + +static ERTS_INLINE ErtsMonotonicTime +get_mtime(Process *c_p) +{ + return erts_get_monotonic_time(ERTS_PROC_GET_SCHDATA(c_p)); +} + /* ************************************************************************* ** Local prototypes */ @@ -97,9 +107,6 @@ static int clear_function_break(BeamInstr *pc, Uint break_flags); static BpDataTime* get_time_break(BeamInstr *pc); static GenericBpData* check_break(BeamInstr *pc, Uint break_flags); -static void bp_time_diff(bp_data_time_item_t *item, - process_breakpoint_time_t *pbt, - Uint ms, Uint s, Uint us); static void bp_meta_unref(BpMetaPid* bmp); static void bp_count_unref(BpCount* bcp); @@ -110,13 +117,8 @@ static void uninstall_breakpoint(BeamInstr* pc); /* bp_hash */ #define BP_TIME_ADD(pi0, pi1) \ do { \ - Uint r; \ (pi0)->count += (pi1)->count; \ - (pi0)->s_time += (pi1)->s_time; \ - (pi0)->us_time += (pi1)->us_time; \ - r = (pi0)->us_time / 1000000; \ - (pi0)->s_time += r; \ - (pi0)->us_time = (pi0)->us_time % 1000000; \ + (pi0)->time += (pi1)->time; \ } while(0) static void bp_hash_init(bp_time_hash_t *hash, Uint n); @@ -948,7 +950,7 @@ do_call_trace(Process* c_p, BeamInstr* I, Eterm* reg, void erts_trace_time_call(Process* c_p, BeamInstr* I, BpDataTime* bdt) { - Uint ms,s,us; + ErtsMonotonicTime time; process_breakpoint_time_t *pbt = NULL; bp_data_time_item_t sitem, *item = NULL; bp_time_hash_t *h = NULL; @@ -961,7 +963,7 @@ erts_trace_time_call(Process* c_p, BeamInstr* I, BpDataTime* bdt) * from the process psd */ pbt = ERTS_PROC_GET_CALL_TIME(c_p); - get_sys_now(&ms, &s, &us); + time = get_mtime(c_p); /* get pbt * timestamp = t0 @@ -976,7 +978,7 @@ erts_trace_time_call(Process* c_p, BeamInstr* I, BpDataTime* bdt) } else { ASSERT(pbt->pc); /* add time to previous code */ - bp_time_diff(&sitem, pbt, ms, s, us); + sitem.time = time - pbt->time; sitem.pid = c_p->common.id; sitem.count = 0; @@ -1002,8 +1004,7 @@ erts_trace_time_call(Process* c_p, BeamInstr* I, BpDataTime* bdt) /* Add count to this code */ sitem.pid = c_p->common.id; sitem.count = 1; - sitem.s_time = 0; - sitem.us_time = 0; + sitem.time = 0; /* this breakpoint */ ASSERT(bdt); @@ -1020,15 +1021,13 @@ erts_trace_time_call(Process* c_p, BeamInstr* I, BpDataTime* bdt) } pbt->pc = I; - pbt->ms = ms; - pbt->s = s; - pbt->us = us; + pbt->time = time; } void erts_trace_time_return(Process *p, BeamInstr *pc) { - Uint ms,s,us; + ErtsMonotonicTime time; process_breakpoint_time_t *pbt = NULL; bp_data_time_item_t sitem, *item = NULL; bp_time_hash_t *h = NULL; @@ -1041,7 +1040,7 @@ erts_trace_time_return(Process *p, BeamInstr *pc) * from the process psd */ pbt = ERTS_PROC_GET_CALL_TIME(p); - get_sys_now(&ms,&s,&us); + time = get_mtime(p); /* get pbt * lookup bdt from code @@ -1057,7 +1056,7 @@ erts_trace_time_return(Process *p, BeamInstr *pc) */ ASSERT(pbt->pc); - bp_time_diff(&sitem, pbt, ms, s, us); + sitem.time = time - pbt->time; sitem.pid = p->common.id; sitem.count = 0; @@ -1080,9 +1079,7 @@ erts_trace_time_return(Process *p, BeamInstr *pc) } pbt->pc = pc; - pbt->ms = ms; - pbt->s = s; - pbt->us = us; + pbt->time = time; } } @@ -1183,10 +1180,14 @@ int erts_is_time_break(Process *p, BeamInstr *pc, Eterm *retval) { for(ix = 0; ix < hash.n; ix++) { item = &(hash.item[ix]); if (item->pid != NIL) { + ErtsMonotonicTime sec, usec; + usec = ERTS_MONOTONIC_TO_USEC(item->time); + sec = usec / 1000000; + usec = usec - sec*1000000; t = TUPLE4(hp, item->pid, make_small(item->count), - make_small(item->s_time), - make_small(item->us_time)); + make_small((Uint) sec), + make_small((Uint) usec)); hp += 5; *retval = CONS(hp, t, *retval); hp += 2; } @@ -1266,8 +1267,7 @@ static void bp_hash_rehash(bp_time_hash_t *hash, Uint n) { } item[hval].pid = hash->item[ix].pid; item[hval].count = hash->item[ix].count; - item[hval].s_time = hash->item[ix].s_time; - item[hval].us_time = hash->item[ix].us_time; + item[hval].time = hash->item[ix].time; } } @@ -1315,8 +1315,7 @@ static ERTS_INLINE bp_data_time_item_t * bp_hash_put(bp_time_hash_t *hash, bp_da item = &(hash->item[hval]); item->pid = sitem->pid; - item->s_time = sitem->s_time; - item->us_time = sitem->us_time; + item->time = sitem->time; item->count = sitem->count; hash->used++; @@ -1330,41 +1329,7 @@ static void bp_hash_delete(bp_time_hash_t *hash) { hash->item = NULL; } -static void bp_time_diff(bp_data_time_item_t *item, /* out */ - process_breakpoint_time_t *pbt, /* in */ - Uint ms, Uint s, Uint us) { - int ds,dus; -#ifdef DEBUG - int dms; - - - dms = ms - pbt->ms; -#endif - ds = s - pbt->s; - dus = us - pbt->us; - - /* get_sys_now may return zero difftime, - * this is ok. - */ - -#ifdef DEBUG - ASSERT(dms >= 0 || ds >= 0 || dus >= 0); -#endif - - if (dus < 0) { - dus += 1000000; - ds -= 1; - } - if (ds < 0) { - ds += 1000000; - } - - item->s_time = ds; - item->us_time = dus; -} - void erts_schedule_time_break(Process *p, Uint schedule) { - Uint ms, s, us; process_breakpoint_time_t *pbt = NULL; bp_data_time_item_t sitem, *item = NULL; bp_time_hash_t *h = NULL; @@ -1387,8 +1352,7 @@ void erts_schedule_time_break(Process *p, Uint schedule) { pbdt = get_time_break(pbt->pc); if (pbdt) { - get_sys_now(&ms,&s,&us); - bp_time_diff(&sitem, pbt, ms, s, us); + sitem.time = get_mtime(p) - pbt->time; sitem.pid = p->common.id; sitem.count = 0; @@ -1410,10 +1374,7 @@ void erts_schedule_time_break(Process *p, Uint schedule) { * timestamp it and remove the previous * timestamp in the psd. */ - get_sys_now(&ms,&s,&us); - pbt->ms = ms; - pbt->s = s; - pbt->us = us; + pbt->time = get_mtime(p); break; default : ASSERT(0); diff --git a/erts/emulator/beam/beam_bp.h b/erts/emulator/beam/beam_bp.h index 97d0539ac7..2b89d6fc71 100644 --- a/erts/emulator/beam/beam_bp.h +++ b/erts/emulator/beam/beam_bp.h @@ -29,8 +29,7 @@ typedef struct { Eterm pid; Sint count; - Uint s_time; - Uint us_time; + ErtsMonotonicTime time; } bp_data_time_item_t; typedef struct { @@ -46,9 +45,7 @@ typedef struct bp_data_time { /* Call time */ } BpDataTime; typedef struct { - Uint ms; - Uint s; - Uint us; + ErtsMonotonicTime time; BeamInstr *pc; } process_breakpoint_time_t; /* used within psd */ diff --git a/erts/emulator/beam/erl_bif_trace.c b/erts/emulator/beam/erl_bif_trace.c index 03f51132b1..08807d72c9 100644 --- a/erts/emulator/beam/erl_bif_trace.c +++ b/erts/emulator/beam/erl_bif_trace.c @@ -431,6 +431,9 @@ Uint erts_trace_flag2bit(Eterm flag) { switch (flag) { + case am_timestamp: return F_NOW_TS; + case am_strict_monotonic_timestamp: return F_STRICT_MON_TS; + case am_monotonic_timestamp: return F_MON_TS; case am_all: return TRACEE_FLAGS; case am_send: return F_TRACE_SEND; case am_receive: return F_TRACE_RECEIVE; @@ -439,7 +442,6 @@ erts_trace_flag2bit(Eterm flag) case am_set_on_first_spawn: return F_TRACE_SOS1; case am_set_on_link: return F_TRACE_SOL; case am_set_on_first_link: return F_TRACE_SOL1; - case am_timestamp: return F_TIMESTAMP; case am_running: return F_TRACE_SCHED; case am_exiting: return F_TRACE_SCHED_EXIT; case am_garbage_collection: return F_TRACE_GC; @@ -592,7 +594,7 @@ Eterm trace_3(BIF_ALIST_3) ERTS_TRACE_FLAGS(tracee_port) |= mask; else ERTS_TRACE_FLAGS(tracee_port) &= ~mask; - + if (!ERTS_TRACE_FLAGS(tracee_port)) ERTS_TRACER_PROC(tracee_port) = NIL; else if (tracer != NIL) @@ -978,7 +980,7 @@ trace_info_pid(Process* p, Eterm pid_spec, Eterm key) } if (key == am_flags) { - int num_flags = 19; /* MAXIMUM number of flags. */ + int num_flags = 21; /* MAXIMUM number of flags. */ Uint needed = 3+2*num_flags; Eterm flag_list = NIL; Eterm* limit; @@ -996,6 +998,9 @@ trace_info_pid(Process* p, Eterm pid_spec, Eterm key) #endif hp = HAlloc(p, needed); limit = hp+needed; + FLAG(F_NOW_TS, am_timestamp); + FLAG(F_STRICT_MON_TS, am_strict_monotonic_timestamp); + FLAG(F_MON_TS, am_monotonic_timestamp); FLAG(F_TRACE_SEND, am_send); FLAG(F_TRACE_RECEIVE, am_receive); FLAG(F_TRACE_SOS, am_set_on_spawn); @@ -1007,7 +1012,6 @@ trace_info_pid(Process* p, Eterm pid_spec, Eterm key) FLAG(F_TRACE_SCHED, am_running); FLAG(F_TRACE_SCHED_EXIT, am_exiting); FLAG(F_TRACE_GC, am_garbage_collection); - FLAG(F_TIMESTAMP, am_timestamp); FLAG(F_TRACE_ARITY_ONLY, am_arity); FLAG(F_TRACE_RETURN_TO, am_return_to); FLAG(F_TRACE_SILENT, am_silent); @@ -1798,7 +1802,11 @@ Eterm erts_seq_trace(Process *p, Eterm arg1, Eterm arg2, } else if (arg1 == am_print) { current_flag = SEQ_TRACE_PRINT; } else if (arg1 == am_timestamp) { - current_flag = SEQ_TRACE_TIMESTAMP; + current_flag = SEQ_TRACE_NOW_TS; + } else if (arg1 == am_strict_monotonic_timestamp) { + current_flag = SEQ_TRACE_STRICT_MON_TS; + } else if (arg1 == am_monotonic_timestamp) { + current_flag = SEQ_TRACE_MON_TS; } else current_flag = 0; @@ -1909,7 +1917,9 @@ BIF_RETTYPE erl_seq_trace_info(Process *p, Eterm item) #endif ) { if ((item == am_send) || (item == am_receive) || - (item == am_print) || (item == am_timestamp)) { + (item == am_print) || (item == am_timestamp) + || (item == am_monotonic_timestamp) + || (item == am_strict_monotonic_timestamp)) { hp = HAlloc(p,3); res = TUPLE2(hp, item, am_false); BIF_RET(res); @@ -1927,7 +1937,11 @@ BIF_RETTYPE erl_seq_trace_info(Process *p, Eterm item) } else if (item == am_print) { current_flag = SEQ_TRACE_PRINT; } else if (item == am_timestamp) { - current_flag = SEQ_TRACE_TIMESTAMP; + current_flag = SEQ_TRACE_NOW_TS; + } else if (item == am_strict_monotonic_timestamp) { + current_flag = SEQ_TRACE_STRICT_MON_TS; + } else if (item == am_monotonic_timestamp) { + current_flag = SEQ_TRACE_MON_TS; } else { current_flag = 0; } @@ -2237,6 +2251,7 @@ static Eterm system_profile_get(Process *p) { if (erts_system_profile_flags.exclusive) { res = CONS(hp, am_exclusive, res); hp += 2; } + return TUPLE2(hp, system_profile, res); } } @@ -2255,6 +2270,7 @@ BIF_RETTYPE system_profile_2(BIF_ALIST_2) int system_blocked = 0; Process *profiler_p = NULL; Port *profiler_port = NULL; + int ts; if (profiler == am_undefined || list == NIL) { prev = system_profile_get(p); @@ -2286,7 +2302,8 @@ BIF_RETTYPE system_profile_2(BIF_ALIST_2) goto error; } - for (scheduler = 0, runnable_ports = 0, runnable_procs = 0, exclusive = 0; + for (ts = ERTS_TRACE_FLG_NOW_TIMESTAMP, scheduler = 0, + runnable_ports = 0, runnable_procs = 0, exclusive = 0; is_list(list); list = CDR(list_val(list))) { @@ -2299,6 +2316,12 @@ BIF_RETTYPE system_profile_2(BIF_ALIST_2) exclusive = !0; } else if (t == am_scheduler) { scheduler = !0; + } else if (t == am_timestamp) { + ts = ERTS_TRACE_FLG_NOW_TIMESTAMP; + } else if (t == am_strict_monotonic_timestamp) { + ts = ERTS_TRACE_FLG_STRICT_MONOTONIC_TIMESTAMP; + } else if (t == am_monotonic_timestamp) { + ts = ERTS_TRACE_FLG_MONOTONIC_TIMESTAMP; } else goto error; } if (is_not_nil(list)) goto error; @@ -2311,7 +2334,7 @@ BIF_RETTYPE system_profile_2(BIF_ALIST_2) erts_system_profile_flags.runnable_ports = !!runnable_ports; erts_system_profile_flags.runnable_procs = !!runnable_procs; erts_system_profile_flags.exclusive = !!exclusive; - + erts_system_profile_ts_type = ts; erts_smp_thr_progress_unblock(); erts_smp_proc_lock(p, ERTS_PROC_LOCK_MAIN); diff --git a/erts/emulator/beam/erl_db.c b/erts/emulator/beam/erl_db.c index 878ee32b47..645f9e3c28 100644 --- a/erts/emulator/beam/erl_db.c +++ b/erts/emulator/beam/erl_db.c @@ -1376,7 +1376,6 @@ BIF_RETTYPE ets_new_2(BIF_ALIST_2) status |= DB_ORDERED_SET; status &= ~(DB_SET | DB_BAG | DB_DUPLICATE_BAG); } - /*TT*/ else if (is_tuple(val)) { Eterm *tp = tuple_val(val); if (arityval(tp[0]) == 2) { @@ -3466,10 +3465,10 @@ static void fix_table_locked(Process* p, DbTable* tb) #endif erts_refc_inc(&tb->common.ref,1); fix = tb->common.fixations; - if (fix == NULL) { - get_now(&(tb->common.megasec), - &(tb->common.sec), - &(tb->common.microsec)); + if (fix == NULL) { + tb->common.time.monotonic + = erts_get_monotonic_time(ERTS_PROC_GET_SCHDATA(p)); + tb->common.time.offset = erts_get_time_offset(); } else { for (; fix != NULL; fix = fix->next) { @@ -3731,6 +3730,7 @@ static int free_table_cont(Process *p, static Eterm table_info(Process* p, DbTable* tb, Eterm What) { Eterm ret = THE_NON_VALUE; + int use_monotonic; if (What == am_size) { ret = make_small(erts_smp_atomic_read_nob(&tb->common.nitems)); @@ -3788,7 +3788,10 @@ static Eterm table_info(Process* p, DbTable* tb, Eterm What) ret = am_true; else ret = am_false; - } else if (What == am_atom_put("safe_fixed",10)) { + } else if ((use_monotonic + = ERTS_IS_ATOM_STR("safe_fixed_monotonic_time", + What)) + || ERTS_IS_ATOM_STR("safe_fixed", What)) { #ifdef ERTS_SMP erts_smp_mtx_lock(&tb->common.fixlock); #endif @@ -3797,7 +3800,19 @@ static Eterm table_info(Process* p, DbTable* tb, Eterm What) Eterm *hp; Eterm tpl, lst; DbFixation *fix; - need = 7; + Sint64 mtime; + + need = 3; + if (use_monotonic) { + mtime = (Sint64) tb->common.time.monotonic; + mtime += ERTS_MONOTONIC_OFFSET_NATIVE; + if (!IS_SSMALL(mtime)) + need += ERTS_SINT64_HEAP_SIZE(mtime); + } + else { + mtime = 0; + need += 4; + } for (fix = tb->common.fixations; fix != NULL; fix = fix->next) { need += 5; } @@ -3809,11 +3824,18 @@ static Eterm table_info(Process* p, DbTable* tb, Eterm What) lst = CONS(hp,tpl,lst); hp += 2; } - tpl = TUPLE3(hp, - make_small(tb->common.megasec), - make_small(tb->common.sec), - make_small(tb->common.microsec)); - hp += 4; + if (use_monotonic) + tpl = (IS_SSMALL(mtime) + ? make_small(mtime) + : erts_sint64_to_big(mtime, &hp)); + else { + Uint ms, s, us; + erts_make_timestamp_value(&ms, &s, &us, + tb->common.time.monotonic, + tb->common.time.offset); + tpl = TUPLE3(hp, make_small(ms), make_small(s), make_small(us)); + hp += 4; + } ret = TUPLE2(hp, tpl, lst); } else { ret = am_false; diff --git a/erts/emulator/beam/erl_db_util.h b/erts/emulator/beam/erl_db_util.h index 1ccdc0305b..0903a40460 100644 --- a/erts/emulator/beam/erl_db_util.h +++ b/erts/emulator/beam/erl_db_util.h @@ -229,7 +229,10 @@ typedef struct db_table_common { DbTableMethod* meth; /* table methods */ erts_smp_atomic_t nitems; /* Total number of items in table */ erts_smp_atomic_t memory_size;/* Total memory size. NOTE: in bytes! */ - Uint megasec,sec,microsec; /* Last fixation time */ + struct { /* Last fixation time */ + ErtsMonotonicTime monotonic; + ErtsMonotonicTime offset; + } time; DbFixation* fixations; /* List of processes who have done safe_fixtable, "local" fixations not included. */ /* All 32-bit fields */ diff --git a/erts/emulator/beam/erl_driver.h b/erts/emulator/beam/erl_driver.h index dbb4d719c1..7ab58e336b 100644 --- a/erts/emulator/beam/erl_driver.h +++ b/erts/emulator/beam/erl_driver.h @@ -37,47 +37,6 @@ # endif #endif -#ifdef SIZEOF_CHAR -# define SIZEOF_CHAR_SAVED__ SIZEOF_CHAR -# undef SIZEOF_CHAR -#endif -#ifdef SIZEOF_SHORT -# define SIZEOF_SHORT_SAVED__ SIZEOF_SHORT -# undef SIZEOF_SHORT -#endif -#ifdef SIZEOF_INT -# define SIZEOF_INT_SAVED__ SIZEOF_INT -# undef SIZEOF_INT -#endif -#ifdef SIZEOF_LONG -# define SIZEOF_LONG_SAVED__ SIZEOF_LONG -# undef SIZEOF_LONG -#endif -#ifdef SIZEOF_LONG_LONG -# define SIZEOF_LONG_LONG_SAVED__ SIZEOF_LONG_LONG -# undef SIZEOF_LONG_LONG -#endif -#ifdef HALFWORD_HEAP_EMULATOR -# define HALFWORD_HEAP_EMULATOR_SAVED__ HALFWORD_HEAP_EMULATOR -# undef HALFWORD_HEAP_EMULATOR -#endif -#include "erl_int_sizes_config.h" -#if defined(SIZEOF_CHAR_SAVED__) && SIZEOF_CHAR_SAVED__ != SIZEOF_CHAR -# error SIZEOF_CHAR mismatch -#endif -#if defined(SIZEOF_SHORT_SAVED__) && SIZEOF_SHORT_SAVED__ != SIZEOF_SHORT -# error SIZEOF_SHORT mismatch -#endif -#if defined(SIZEOF_INT_SAVED__) && SIZEOF_INT_SAVED__ != SIZEOF_INT -# error SIZEOF_INT mismatch -#endif -#if defined(SIZEOF_LONG_SAVED__) && SIZEOF_LONG_SAVED__ != SIZEOF_LONG -# error SIZEOF_LONG mismatch -#endif -#if defined(SIZEOF_LONG_LONG_SAVED__) && SIZEOF_LONG_LONG_SAVED__ != SIZEOF_LONG_LONG -# error SIZEOF_LONG_LONG mismatch -#endif - /* This is OK to override by the NIF/driver implementor */ #if defined(HALFWORD_HEAP_EMULATOR_SAVED__) && !defined(HALFWORD_HEAP_EMULATOR) #define HALFWORD_HEAP_EMULATOR HALFWORD_HEAP_EMULATOR_SAVED__ @@ -134,7 +93,7 @@ typedef struct { #define ERL_DRV_EXTENDED_MARKER (0xfeeeeeed) #define ERL_DRV_EXTENDED_MAJOR_VERSION 3 -#define ERL_DRV_EXTENDED_MINOR_VERSION 2 +#define ERL_DRV_EXTENDED_MINOR_VERSION 3 /* * The emulator will refuse to load a driver with a major version @@ -176,28 +135,12 @@ typedef struct { /* * Integer types */ -#if defined(__WIN32__) && (SIZEOF_VOID_P == 8) -typedef unsigned __int64 ErlDrvTermData; -typedef unsigned __int64 ErlDrvUInt; -typedef signed __int64 ErlDrvSInt; -#else -typedef unsigned long ErlDrvTermData; -typedef unsigned long ErlDrvUInt; -typedef signed long ErlDrvSInt; -#endif -#if defined(__WIN32__) -typedef unsigned __int64 ErlDrvUInt64; -typedef __int64 ErlDrvSInt64; -#elif SIZEOF_LONG == 8 -typedef unsigned long ErlDrvUInt64; -typedef long ErlDrvSInt64; -#elif SIZEOF_LONG_LONG == 8 -typedef unsigned long long ErlDrvUInt64; -typedef long long ErlDrvSInt64; -#else -#error No 64-bit integer type -#endif +typedef ErlNapiUInt64 ErlDrvUInt64; +typedef ErlNapiSInt64 ErlDrvSInt64; +typedef ErlNapiUInt ErlDrvUInt; +typedef ErlNapiSInt ErlDrvSInt; +typedef ErlNapiUInt ErlDrvTermData; #if defined(__WIN32__) || defined(_WIN32) typedef ErlDrvUInt ErlDrvSizeT; @@ -250,6 +193,17 @@ typedef struct { unsigned long microsecs; } ErlDrvNowData; +typedef ErlDrvSInt64 ErlDrvTime; + +#define ERL_DRV_TIME_ERROR ((ErlDrvSInt64) ERTS_NAPI_TIME_ERROR__) + +typedef enum { + ERL_DRV_SEC = ERTS_NAPI_SEC__, + ERL_DRV_MSEC = ERTS_NAPI_MSEC__, + ERL_DRV_USEC = ERTS_NAPI_USEC__, + ERL_DRV_NSEC = ERTS_NAPI_NSEC__ +} ErlDrvTimeUnit; + /* * Error codes that can be return from driver. */ @@ -685,8 +639,16 @@ EXTERN long driver_async(ErlDrvPort ix, EXTERN int driver_lock_driver(ErlDrvPort ix); /* Get the current 'now' timestamp (analogue to erlang:now()) */ -EXTERN int driver_get_now(ErlDrvNowData *now); - +EXTERN int driver_get_now(ErlDrvNowData *now) ERL_DRV_DEPRECATED_FUNC; + +/* Erlang Monotonic Time */ +EXTERN ErlDrvTime erl_drv_monotonic_time(ErlDrvTimeUnit time_unit); +/* Time offset between Erlang Monotonic Time and Erlang System Time */ +EXTERN ErlDrvTime erl_drv_time_offset(ErlDrvTimeUnit time_unit); +/* Time unit conversion */ +EXTERN ErlDrvTime erl_drv_convert_time_unit(ErlDrvTime val, + ErlDrvTimeUnit from, + ErlDrvTimeUnit to); /* These were removed from the ANSI version, now they're back. */ diff --git a/erts/emulator/beam/erl_drv_nif.h b/erts/emulator/beam/erl_drv_nif.h index e2385f63f4..f6b946ae82 100644 --- a/erts/emulator/beam/erl_drv_nif.h +++ b/erts/emulator/beam/erl_drv_nif.h @@ -50,6 +50,90 @@ typedef enum { } ErlDrvDirtyJobFlags; #endif +#ifdef SIZEOF_CHAR +# define SIZEOF_CHAR_SAVED__ SIZEOF_CHAR +# undef SIZEOF_CHAR +#endif +#ifdef SIZEOF_SHORT +# define SIZEOF_SHORT_SAVED__ SIZEOF_SHORT +# undef SIZEOF_SHORT +#endif +#ifdef SIZEOF_INT +# define SIZEOF_INT_SAVED__ SIZEOF_INT +# undef SIZEOF_INT +#endif +#ifdef SIZEOF_LONG +# define SIZEOF_LONG_SAVED__ SIZEOF_LONG +# undef SIZEOF_LONG +#endif +#ifdef SIZEOF_LONG_LONG +# define SIZEOF_LONG_LONG_SAVED__ SIZEOF_LONG_LONG +# undef SIZEOF_LONG_LONG +#endif +#ifdef HALFWORD_HEAP_EMULATOR +# define HALFWORD_HEAP_EMULATOR_SAVED__ HALFWORD_HEAP_EMULATOR +# undef HALFWORD_HEAP_EMULATOR +#endif +#include "erl_int_sizes_config.h" +#if defined(SIZEOF_CHAR_SAVED__) && SIZEOF_CHAR_SAVED__ != SIZEOF_CHAR +# error SIZEOF_CHAR mismatch +#endif +#if defined(SIZEOF_SHORT_SAVED__) && SIZEOF_SHORT_SAVED__ != SIZEOF_SHORT +# error SIZEOF_SHORT mismatch +#endif +#if defined(SIZEOF_INT_SAVED__) && SIZEOF_INT_SAVED__ != SIZEOF_INT +# error SIZEOF_INT mismatch +#endif +#if defined(SIZEOF_LONG_SAVED__) && SIZEOF_LONG_SAVED__ != SIZEOF_LONG +# error SIZEOF_LONG mismatch +#endif +#if defined(SIZEOF_LONG_LONG_SAVED__) && SIZEOF_LONG_LONG_SAVED__ != SIZEOF_LONG_LONG +# error SIZEOF_LONG_LONG mismatch +#endif + +#if !defined(__GNUC__) && (defined(__WIN32__) || defined(_WIN32) || defined(_WIN32_)) +typedef unsigned __int64 ErlNapiUInt64; +typedef signed __int64 ErlNapiSInt64; +#define ERL_NAPI_SINT64_MAX__ 9223372036854775807i64 +#define ERL_NAPI_SINT64_MIN__ (-ERL_NAPI_SINT64_MAX__ - 1i64) +#elif SIZEOF_LONG == 8 +typedef unsigned long ErlNapiUInt64; +typedef signed long ErlNapiSInt64; +#define ERL_NAPI_SINT64_MAX__ 9223372036854775807L +#define ERL_NAPI_SINT64_MIN__ (-ERL_NAPI_SINT64_MAX__ - 1L) +#elif SIZEOF_LONG_LONG == 8 +typedef unsigned long long ErlNapiUInt64; +typedef signed long long ErlNapiSInt64; +#define ERL_NAPI_SINT64_MAX__ 9223372036854775807LL +#define ERL_NAPI_SINT64_MIN__ (-ERL_NAPI_SINT64_MAX__ - 1LL) +#else +# error No 64-bit integer type +#endif + +#if SIZEOF_VOID_P == 8 +typedef ErlNapiUInt64 ErlNapiUInt; +typedef ErlNapiSInt64 ErlNapiSInt; +#elif SIZEOF_VOID_P == 4 +# if SIZEOF_LONG == SIZEOF_VOID_P +typedef unsigned long ErlNapiUInt; +typedef signed long ErlNapiSInt; +# elif SIZEOF_INT == SIZEOF_VOID_P +typedef unsigned int ErlNapiUInt; +typedef signed int ErlNapiSInt; +# else +# error No 32-bit integer type +# endif +#else +# error Not support arch +#endif + +#define ERTS_NAPI_TIME_ERROR__ ERL_NAPI_SINT64_MIN__ + +#define ERTS_NAPI_SEC__ 0 +#define ERTS_NAPI_MSEC__ 1 +#define ERTS_NAPI_USEC__ 2 +#define ERTS_NAPI_NSEC__ 3 + #endif /* __ERL_DRV_NIF_H__ */ diff --git a/erts/emulator/beam/erl_hl_timer.c b/erts/emulator/beam/erl_hl_timer.c index 51a0d68247..fb6d249145 100644 --- a/erts/emulator/beam/erl_hl_timer.c +++ b/erts/emulator/beam/erl_hl_timer.c @@ -1055,6 +1055,8 @@ create_hl_timer(ErtsSchedulerData *esdp, erts_aint32_t refc; Uint32 roflgs; + ERTS_HLT_HDBG_CHK_SRV(srv); + check_canceled_queue(esdp, srv); ERTS_HLT_ASSERT((esdp->no & ~ERTS_TMR_ROFLG_SID_MASK) == 0); @@ -1179,8 +1181,6 @@ create_hl_timer(ErtsSchedulerData *esdp, erts_smp_atomic32_init_nob(&tmr->head.refc, refc); erts_smp_atomic32_init_nob(&tmr->state, ERTS_TMR_STATE_ACTIVE); - ERTS_HLT_HDBG_CHK_SRV(srv); - if (!srv->next_timeout || tmr->timeout < srv->next_timeout->timeout) { if (srv->next_timeout) @@ -3099,7 +3099,8 @@ tt_hdbg_func(ErtsHLTimer *tmr, void *vhdbg) & ~ERTS_HLT_PFLGS_MASK); ERTS_HLT_ASSERT(tmr == prnt); } - ERTS_HLT_ASSERT(btm_rbt_lookup(hdbg->srv->btm_tree, tmr->btm.refn) == tmr); + if (tmr->head.roflgs & ERTS_TMR_ROFLG_BIF_TMR) + ERTS_HLT_ASSERT(btm_rbt_lookup(hdbg->srv->btm_tree, tmr->btm.refn) == tmr); if (tmr->time.tree.same_time) { ErtsHdbgHLT st_hdbg; st_hdbg.srv = hdbg->srv; diff --git a/erts/emulator/beam/erl_nif.c b/erts/emulator/beam/erl_nif.c index d7a2076d85..3141b05e2b 100644 --- a/erts/emulator/beam/erl_nif.c +++ b/erts/emulator/beam/erl_nif.c @@ -1175,6 +1175,26 @@ void enif_thread_exit(void *resp) { erl_drv_thread_exit(resp); } int enif_thread_join(ErlNifTid tid, void **respp) { return erl_drv_thread_join(tid,respp); } int enif_getenv(const char *key, char *value, size_t *value_size) { return erl_drv_getenv(key, value, value_size); } +ErlNifTime enif_monotonic_time(ErlNifTimeUnit time_unit) +{ + return (ErlNifTime) erts_napi_monotonic_time((int) time_unit); +} + +ErlNifTime enif_time_offset(ErlNifTimeUnit time_unit) +{ + return (ErlNifTime) erts_napi_time_offset((int) time_unit); +} + +ErlNifTime +enif_convert_time_unit(ErlNifTime val, + ErlNifTimeUnit from, + ErlNifTimeUnit to) +{ + return (ErlNifTime) erts_napi_convert_time_unit((ErtsMonotonicTime) val, + (int) from, + (int) to); +} + int enif_fprintf(void* filep, const char* format, ...) { int ret; diff --git a/erts/emulator/beam/erl_nif.h b/erts/emulator/beam/erl_nif.h index 5e39343e9b..75070ad901 100644 --- a/erts/emulator/beam/erl_nif.h +++ b/erts/emulator/beam/erl_nif.h @@ -49,9 +49,10 @@ ** add ErlNifFunc flags ** 2.8: 18.0 add enif_has_pending_exception ** 2.9: 18.2 enif_getenv +** 2.10: Time API */ #define ERL_NIF_MAJOR_VERSION 2 -#define ERL_NIF_MINOR_VERSION 9 +#define ERL_NIF_MINOR_VERSION 10 /* * The emulator will refuse to load a nif-lib with a major version @@ -67,63 +68,36 @@ #include <stdlib.h> -#ifdef SIZEOF_CHAR -# define SIZEOF_CHAR_SAVED__ SIZEOF_CHAR -# undef SIZEOF_CHAR -#endif -#ifdef SIZEOF_SHORT -# define SIZEOF_SHORT_SAVED__ SIZEOF_SHORT -# undef SIZEOF_SHORT -#endif -#ifdef SIZEOF_INT -# define SIZEOF_INT_SAVED__ SIZEOF_INT -# undef SIZEOF_INT -#endif -#ifdef SIZEOF_LONG -# define SIZEOF_LONG_SAVED__ SIZEOF_LONG -# undef SIZEOF_LONG -#endif -#ifdef SIZEOF_LONG_LONG -# define SIZEOF_LONG_LONG_SAVED__ SIZEOF_LONG_LONG -# undef SIZEOF_LONG_LONG -#endif -#ifdef HALFWORD_HEAP_EMULATOR -# define HALFWORD_HEAP_EMULATOR_SAVED__ HALFWORD_HEAP_EMULATOR -# undef HALFWORD_HEAP_EMULATOR -#endif -#include "erl_int_sizes_config.h" - #ifdef __cplusplus extern "C" { #endif -#if (defined(__WIN32__) || defined(_WIN32) || defined(_WIN32_)) -typedef unsigned __int64 ErlNifUInt64; -typedef __int64 ErlNifSInt64; -#elif SIZEOF_LONG == 8 -typedef unsigned long ErlNifUInt64; -typedef long ErlNifSInt64; -#elif SIZEOF_LONG_LONG == 8 -typedef unsigned long long ErlNifUInt64; -typedef long long ErlNifSInt64; -#else -#error No 64-bit integer type -#endif +typedef ErlNapiUInt64 ErlNifUInt64; +typedef ErlNapiSInt64 ErlNifSInt64; +typedef ErlNapiUInt ErlNifUInt; +typedef ErlNapiSInt ErlNifSInt; #ifdef HALFWORD_HEAP_EMULATOR # define ERL_NIF_VM_VARIANT "beam.halfword" typedef unsigned int ERL_NIF_TERM; #else # define ERL_NIF_VM_VARIANT "beam.vanilla" -# if SIZEOF_LONG == SIZEOF_VOID_P -typedef unsigned long ERL_NIF_TERM; -# elif SIZEOF_LONG_LONG == SIZEOF_VOID_P -typedef unsigned long long ERL_NIF_TERM; -# endif +typedef ErlNifUInt ERL_NIF_TERM; #endif typedef ERL_NIF_TERM ERL_NIF_UINT; +typedef ErlNifSInt64 ErlNifTime; + +#define ERL_NIF_TIME_ERROR ((ErlNifSInt64) ERTS_NAPI_TIME_ERROR__) + +typedef enum { + ERL_NIF_SEC = ERTS_NAPI_SEC__, + ERL_NIF_MSEC = ERTS_NAPI_MSEC__, + ERL_NIF_USEC = ERTS_NAPI_USEC__, + ERL_NIF_NSEC = ERTS_NAPI_NSEC__ +} ErlNifTimeUnit; + struct enif_environment_t; typedef struct enif_environment_t ErlNifEnv; diff --git a/erts/emulator/beam/erl_nif_api_funcs.h b/erts/emulator/beam/erl_nif_api_funcs.h index 08b9afc6af..1448a508a2 100644 --- a/erts/emulator/beam/erl_nif_api_funcs.h +++ b/erts/emulator/beam/erl_nif_api_funcs.h @@ -160,6 +160,9 @@ ERL_NIF_API_FUNC_DECL(ERL_NIF_TERM,enif_schedule_nif,(ErlNifEnv*,const char*,int ERL_NIF_API_FUNC_DECL(int, enif_has_pending_exception, (ErlNifEnv *env, ERL_NIF_TERM* reason)); ERL_NIF_API_FUNC_DECL(ERL_NIF_TERM, enif_raise_exception, (ErlNifEnv *env, ERL_NIF_TERM reason)); ERL_NIF_API_FUNC_DECL(int,enif_getenv,(const char* key, char* value, size_t* value_size)); +ERL_NIF_API_FUNC_DECL(ErlNifTime, enif_monotonic_time, (ErlNifTimeUnit)); +ERL_NIF_API_FUNC_DECL(ErlNifTime, enif_time_offset, (ErlNifTimeUnit)); +ERL_NIF_API_FUNC_DECL(ErlNifTime, enif_convert_time_unit, (ErlNifTime, ErlNifTimeUnit, ErlNifTimeUnit)); /* ** ADD NEW ENTRIES HERE (before this comment) !!! @@ -312,6 +315,9 @@ ERL_NIF_API_FUNC_DECL(int,enif_is_on_dirty_scheduler,(ErlNifEnv*)); # define enif_has_pending_exception ERL_NIF_API_FUNC_MACRO(enif_has_pending_exception) # define enif_raise_exception ERL_NIF_API_FUNC_MACRO(enif_raise_exception) # define enif_getenv ERL_NIF_API_FUNC_MACRO(enif_getenv) +# define enif_monotonic_time ERL_NIF_API_FUNC_MACRO(enif_monotonic_time) +# define enif_time_offset ERL_NIF_API_FUNC_MACRO(enif_time_offset) +# define enif_convert_time_unit ERL_NIF_API_FUNC_MACRO(enif_convert_time_unit) /* ** ADD NEW ENTRIES HERE (before this comment) diff --git a/erts/emulator/beam/erl_process.c b/erts/emulator/beam/erl_process.c index b47aae0f74..8fd1b5c0c3 100644 --- a/erts/emulator/beam/erl_process.c +++ b/erts/emulator/beam/erl_process.c @@ -353,6 +353,7 @@ struct erts_system_monitor_flags_t erts_system_monitor_flags; /* system performance monitor */ Eterm erts_system_profile; struct erts_system_profile_flags_t erts_system_profile_flags; +int erts_system_profile_ts_type = ERTS_TRACE_FLG_NOW_TIMESTAMP; #if ERTS_MAX_PROCESSES > 0x7fffffff #error "Need to store process_count in another type" @@ -2239,6 +2240,7 @@ handle_aux_work(ErtsAuxWorkData *awdp, erts_aint32_t orig_aux_work, int waiting) erts_aint32_t aux_work = orig_aux_work; erts_aint32_t ignore = 0; + ASSERT(!awdp->esdp || !ERTS_SCHEDULER_IS_DIRTY(awdp->esdp)); #ifdef ERTS_SMP haw_thr_prgr_current_reset(awdp); #endif @@ -2972,14 +2974,13 @@ scheduler_wait(int *fcalls, ErtsSchedulerData *esdp, ErtsRunQueue *rq) ErtsMonotonicTime current_time; aux_work = erts_atomic32_read_acqb(&ssi->aux_work); - if (aux_work) { - if (!ERTS_SCHEDULER_IS_DIRTY(esdp) && !thr_prgr_active) { + if (aux_work && !ERTS_SCHEDULER_IS_DIRTY(esdp)) { + if (!thr_prgr_active) { erts_thr_progress_active(esdp, thr_prgr_active = 1); sched_wall_time_change(esdp, 1); } aux_work = handle_aux_work(&esdp->aux_work_data, aux_work, 1); - if (aux_work && !ERTS_SCHEDULER_IS_DIRTY(esdp) - && erts_thr_progress_update(esdp)) + if (aux_work && erts_thr_progress_update(esdp)) erts_thr_progress_leader_update(esdp); } @@ -3131,19 +3132,16 @@ scheduler_wait(int *fcalls, ErtsSchedulerData *esdp, ErtsRunQueue *rq) #endif aux_work = erts_atomic32_read_acqb(&ssi->aux_work); - if (aux_work) { - if (!ERTS_SCHEDULER_IS_DIRTY(esdp)) { - if (!working) - sched_wall_time_change(esdp, working = 1); + if (aux_work && !ERTS_SCHEDULER_IS_DIRTY(esdp)) { + if (!working) + sched_wall_time_change(esdp, working = 1); #ifdef ERTS_SMP - if (!thr_prgr_active) - erts_thr_progress_active(esdp, thr_prgr_active = 1); + if (!thr_prgr_active) + erts_thr_progress_active(esdp, thr_prgr_active = 1); #endif - } aux_work = handle_aux_work(&esdp->aux_work_data, aux_work, 1); #ifdef ERTS_SMP - if (!ERTS_SCHEDULER_IS_DIRTY(esdp) && aux_work && - erts_thr_progress_update(esdp)) + if (aux_work && erts_thr_progress_update(esdp)) erts_thr_progress_leader_update(esdp); #endif } @@ -6798,18 +6796,19 @@ suspend_scheduler(ErtsSchedulerData *esdp) & ERTS_RUNQ_FLGS_QMASK); aux_work = erts_atomic32_read_acqb(&ssi->aux_work); if (aux_work|qmask) { - if (!ERTS_SCHEDULER_IS_DIRTY(esdp) && !thr_prgr_active) { - erts_thr_progress_active(esdp, thr_prgr_active = 1); - sched_wall_time_change(esdp, 1); + if (!ERTS_SCHEDULER_IS_DIRTY(esdp)) { + if (!thr_prgr_active) { + erts_thr_progress_active(esdp, thr_prgr_active = 1); + sched_wall_time_change(esdp, 1); + } + if (aux_work) + aux_work = handle_aux_work(&esdp->aux_work_data, + aux_work, + 1); + + if (aux_work && erts_thr_progress_update(esdp)) + erts_thr_progress_leader_update(esdp); } - if (aux_work) - aux_work = handle_aux_work(&esdp->aux_work_data, - aux_work, - 1); - - if (!ERTS_SCHEDULER_IS_DIRTY(esdp) && - (aux_work && erts_thr_progress_update(esdp))) - erts_thr_progress_leader_update(esdp); if (qmask) { #ifdef ERTS_DIRTY_SCHEDULERS if (ERTS_SCHEDULER_IS_DIRTY(esdp)) { @@ -7026,17 +7025,18 @@ suspend_scheduler(ErtsSchedulerData *esdp) & ERTS_RUNQ_FLGS_QMASK); aux_work = erts_atomic32_read_acqb(&ssi->aux_work); if (aux_work|qmask) { - if (!ERTS_SCHEDULER_IS_DIRTY(esdp) && !thr_prgr_active) { - erts_thr_progress_active(esdp, thr_prgr_active = 1); - sched_wall_time_change(esdp, 1); + if (!ERTS_SCHEDULER_IS_DIRTY(esdp)) { + if (!thr_prgr_active) { + erts_thr_progress_active(esdp, thr_prgr_active = 1); + sched_wall_time_change(esdp, 1); + } + if (aux_work) + aux_work = handle_aux_work(&esdp->aux_work_data, + aux_work, + 1); + if (aux_work && erts_thr_progress_update(esdp)) + erts_thr_progress_leader_update(esdp); } - if (aux_work) - aux_work = handle_aux_work(&esdp->aux_work_data, - aux_work, - 1); - if (!ERTS_SCHEDULER_IS_DIRTY(esdp) && aux_work && - erts_thr_progress_update(esdp)) - erts_thr_progress_leader_update(esdp); if (qmask) { erts_smp_runq_lock(esdp->run_queue); evacuate_run_queue(esdp->run_queue, &sbp); @@ -9427,10 +9427,9 @@ Process *schedule(Process *p, int calls) suspend_scheduler(esdp); #endif - { + if (!ERTS_SCHEDULER_IS_DIRTY(esdp)) { erts_aint32_t aux_work; - int leader_update = ERTS_SCHEDULER_IS_DIRTY(esdp) ? 0 - : erts_thr_progress_update(esdp); + int leader_update = erts_thr_progress_update(esdp); aux_work = erts_atomic32_read_acqb(&esdp->ssi->aux_work); if (aux_work | leader_update | ERTS_SCHED_FAIR) { erts_smp_runq_unlock(rq); @@ -9443,8 +9442,7 @@ Process *schedule(Process *p, int calls) erts_smp_runq_lock(rq); } - ERTS_SMP_LC_ASSERT(ERTS_SCHEDULER_IS_DIRTY(esdp) - || !erts_thr_progress_is_blocking()); + ERTS_SMP_LC_ASSERT(!erts_thr_progress_is_blocking()); } ERTS_SMP_LC_ASSERT(erts_smp_lc_runq_is_locked(rq)); diff --git a/erts/emulator/beam/erl_process.h b/erts/emulator/beam/erl_process.h index fd7d4183f4..799e49005c 100644 --- a/erts/emulator/beam/erl_process.h +++ b/erts/emulator/beam/erl_process.h @@ -60,6 +60,9 @@ typedef struct process Process; #include "erl_mseg.h" #include "erl_async.h" #include "erl_gc.h" +#define ERTS_ONLY_INCLUDE_TRACE_FLAGS +#include "erl_trace.h" +#undef ERTS_ONLY_INCLUDE_TRACE_FLAGS #ifdef HIPE #include "hipe_process.h" @@ -615,7 +618,7 @@ typedef enum { typedef union { struct { ErtsDirtySchedulerType type: 1; - unsigned num: 31; + Uint num: sizeof(Uint)*8 - 1; } s; Uint no; } ErtsDirtySchedId; @@ -1292,6 +1295,7 @@ struct erts_system_profile_flags_t { unsigned int exclusive : 1; }; extern struct erts_system_profile_flags_t erts_system_profile_flags; +extern int erts_system_profile_ts_type; /* process flags */ #define F_HIBERNATE_SCHED (1 << 0) /* Schedule out after hibernate op */ @@ -1307,61 +1311,90 @@ extern struct erts_system_profile_flags_t erts_system_profile_flags; #define F_FORCE_GC (1 << 10) /* Force gc at process in-scheduling */ #define F_DISABLE_GC (1 << 11) /* Disable GC */ +#define ERTS_TRACE_FLAGS_TS_TYPE_SHIFT 0 + +#define F_TRACE_FLAG(N) (1 << (ERTS_TRACE_TS_TYPE_BITS + (N))) + /* process trace_flags */ -#define F_SENSITIVE (1 << 0) -#define F_TRACE_SEND (1 << 1) -#define F_TRACE_RECEIVE (1 << 2) -#define F_TRACE_SOS (1 << 3) /* Set on spawn */ -#define F_TRACE_SOS1 (1 << 4) /* Set on first spawn */ -#define F_TRACE_SOL (1 << 5) /* Set on link */ -#define F_TRACE_SOL1 (1 << 6) /* Set on first link */ -#define F_TRACE_CALLS (1 << 7) -#define F_TIMESTAMP (1 << 8) -#define F_TRACE_PROCS (1 << 9) -#define F_TRACE_FIRST_CHILD (1 << 10) -#define F_TRACE_SCHED (1 << 11) -#define F_TRACE_GC (1 << 12) -#define F_TRACE_ARITY_ONLY (1 << 13) -#define F_TRACE_RETURN_TO (1 << 14) /* Return_to trace when breakpoint tracing */ -#define F_TRACE_SILENT (1 << 15) /* No call trace msg suppress */ -#define F_TRACER (1 << 16) /* May be (has been) tracer */ -#define F_EXCEPTION_TRACE (1 << 17) /* May have exception trace on stack */ + +#define F_NOW_TS (ERTS_TRACE_FLG_NOW_TIMESTAMP \ + << ERTS_TRACE_FLAGS_TS_TYPE_SHIFT) +#define F_STRICT_MON_TS (ERTS_TRACE_FLG_STRICT_MONOTONIC_TIMESTAMP \ + << ERTS_TRACE_FLAGS_TS_TYPE_SHIFT) +#define F_MON_TS (ERTS_TRACE_FLG_MONOTONIC_TIMESTAMP \ + << ERTS_TRACE_FLAGS_TS_TYPE_SHIFT) +#define F_SENSITIVE F_TRACE_FLAG(0) +#define F_TRACE_SEND F_TRACE_FLAG(1) +#define F_TRACE_RECEIVE F_TRACE_FLAG(2) +#define F_TRACE_SOS F_TRACE_FLAG(3) /* Set on spawn */ +#define F_TRACE_SOS1 F_TRACE_FLAG(4) /* Set on first spawn */ +#define F_TRACE_SOL F_TRACE_FLAG(5) /* Set on link */ +#define F_TRACE_SOL1 F_TRACE_FLAG(6) /* Set on first link */ +#define F_TRACE_CALLS F_TRACE_FLAG(7) +#define F_TRACE_PROCS F_TRACE_FLAG(8) +#define F_TRACE_FIRST_CHILD F_TRACE_FLAG(9) +#define F_TRACE_SCHED F_TRACE_FLAG(10) +#define F_TRACE_GC F_TRACE_FLAG(11) +#define F_TRACE_ARITY_ONLY F_TRACE_FLAG(12) +#define F_TRACE_RETURN_TO F_TRACE_FLAG(13) /* Return_to trace when breakpoint tracing */ +#define F_TRACE_SILENT F_TRACE_FLAG(14) /* No call trace msg suppress */ +#define F_TRACER F_TRACE_FLAG(15) /* May be (has been) tracer */ +#define F_EXCEPTION_TRACE F_TRACE_FLAG(16) /* May have exception trace on stack */ /* port trace flags, currently the same as process trace flags */ -#define F_TRACE_SCHED_PORTS (1 << 18) /* Trace of port scheduling */ -#define F_TRACE_SCHED_PROCS (1 << 19) /* With virtual scheduling */ -#define F_TRACE_PORTS (1 << 20) /* Ports equivalent to F_TRACE_PROCS */ -#define F_TRACE_SCHED_NO (1 << 21) /* Trace with scheduler id */ -#define F_TRACE_SCHED_EXIT (1 << 22) +#define F_TRACE_SCHED_PORTS F_TRACE_FLAG(17) /* Trace of port scheduling */ +#define F_TRACE_SCHED_PROCS F_TRACE_FLAG(18) /* With virtual scheduling */ +#define F_TRACE_PORTS F_TRACE_FLAG(19) /* Ports equivalent to F_TRACE_PROCS */ +#define F_TRACE_SCHED_NO F_TRACE_FLAG(20) /* Trace with scheduler id */ +#define F_TRACE_SCHED_EXIT F_TRACE_FLAG(21) -#define F_NUM_FLAGS 23 +#define F_NUM_FLAGS (ERTS_TRACE_TS_TYPE_BITS + 22) #ifdef DEBUG # define F_INITIAL_TRACE_FLAGS (5 << F_NUM_FLAGS) #else # define F_INITIAL_TRACE_FLAGS 0 #endif +/* F_TIMESTAMP_MASK is a bit-field of all all timestamp types */ +#define F_TIMESTAMP_MASK \ + (ERTS_TRACE_TS_TYPE_MASK << ERTS_TRACE_FLAGS_TS_TYPE_SHIFT) + #define TRACEE_FLAGS ( F_TRACE_PROCS | F_TRACE_CALLS \ | F_TRACE_SOS | F_TRACE_SOS1| F_TRACE_RECEIVE \ | F_TRACE_SOL | F_TRACE_SOL1 | F_TRACE_SEND \ - | F_TRACE_SCHED | F_TIMESTAMP | F_TRACE_GC \ + | F_TRACE_SCHED | F_TIMESTAMP_MASK | F_TRACE_GC \ | F_TRACE_ARITY_ONLY | F_TRACE_RETURN_TO \ | F_TRACE_SILENT | F_TRACE_SCHED_PROCS | F_TRACE_PORTS \ | F_TRACE_SCHED_PORTS | F_TRACE_SCHED_NO \ | F_TRACE_SCHED_EXIT) #define ERTS_TRACEE_MODIFIER_FLAGS \ - (F_TRACE_SILENT | F_TIMESTAMP | F_TRACE_SCHED_NO) + (F_TRACE_SILENT | F_TIMESTAMP_MASK | F_TRACE_SCHED_NO) #define ERTS_PORT_TRACEE_FLAGS \ (ERTS_TRACEE_MODIFIER_FLAGS | F_TRACE_PORTS | F_TRACE_SCHED_PORTS) #define ERTS_PROC_TRACEE_FLAGS \ ((TRACEE_FLAGS & ~ERTS_PORT_TRACEE_FLAGS) | ERTS_TRACEE_MODIFIER_FLAGS) +#define SEQ_TRACE_FLAG(N) (1 << (ERTS_TRACE_TS_TYPE_BITS + (N))) + /* Sequential trace flags */ + +/* SEQ_TRACE_TIMESTAMP_MASK is a bit-field */ +#define SEQ_TRACE_TIMESTAMP_MASK \ + (ERTS_TRACE_TS_TYPE_MASK << ERTS_SEQ_TRACE_FLAGS_TS_TYPE_SHIFT) + #define SEQ_TRACE_SEND (1 << 0) #define SEQ_TRACE_RECEIVE (1 << 1) #define SEQ_TRACE_PRINT (1 << 2) -#define SEQ_TRACE_TIMESTAMP (1 << 3) + +#define ERTS_SEQ_TRACE_FLAGS_TS_TYPE_SHIFT 3 + +#define SEQ_TRACE_NOW_TS (ERTS_TRACE_FLG_NOW_TIMESTAMP \ + << ERTS_SEQ_TRACE_FLAGS_TS_TYPE_SHIFT) +#define SEQ_TRACE_STRICT_MON_TS (ERTS_TRACE_FLG_STRICT_MONOTONIC_TIMESTAMP \ + << ERTS_SEQ_TRACE_FLAGS_TS_TYPE_SHIFT) +#define SEQ_TRACE_MON_TS (ERTS_TRACE_FLG_MONOTONIC_TIMESTAMP \ + << ERTS_SEQ_TRACE_FLAGS_TS_TYPE_SHIFT) #ifdef USE_VM_PROBES #define DT_UTAG_PERMANENT (1 << 0) diff --git a/erts/emulator/beam/erl_time.h b/erts/emulator/beam/erl_time.h index 43e543e035..93a0d556bf 100644 --- a/erts/emulator/beam/erl_time.h +++ b/erts/emulator/beam/erl_time.h @@ -133,6 +133,10 @@ typedef struct { extern ErtsTimeSupData erts_time_sup__; +ErtsMonotonicTime erts_napi_monotonic_time(int time_unit); +ErtsMonotonicTime erts_napi_time_offset(int time_unit); +ErtsMonotonicTime erts_napi_convert_time_unit(ErtsMonotonicTime val, int from, int to); + ERTS_GLB_INLINE Uint64 erts_time_unit_conversion(Uint64 value, Uint32 from_time_unit, diff --git a/erts/emulator/beam/erl_time_sup.c b/erts/emulator/beam/erl_time_sup.c index 7327e0b48c..5f12c7809a 100644 --- a/erts/emulator/beam/erl_time_sup.c +++ b/erts/emulator/beam/erl_time_sup.c @@ -33,6 +33,8 @@ #include "global.h" #define ERTS_WANT_TIMER_WHEEL_API #include "erl_time.h" +#include "erl_driver.h" +#include "erl_nif.h" static erts_smp_mtx_t erts_timeofday_mtx; static erts_smp_mtx_t erts_get_time_mtx; @@ -57,6 +59,7 @@ static int time_sup_initialized = 0; #define ERTS_MONOTONIC_TIME_TERA \ (ERTS_MONOTONIC_TIME_GIGA*ERTS_MONOTONIC_TIME_KILO) +static void init_time_napi(void); static void schedule_send_time_offset_changed_notifications(ErtsMonotonicTime new_offset); @@ -948,6 +951,8 @@ erts_init_time_sup(int time_correction, ErtsTimeWarpMode time_warp_mode) ErtsMonotonicTime abs_native_offset, native_offset; #endif + init_time_napi(); + erts_hl_timer_init(); ASSERT(ERTS_MONOTONIC_TIME_MIN < ERTS_MONOTONIC_TIME_MAX); @@ -1747,6 +1752,39 @@ erts_get_monotonic_time(ErtsSchedulerData *esdp) return mtime; } +ErtsMonotonicTime +erts_get_time_offset(void) +{ + return get_time_offset(); +} + +static ERTS_INLINE void +make_timestamp_value(Uint* megasec, Uint* sec, Uint* microsec, + ErtsMonotonicTime mtime, ErtsMonotonicTime offset) +{ + ErtsMonotonicTime stime, as; + Uint ms; + + stime = ERTS_MONOTONIC_TO_USEC(mtime + offset); + + as = stime / ERTS_MONOTONIC_TIME_MEGA; + *megasec = ms = (Uint) (stime / ERTS_MONOTONIC_TIME_TERA); + *sec = (Uint) (as - (((ErtsMonotonicTime) ms) + * ERTS_MONOTONIC_TIME_MEGA)); + *microsec = (Uint) (stime - as*ERTS_MONOTONIC_TIME_MEGA); + + ASSERT(((ErtsMonotonicTime) ms)*ERTS_MONOTONIC_TIME_TERA + + ((ErtsMonotonicTime) *sec)*ERTS_MONOTONIC_TIME_MEGA + + *microsec == stime); +} + +void +erts_make_timestamp_value(Uint* megasec, Uint* sec, Uint* microsec, + ErtsMonotonicTime mtime, ErtsMonotonicTime offset) +{ + make_timestamp_value(megasec, sec, microsec, mtime, offset); +} + void get_sys_now(Uint* megasec, Uint* sec, Uint* microsec) { @@ -2164,6 +2202,146 @@ time_unit_conversion(Process *c_p, Eterm term, ErtsMonotonicTime val, ErtsMonoto return ret; } + +/* + * Time Native API (drivers and NIFs) + */ + +#define ERTS_NAPI_TIME_ERROR ((ErtsMonotonicTime) ERTS_NAPI_TIME_ERROR__) + +static void +init_time_napi(void) +{ + /* Verify that time native api constants are as expected... */ + + ASSERT(sizeof(ErtsMonotonicTime) == sizeof(ErlDrvTime)); + ASSERT(ERL_DRV_TIME_ERROR == (ErlDrvTime) ERTS_NAPI_TIME_ERROR); + ASSERT(ERL_DRV_TIME_ERROR < (ErlDrvTime) 0); + ASSERT(ERTS_NAPI_SEC__ == (int) ERL_DRV_SEC); + ASSERT(ERTS_NAPI_MSEC__ == (int) ERL_DRV_MSEC); + ASSERT(ERTS_NAPI_USEC__ == (int) ERL_DRV_USEC); + ASSERT(ERTS_NAPI_NSEC__ == (int) ERL_DRV_NSEC); + + ASSERT(sizeof(ErtsMonotonicTime) == sizeof(ErlNifTime)); + ASSERT(ERL_NIF_TIME_ERROR == (ErlNifTime) ERTS_NAPI_TIME_ERROR); + ASSERT(ERL_NIF_TIME_ERROR < (ErlNifTime) 0); + ASSERT(ERTS_NAPI_SEC__ == (int) ERL_NIF_SEC); + ASSERT(ERTS_NAPI_MSEC__ == (int) ERL_NIF_MSEC); + ASSERT(ERTS_NAPI_USEC__ == (int) ERL_NIF_USEC); + ASSERT(ERTS_NAPI_NSEC__ == (int) ERL_NIF_NSEC); +} + +ErtsMonotonicTime +erts_napi_monotonic_time(int time_unit) +{ + ErtsSchedulerData *esdp; + ErtsMonotonicTime mtime; + + /* At least for now only allow schedulers to do this... */ + esdp = erts_get_scheduler_data(); + if (!esdp) + return ERTS_NAPI_TIME_ERROR; + + mtime = time_sup.r.o.get_time(); + update_last_mtime(esdp, mtime); + + switch (time_unit) { + case ERTS_NAPI_SEC__: + mtime = ERTS_MONOTONIC_TO_SEC(mtime); + mtime += ERTS_MONOTONIC_OFFSET_SEC; + break; + case ERTS_NAPI_MSEC__: + mtime = ERTS_MONOTONIC_TO_MSEC(mtime); + mtime += ERTS_MONOTONIC_OFFSET_MSEC; + break; + case ERTS_NAPI_USEC__: + mtime = ERTS_MONOTONIC_TO_USEC(mtime); + mtime += ERTS_MONOTONIC_OFFSET_USEC; + break; + case ERTS_NAPI_NSEC__: + mtime = ERTS_MONOTONIC_TO_NSEC(mtime); + mtime += ERTS_MONOTONIC_OFFSET_NSEC; + break; + default: + return ERTS_NAPI_TIME_ERROR; + } + + return mtime; +} + +ErtsMonotonicTime +erts_napi_time_offset(int time_unit) +{ + ErtsSchedulerData *esdp; + ErtsSystemTime offs; + + /* At least for now only allow schedulers to do this... */ + esdp = erts_get_scheduler_data(); + if (!esdp) + return ERTS_NAPI_TIME_ERROR; + + offs = get_time_offset(); + switch (time_unit) { + case ERTS_NAPI_SEC__: + offs = ERTS_MONOTONIC_TO_SEC(offs); + offs -= ERTS_MONOTONIC_OFFSET_SEC; + break; + case ERTS_NAPI_MSEC__: + offs = ERTS_MONOTONIC_TO_MSEC(offs); + offs -= ERTS_MONOTONIC_OFFSET_MSEC; + break; + case ERTS_NAPI_USEC__: + offs = ERTS_MONOTONIC_TO_USEC(offs); + offs -= ERTS_MONOTONIC_OFFSET_USEC; + break; + case ERTS_NAPI_NSEC__: + offs = ERTS_MONOTONIC_TO_NSEC(offs); + offs -= ERTS_MONOTONIC_OFFSET_NSEC; + break; + default: + return ERTS_NAPI_TIME_ERROR; + } + return offs; +} + +ErtsMonotonicTime +erts_napi_convert_time_unit(ErtsMonotonicTime val, int from, int to) +{ + ErtsMonotonicTime ffreq, tfreq, denom; + /* + * Convertion between time units using floor function. + * + * Note that this needs to work also for negative + * values. Ordinary integer division on a negative + * value will give ceiling... + */ + + switch ((int) from) { + case ERTS_NAPI_SEC__: ffreq = 1; break; + case ERTS_NAPI_MSEC__: ffreq = 1000; break; + case ERTS_NAPI_USEC__: ffreq = 1000*1000; break; + case ERTS_NAPI_NSEC__: ffreq = 1000*1000*1000; break; + default: return ERTS_NAPI_TIME_ERROR; + } + + switch ((int) to) { + case ERTS_NAPI_SEC__: tfreq = 1; break; + case ERTS_NAPI_MSEC__: tfreq = 1000; break; + case ERTS_NAPI_USEC__: tfreq = 1000*1000; break; + case ERTS_NAPI_NSEC__: tfreq = 1000*1000*1000; break; + default: return ERTS_NAPI_TIME_ERROR; + } + + if (tfreq >= ffreq) + return val * (tfreq / ffreq); + + denom = ffreq / tfreq; + if (val >= 0) + return val / denom; + + return (val - (denom - 1)) / denom; +} + /* Built in functions */ BIF_RETTYPE monotonic_time_0(BIF_ALIST_0) @@ -2220,22 +2398,14 @@ BIF_RETTYPE time_offset_1(BIF_ALIST_1) BIF_RETTYPE timestamp_0(BIF_ALIST_0) { Eterm *hp, res; - ErtsMonotonicTime stime, mtime, all_sec, offset; + ErtsMonotonicTime mtime, offset; Uint mega_sec, sec, micro_sec; mtime = time_sup.r.o.get_time(); offset = get_time_offset(); update_last_mtime(ERTS_PROC_GET_SCHDATA(BIF_P), mtime); - stime = ERTS_MONOTONIC_TO_USEC(mtime + offset); - all_sec = stime / ERTS_MONOTONIC_TIME_MEGA; - mega_sec = (Uint) (stime / ERTS_MONOTONIC_TIME_TERA); - sec = (Uint) (all_sec - (((ErtsMonotonicTime) mega_sec) - * ERTS_MONOTONIC_TIME_MEGA)); - micro_sec = (Uint) (stime - all_sec*ERTS_MONOTONIC_TIME_MEGA); - - ASSERT(((ErtsMonotonicTime) mega_sec)*ERTS_MONOTONIC_TIME_TERA - + ((ErtsMonotonicTime) sec)*ERTS_MONOTONIC_TIME_MEGA - + micro_sec == stime); + + make_timestamp_value(&mega_sec, &sec, µ_sec, mtime, offset); /* * Mega seconds is the only value that potentially diff --git a/erts/emulator/beam/erl_trace.c b/erts/emulator/beam/erl_trace.c index e1b03a057f..2243639099 100644 --- a/erts/emulator/beam/erl_trace.c +++ b/erts/emulator/beam/erl_trace.c @@ -38,6 +38,7 @@ #include "erl_binary.h" #include "erl_bits.h" #include "erl_thr_progress.h" +#include "erl_bif_unique.h" #if 0 #define DEBUG_PRINTOUTS @@ -77,6 +78,263 @@ enum ErtsSysMsgType { SYS_MSG_TYPE_SYSPROF }; +#define ERTS_TRACE_TS_NOW_MAX_SIZE \ + 4 +#define ERTS_TRACE_TS_MONOTONIC_MAX_SIZE \ + ERTS_MAX_SINT64_HEAP_SIZE +#define ERTS_TRACE_TS_STRICT_MONOTONIC_MAX_SIZE \ + (3 + ERTS_MAX_SINT64_HEAP_SIZE \ + + ERTS_MAX_UINT64_HEAP_SIZE) + +#define ERTS_TRACE_PATCH_TS_MAX_SIZE \ + (1 + ((ERTS_TRACE_TS_NOW_MAX_SIZE \ + > ERTS_TRACE_TS_MONOTONIC_MAX_SIZE) \ + ? ((ERTS_TRACE_TS_NOW_MAX_SIZE \ + > ERTS_TRACE_TS_STRICT_MONOTONIC_MAX_SIZE) \ + ? ERTS_TRACE_TS_NOW_MAX_SIZE \ + : ERTS_TRACE_TS_STRICT_MONOTONIC_MAX_SIZE) \ + : ((ERTS_TRACE_TS_MONOTONIC_MAX_SIZE \ + > ERTS_TRACE_TS_STRICT_MONOTONIC_MAX_SIZE) \ + ? ERTS_TRACE_TS_MONOTONIC_MAX_SIZE \ + : ERTS_TRACE_TS_STRICT_MONOTONIC_MAX_SIZE))) + +#define TFLGS_TS_TYPE(p) ERTS_TFLGS2TSTYPE(ERTS_TRACE_FLAGS((p))) + +/* + * FUTURE CHANGES: + * + * The timestamp functionality has intentionally been + * split in two parts for future use even though it + * is not used like this today. take_timestamp() takes + * the timestamp and calculate heap need for it (which + * is not constant). write_timestamp() writes the + * timestamp to the allocated heap. That is, one typically + * want to take the timestamp before allocating the heap + * and then write it to the heap. + * + * The trace output functionality now use patch_ts_size(), + * write_ts(), and patch_ts(). write_ts() both takes the + * timestamp and writes it. Since we don't know the + * heap need when allocating the heap area we need to + * over allocate (maximum size from patch_ts_size()) and + * then potentially (often) shrink the heap area after the + * timestamp has been written. The only reason it is + * currently done this way is because we do not want to + * make major changes of the trace behavior in a patch. + * This is planned to be changed in next major release. + */ + +typedef struct { + int ts_type_flag; + union { + struct { + Uint ms; + Uint s; + Uint us; + } now; + struct { + ErtsMonotonicTime time; + Sint64 raw_unique; + } monotonic; + } u; +} ErtsTraceTimeStamp; + +static ERTS_INLINE Uint +take_timestamp(ErtsTraceTimeStamp *tsp, int ts_type) +{ + int ts_type_flag = ts_type & -ts_type; /* least significant flag */ + + ASSERT(ts_type_flag == ERTS_TRACE_FLG_NOW_TIMESTAMP + || ts_type_flag == ERTS_TRACE_FLG_MONOTONIC_TIMESTAMP + || ts_type_flag == ERTS_TRACE_FLG_STRICT_MONOTONIC_TIMESTAMP + || ts_type_flag == 0); + + tsp->ts_type_flag = ts_type_flag; + switch (ts_type_flag) { + case 0: + return (Uint) 0; + case ERTS_TRACE_FLG_NOW_TIMESTAMP: +#ifdef HAVE_ERTS_NOW_CPU + if (erts_cpu_timestamp) + erts_get_now_cpu(&tsp->u.now.ms, &tsp->u.now.s, &tsp->u.now.us); + else +#endif + get_now(&tsp->u.now.ms, &tsp->u.now.s, &tsp->u.now.us); + return (Uint) 4; + case ERTS_TRACE_FLG_MONOTONIC_TIMESTAMP: + case ERTS_TRACE_FLG_STRICT_MONOTONIC_TIMESTAMP: { + Uint hsz = 0; + ErtsMonotonicTime mtime = erts_get_monotonic_time(NULL); + mtime += ERTS_MONOTONIC_OFFSET_NATIVE; + hsz = (IS_SSMALL(mtime) ? + (Uint) 0 + : ERTS_SINT64_HEAP_SIZE((Sint64) mtime)); + tsp->u.monotonic.time = mtime; + if (ts_type_flag == ERTS_TRACE_FLG_STRICT_MONOTONIC_TIMESTAMP) { + Sint64 raw_unique; + hsz += 3; /* 2-tuple */ + raw_unique = erts_raw_get_unique_monotonic_integer(); + tsp->u.monotonic.raw_unique = raw_unique; + hsz += erts_raw_unique_monotonic_integer_heap_size(raw_unique); + } + return hsz; + } + default: + ERTS_INTERNAL_ERROR("invalid timestamp type"); + return 0; + } +} + +static ERTS_INLINE Eterm +write_timestamp(ErtsTraceTimeStamp *tsp, Eterm **hpp) +{ + int ts_type_flag = tsp->ts_type_flag; + Eterm res; + + switch (ts_type_flag) { + case 0: + return NIL; + case ERTS_TRACE_FLG_NOW_TIMESTAMP: + res = TUPLE3(*hpp, + make_small(tsp->u.now.ms), + make_small(tsp->u.now.s), + make_small(tsp->u.now.us)); + *hpp += 4; + return res; + case ERTS_TRACE_FLG_MONOTONIC_TIMESTAMP: + case ERTS_TRACE_FLG_STRICT_MONOTONIC_TIMESTAMP: { + Sint64 mtime, raw; + Eterm unique, emtime; + + mtime = (Sint64) tsp->u.monotonic.time; + emtime = (IS_SSMALL(mtime) + ? make_small((Sint64) mtime) + : erts_sint64_to_big((Sint64) mtime, hpp)); + + if (ts_type_flag == ERTS_TRACE_FLG_MONOTONIC_TIMESTAMP) + return emtime; + + raw = tsp->u.monotonic.raw_unique; + unique = erts_raw_make_unique_monotonic_integer_value(hpp, + raw); + res = TUPLE2(*hpp, emtime, unique); + *hpp += 3; + return res; + } + default: + ERTS_INTERNAL_ERROR("invalid timestamp type"); + return THE_NON_VALUE; + } +} + +#define PATCH_TS_SIZE(p) patch_ts_size(TFLGS_TS_TYPE(p)) + +static ERTS_INLINE Uint +patch_ts_size(int ts_type) +{ + int ts_type_flag = ts_type & -ts_type; /* least significant flag */ + switch (ts_type_flag) { + case 0: + return 0; + case ERTS_TRACE_FLG_NOW_TIMESTAMP: + return 1 + ERTS_TRACE_TS_NOW_MAX_SIZE; + case ERTS_TRACE_FLG_MONOTONIC_TIMESTAMP: + return 1 + ERTS_TRACE_TS_MONOTONIC_MAX_SIZE; + case ERTS_TRACE_FLG_STRICT_MONOTONIC_TIMESTAMP: + return 1 + ERTS_TRACE_TS_STRICT_MONOTONIC_MAX_SIZE; + default: + ERTS_INTERNAL_ERROR("invalid timestamp type"); + return 0; + } +} + +/* + * Write a timestamp. The timestamp MUST be the last + * thing built on the heap. This since write_ts() might + * adjust the size of the used area. + */ +static Eterm +write_ts(int ts_type, Eterm *hp, ErlHeapFragment *bp, Process *tracer) +{ + ErtsTraceTimeStamp ts; + Sint shrink; + Eterm res, *ts_hp = hp; + Uint hsz; + + ASSERT(ts_type); + + hsz = take_timestamp(&ts, ts_type); + + res = write_timestamp(&ts, &ts_hp); + + ASSERT(ts_hp == hp + hsz); + + switch (ts.ts_type_flag) { + case ERTS_TRACE_FLG_MONOTONIC_TIMESTAMP: + shrink = ERTS_TRACE_TS_MONOTONIC_MAX_SIZE; + break; + case ERTS_TRACE_FLG_STRICT_MONOTONIC_TIMESTAMP: + shrink = ERTS_TRACE_TS_STRICT_MONOTONIC_MAX_SIZE; + break; + default: + return res; + } + + shrink -= hsz; + + ASSERT(shrink >= 0); + + if (shrink) { + if (bp) + bp->used_size -= shrink; +#ifndef ERTS_SMP + else if (tracer) { + Eterm *endp = ts_hp + shrink; + HRelease(tracer, endp, ts_hp); + } +#endif + } + + return res; +} + +/* + * Patch a timestamp into a tuple. The tuple MUST be the last thing + * built on the heap before the call, and the timestamp MUST be + * the last thing after the call. This since patch_ts() might adjust + * the size of the used area. + */ + +#define PATCH_TS__(Type, Tuple, Hp, Bp, Tracer) \ + do { \ + int ts_type__ = (Type); \ + if (ts_type__) \ + patch_ts(ts_type__, (Tuple), (Hp), (Bp), (Tracer)); \ + } while (0) + +#ifdef ERTS_SMP +#define PATCH_TS(Type, Tuple, Hp, Bp, Tracer) \ + PATCH_TS__((Type), (Tuple), (Hp), (Bp), NULL) +#else +#define PATCH_TS(Type, Tuple, Hp, Bp, Tracer) \ + PATCH_TS__((Type), (Tuple), (Hp), (Bp), (Tracer)) +#endif + +static ERTS_INLINE void +patch_ts(int ts_type, Eterm tuple, Eterm* hp, ErlHeapFragment *bp, Process *tracer) +{ + Eterm *tptr = tuple_val(tuple); + int arity = arityval(*tptr); + + ASSERT(ts_type); + ASSERT((tptr+arity+1) == hp); + + tptr[0] = make_arityval(arity+1); + tptr[1] = am_trace_ts; + + *hp = write_ts(ts_type, hp+1, bp, tracer); +} + #ifdef ERTS_SMP static void enqueue_sys_msg_unlocked(enum ErtsSysMsgType type, Eterm from, @@ -365,23 +623,6 @@ erts_get_system_profile(void) { return profile; } - -#ifdef HAVE_ERTS_NOW_CPU -# define GET_NOW(m, s, u) \ -do { \ - if (erts_cpu_timestamp) \ - erts_get_now_cpu(m, s, u); \ - else \ - get_now(m, s, u); \ -} while (0) -#else -# define GET_NOW(m, s, u) do {get_now(m, s, u);} while (0) -#endif - - - -static Eterm* patch_ts(Eterm tuple4, Eterm* hp); - #ifdef ERTS_SMP static void do_send_to_port(Eterm to, @@ -436,11 +677,11 @@ WRITE_SYS_MSG_TO_PORT(Eterm unused_to, /* Send {trace_ts, Pid, out, 0, Timestamp} * followed by {trace_ts, Pid, in, 0, NewTimestamp} * - * 'NewTimestamp' is fetched from GET_NOW() through patch_ts(). + * 'NewTimestamp' through patch_ts(). */ static void -do_send_schedfix_to_port(Port *trace_port, Eterm pid, Eterm timestamp) { -#define LOCAL_HEAP_SIZE (4+5+5) +do_send_schedfix_to_port(Port *trace_port, Eterm pid, Eterm timestamp, int ts_type) { +#define LOCAL_HEAP_SIZE (5+5+ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); Eterm message; Eterm *hp; @@ -462,9 +703,11 @@ do_send_schedfix_to_port(Port *trace_port, Eterm pid, Eterm timestamp) { SYS_MSG_TYPE_UNDEFINED, message); - message = TUPLE4(hp, am_trace_ts, pid, am_in, mfarity); - hp += 5; - hp = patch_ts(message, hp); + + message = TUPLE5(hp, am_trace_ts, pid, am_in, mfarity, + NIL /* Will be overwritten by timestamp */); + hp += 6; + hp[-1] = write_ts(ts_type, hp, NULL, NULL); do_send_to_port(trace_port->common.id, trace_port, @@ -481,7 +724,7 @@ do_send_schedfix_to_port(Port *trace_port, Eterm pid, Eterm timestamp) { * It is assumed that 'message' is not an 'out' message. * * 'c_p' is the currently executing process, "tracee" is the traced process - * which 'message' concerns => if (*tracee_flags & F_TIMESTAMP), + * which 'message' concerns => if (*tracee_flags & F_TIMESTAMP_MASK), * 'message' must contain a timestamp. */ static void @@ -489,8 +732,9 @@ send_to_port(Process *c_p, Eterm message, Eterm *tracer_pid, Uint *tracee_flags) { Port* trace_port; #ifndef ERTS_SMP -#define LOCAL_HEAP_SIZE (4) - Eterm ts, *hp; + int ts_type; +#define LOCAL_HEAP_SIZE ERTS_TRACE_PATCH_TS_MAX_SIZE + Eterm ts; DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); #endif @@ -519,7 +763,7 @@ send_to_port(Process *c_p, Eterm message, */ if ( c_p == NULL || - (! IS_TRACED_FL(c_p, F_TRACE_SCHED | F_TIMESTAMP))) { + (! IS_TRACED_FL(c_p, F_TRACE_SCHED | F_TIMESTAMP_MASK))) { #endif do_send_to_port(*tracer_pid, trace_port, @@ -538,22 +782,12 @@ send_to_port(Process *c_p, Eterm message, */ UseTmpHeapNoproc(LOCAL_HEAP_SIZE); - if (*tracee_flags & F_TIMESTAMP) { - ASSERT(is_tuple(message)); - hp = tuple_val(message); - ts = hp[arityval(hp[0])]; - } else { - /* A fake schedule might be needed, - * but this message does not contain a timestamp. - * Create a dummy trace message with timestamp to be - * passed to do_send_schedfix_to_port(). - */ - Uint ms,s,us; - GET_NOW(&ms, &s, &us); - hp = local_heap; - ts = TUPLE3(hp, make_small(ms), make_small(s), make_small(us)); - hp += 4; - } + /* A fake schedule might be needed. + * Create a dummy trace message with timestamp to be + * passed to do_send_schedfix_to_port(). + */ + ts_type = TFLGS_TS_TYPE(c_p); + ts = write_ts(ts_type, local_heap, NULL, NULL); trace_port->control_flags &= ~PORT_CONTROL_FLAG_HEAVY; do_send_to_port(*tracer_pid, @@ -572,7 +806,7 @@ send_to_port(Process *c_p, Eterm message, * just after writning the real trace message, and now gets scheduled * in again. */ - do_send_schedfix_to_port(trace_port, c_p->common.id, ts); + do_send_schedfix_to_port(trace_port, c_p->common.id, ts, ts_type); } erts_port_release(trace_port); @@ -641,20 +875,19 @@ profile_send(Eterm from, Eterm message) { /* A fake schedule out/in message pair will be sent, * if the driver so requests. - * If (timestamp == NIL), one is fetched from GET_NOW(). * * 'c_p' is the currently executing process, may be NULL. */ static void seq_trace_send_to_port(Process *c_p, Eterm seq_tracer, - Eterm message, - Eterm timestamp) + Eterm message) { Port* trace_port; #ifndef ERTS_SMP - Eterm ts, *hp; -#define LOCAL_HEAP_SIZE (4) + int ts_type; + Eterm ts; +#define LOCAL_HEAP_SIZE ERTS_TRACE_PATCH_TS_MAX_SIZE DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); UseTmpHeapNoproc(LOCAL_HEAP_SIZE); #endif @@ -679,7 +912,7 @@ seq_trace_send_to_port(Process *c_p, } if (c_p == NULL - || (! IS_TRACED_FL(c_p, F_TRACE_SCHED | F_TIMESTAMP))) { + || (! IS_TRACED_FL(c_p, F_TRACE_SCHED | F_TIMESTAMP_MASK))) { #endif do_send_to_port(seq_tracer, trace_port, @@ -696,20 +929,12 @@ seq_trace_send_to_port(Process *c_p, * with 'running' and 'timestamp'. */ - if (timestamp != NIL) { - ts = timestamp; - } else { - /* A fake schedule might be needed, - * but this message does not contain a timestamp. - * Create a dummy trace message with timestamp to be - * passed to do_send_schedfix_to_port(). - */ - Uint ms,s,us; - GET_NOW(&ms, &s, &us); - hp = local_heap; - ts = TUPLE3(hp, make_small(ms), make_small(s), make_small(us)); - hp += 4; - } + /* A fake schedule might be needed. + * Create a dummy trace message with timestamp to be + * passed to do_send_schedfix_to_port(). + */ + ts_type = TFLGS_TS_TYPE(c_p); + ts = write_ts(ts_type, local_heap, NULL, NULL); trace_port->control_flags &= ~PORT_CONTROL_FLAG_HEAVY; do_send_to_port(seq_tracer, @@ -728,7 +953,7 @@ seq_trace_send_to_port(Process *c_p, * just after writing the real trace message, and now gets scheduled * in again. */ - do_send_schedfix_to_port(trace_port, c_p->common.id, ts); + do_send_schedfix_to_port(trace_port, c_p->common.id, ts, ts_type); } erts_port_release(trace_port); @@ -738,32 +963,6 @@ seq_trace_send_to_port(Process *c_p, #endif } -#define TS_HEAP_WORDS 5 -#define TS_SIZE(p) ((ERTS_TRACE_FLAGS((p)) & F_TIMESTAMP) \ - ? TS_HEAP_WORDS \ - : 0) - -/* - * Patch a timestamp into a tuple. The tuple must be the last thing - * built on the heap. - * - * Returns the new hp pointer. -*/ -static Eterm* -patch_ts(Eterm tuple, Eterm* hp) -{ - Uint ms, s, us; - Eterm* ptr = tuple_val(tuple); - int arity = arityval(*ptr); - - ASSERT((ptr+arity+1) == hp); - ptr[0] = make_arityval(arity+1); - ptr[1] = am_trace_ts; - GET_NOW(&ms, &s, &us); - *hp = TUPLE3(hp+1, make_small(ms), make_small(s), make_small(us)); - return hp+5; -} - static ERTS_INLINE void send_to_tracer(Process *tracee, ERTS_TRACER_REF_TYPE tracer_ref, @@ -776,13 +975,13 @@ send_to_tracer(Process *tracee, erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(tracee) & F_TIMESTAMP) - *hpp = patch_ts(msg, *hpp); - - if (is_internal_pid(ERTS_TRACER_PROC(tracee))) + if (is_internal_pid(ERTS_TRACER_PROC(tracee))) { + PATCH_TS(TFLGS_TS_TYPE(tracee), msg, *hpp, bp, tracer_ref); ERTS_ENQ_TRACE_MSG(tracee->common.id, tracer_ref, msg, bp); + } else { ASSERT(is_internal_port(ERTS_TRACER_PROC(tracee))); + PATCH_TS(TFLGS_TS_TYPE(tracee), msg, *hpp, NULL, NULL); send_to_port(no_fake_sched ? NULL : tracee, msg, &ERTS_TRACER_PROC(tracee), @@ -796,7 +995,7 @@ send_to_tracer(Process *tracee, static void trace_sched_aux(Process *p, Eterm what, int never_fake_sched) { -#define LOCAL_HEAP_SIZE (5+4+1+TS_HEAP_WORDS) +#define LOCAL_HEAP_SIZE (5+4+1+ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeap(local_heap,LOCAL_HEAP_SIZE,p); Eterm tmp, mess, *hp; ErlHeapFragment *bp = NULL; @@ -852,7 +1051,7 @@ trace_sched_aux(Process *p, Eterm what, int never_fake_sched) size += 4; if (sched_no) size += 1; - size += TS_SIZE(p); + size += PATCH_TS_SIZE(p); hp = ERTS_ALLOC_SYSMSG_HEAP(size, &bp, &off_heap, tracer_ref); } @@ -926,7 +1125,7 @@ trace_send(Process *p, Eterm to, Eterm msg) } if (is_internal_port(ERTS_TRACER_PROC(p))) { -#define LOCAL_HEAP_SIZE (11) +#define LOCAL_HEAP_SIZE (6 + ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); UseTmpHeapNoproc(LOCAL_HEAP_SIZE); @@ -934,9 +1133,7 @@ trace_send(Process *p, Eterm to, Eterm msg) mess = TUPLE5(hp, am_trace, p->common.id, operation, msg, to); hp += 6; erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(p) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(TFLGS_TS_TYPE(p), mess, hp, NULL, NULL); send_to_port(p, mess, &ERTS_TRACER_PROC(p), &ERTS_TRACE_FLAGS(p)); UnUseTmpHeapNoproc(LOCAL_HEAP_SIZE); #undef LOCAL_HEAP_SIZE @@ -955,7 +1152,7 @@ trace_send(Process *p, Eterm to, Eterm msg) sz_msg = size_object(msg); sz_to = size_object(to); - need = sz_msg + sz_to + 6 + TS_SIZE(p); + need = sz_msg + sz_to + 6 + PATCH_TS_SIZE(p); hp = ERTS_ALLOC_SYSMSG_HEAP(need, &bp, &off_heap, tracer_ref); @@ -972,10 +1169,7 @@ trace_send(Process *p, Eterm to, Eterm msg) erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(p) & F_TIMESTAMP) { - patch_ts(mess, hp); - } - + PATCH_TS(TFLGS_TS_TYPE(p), mess, hp, bp, tracer_ref); ERTS_ENQ_TRACE_MSG(p->common.id, tracer_ref, mess, bp); erts_smp_mtx_unlock(&smq_mtx); } @@ -992,7 +1186,7 @@ trace_receive(Process *rp, Eterm msg) Eterm* hp; if (is_internal_port(ERTS_TRACER_PROC(rp))) { -#define LOCAL_HEAP_SIZE (10) +#define LOCAL_HEAP_SIZE (5+ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); UseTmpHeapNoproc(LOCAL_HEAP_SIZE); @@ -1000,9 +1194,7 @@ trace_receive(Process *rp, Eterm msg) mess = TUPLE4(hp, am_trace, rp->common.id, am_receive, msg); hp += 5; erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(rp) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(TFLGS_TS_TYPE(rp), mess, hp, NULL, NULL); send_to_port(rp, mess, &ERTS_TRACER_PROC(rp), &ERTS_TRACE_FLAGS(rp)); UnUseTmpHeapNoproc(LOCAL_HEAP_SIZE); #undef LOCAL_HEAP_SIZE @@ -1021,7 +1213,7 @@ trace_receive(Process *rp, Eterm msg) sz_msg = size_object(msg); - hsz = sz_msg + 5 + TS_SIZE(rp); + hsz = sz_msg + 5 + PATCH_TS_SIZE(rp); hp = ERTS_ALLOC_SYSMSG_HEAP(hsz, &bp, &off_heap, tracer_ref); @@ -1031,10 +1223,7 @@ trace_receive(Process *rp, Eterm msg) erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(rp) & F_TIMESTAMP) { - patch_ts(mess, hp); - } - + PATCH_TS(TFLGS_TS_TYPE(rp), mess, hp, bp, tracer_ref); ERTS_ENQ_TRACE_MSG(rp->common.id, tracer_ref, mess, bp); erts_smp_mtx_unlock(&smq_mtx); } @@ -1084,6 +1273,7 @@ seq_trace_output_generic(Eterm token, Eterm msg, Uint type, Eterm type_atom; int sz_exit; Eterm seq_tracer; + int ts_type; seq_tracer = erts_get_system_seq_tracer(); @@ -1111,8 +1301,10 @@ seq_trace_output_generic(Eterm token, Eterm msg, Uint type, return; /* no need to send anything */ } + ts_type = ERTS_SEQTFLGS2TSTYPE(unsigned_val(SEQ_TRACE_T_FLAGS(token))); + if (is_internal_port(seq_tracer)) { -#define LOCAL_HEAP_SIZE (64) +#define LOCAL_HEAP_SIZE (60 + ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); UseTmpHeapNoproc(LOCAL_HEAP_SIZE); @@ -1128,17 +1320,17 @@ seq_trace_output_generic(Eterm token, Eterm msg, Uint type, mess = TUPLE5(hp, type_atom, lastcnt_serial, SEQ_TRACE_T_SENDER(token), receiver, msg); hp += 6; + erts_smp_mtx_lock(&smq_mtx); - if ((unsigned_val(SEQ_TRACE_T_FLAGS(token)) & SEQ_TRACE_TIMESTAMP) == 0) { + if (!ts_type) { mess = TUPLE3(hp, am_seq_trace, label, mess); - seq_trace_send_to_port(NULL, seq_tracer, mess, NIL); + seq_trace_send_to_port(NULL, seq_tracer, mess); } else { - Uint ms,s,us,ts; - GET_NOW(&ms, &s, &us); - ts = TUPLE3(hp, make_small(ms),make_small(s), make_small(us)); - hp += 4; - mess = TUPLE4(hp, am_seq_trace, label, mess, ts); - seq_trace_send_to_port(process, seq_tracer, mess, ts); + mess = TUPLE4(hp, am_seq_trace, label, mess, + NIL /* Will be overwritten by timestamp */); + hp += 5; + hp[-1] = write_ts(ts_type, hp, NULL, NULL); + seq_trace_send_to_port(process, seq_tracer, mess); } UnUseTmpHeapNoproc(LOCAL_HEAP_SIZE); #undef LOCAL_HEAP_SIZE @@ -1173,8 +1365,7 @@ seq_trace_output_generic(Eterm token, Eterm msg, Uint type, sz_lastcnt_serial = 3; /* TUPLE2 */ sz_msg = size_object(msg); - sz_ts = ((unsigned_val(SEQ_TRACE_T_FLAGS(token)) & SEQ_TRACE_TIMESTAMP) ? - 5 : 0); + sz_ts = patch_ts_size(ts_type); if (exitfrom != NIL) { sz_exit = 4; /* create {'EXIT',exitfrom,msg} */ sz_exitfrom = size_object(exitfrom); @@ -1218,14 +1409,20 @@ seq_trace_output_generic(Eterm token, Eterm msg, Uint type, erts_smp_mtx_lock(&smq_mtx); - if (sz_ts) {/* timestamp should be included */ - Uint ms,s,us,ts; - GET_NOW(&ms, &s, &us); - ts = TUPLE3(hp, make_small(ms),make_small(s), make_small(us)); - hp += 4; - mess = TUPLE4(hp, am_seq_trace, label, mess, ts); - } else { + if (!ts_type) mess = TUPLE3(hp, am_seq_trace, label, mess); + else { + mess = TUPLE4(hp, am_seq_trace, label, mess, + NIL /* Will be overwritten by timestamp */); + hp += 5; + /* Write timestamp in element 6 of the 'msg' tuple */ + hp[-1] = write_ts(ts_type, hp, bp, +#ifndef ERTS_SMP + tracer +#else + NULL +#endif + ); } #ifdef ERTS_SMP @@ -1244,7 +1441,7 @@ seq_trace_output_generic(Eterm token, Eterm msg, Uint type, void erts_trace_return_to(Process *p, BeamInstr *pc) { -#define LOCAL_HEAP_SIZE (4+5+5) +#define LOCAL_HEAP_SIZE (4+5+ERTS_TRACE_PATCH_TS_MAX_SIZE) Eterm* hp; Eterm mfa; Eterm mess; @@ -1269,9 +1466,7 @@ erts_trace_return_to(Process *p, BeamInstr *pc) erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(p) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(TFLGS_TS_TYPE(p), mess, hp, NULL, NULL); if (is_internal_port(ERTS_TRACER_PROC(p))) { send_to_port(p, mess, &ERTS_TRACER_PROC(p), &ERTS_TRACE_FLAGS(p)); @@ -1318,6 +1513,7 @@ erts_trace_return(Process* p, BeamInstr* fi, Eterm retval, Eterm *tracer_pid) Eterm mod, name; int arity; Uint meta_flags, *tracee_flags; + int ts_type; #ifdef ERTS_SMP Eterm tracee; #endif @@ -1353,7 +1549,7 @@ erts_trace_return(Process* p, BeamInstr* fi, Eterm retval, Eterm *tracer_pid) * meta trace => * use fixed flag set instead of process flags */ - meta_flags = F_TRACE_CALLS | F_TIMESTAMP; + meta_flags = F_TRACE_CALLS | F_NOW_TS; tracee_flags = &meta_flags; #ifdef ERTS_SMP tracee = NIL; @@ -1367,8 +1563,10 @@ erts_trace_return(Process* p, BeamInstr* fi, Eterm retval, Eterm *tracer_pid) name = fi[1]; arity = fi[2]; + ts_type = ERTS_TFLGS2TSTYPE(*tracee_flags); + if (is_internal_port(*tracer_pid)) { -#define LOCAL_HEAP_SIZE (4+6+5) +#define LOCAL_HEAP_SIZE (4+6+ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); UseTmpHeapNoproc(LOCAL_HEAP_SIZE); hp = local_heap; @@ -1377,9 +1575,7 @@ erts_trace_return(Process* p, BeamInstr* fi, Eterm retval, Eterm *tracer_pid) mess = TUPLE5(hp, am_trace, p->common.id, am_return_from, mfa, retval); hp += 6; erts_smp_mtx_lock(&smq_mtx); - if (*tracee_flags & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(ts_type, mess, hp, NULL, NULL); send_to_port(p, mess, tracer_pid, tracee_flags); UnUseTmpHeapNoproc(LOCAL_HEAP_SIZE); #undef LOCAL_HEAP_SIZE @@ -1390,24 +1586,15 @@ erts_trace_return(Process* p, BeamInstr* fi, Eterm retval, Eterm *tracer_pid) ERTS_TRACER_REF_TYPE tracer_ref; unsigned size; unsigned retval_size; -#ifdef DEBUG - Eterm* limit; -#endif ASSERT(is_internal_pid(*tracer_pid)); ERTS_GET_TRACER_REF(tracer_ref, *tracer_pid, *tracee_flags); - + retval_size = size_object(retval); - size = 6 + 4 + retval_size; - if (*tracee_flags & F_TIMESTAMP) { - size += 1+4; - } + size = 6 + 4 + retval_size + patch_ts_size(ts_type); hp = ERTS_ALLOC_SYSMSG_HEAP(size, &bp, &off_heap, tracer_ref); -#ifdef DEBUG - limit = hp + size; -#endif /* * Build the trace tuple and put it into receive queue of the tracer process. @@ -1421,11 +1608,7 @@ erts_trace_return(Process* p, BeamInstr* fi, Eterm retval, Eterm *tracer_pid) erts_smp_mtx_lock(&smq_mtx); - if (*tracee_flags & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } - - ASSERT(hp == limit); + PATCH_TS(ts_type, mess, hp, bp, tracer_ref); ERTS_ENQ_TRACE_MSG(tracee, tracer_ref, mess, bp); erts_smp_mtx_unlock(&smq_mtx); @@ -1448,6 +1631,7 @@ erts_trace_exception(Process* p, BeamInstr mfa[3], Eterm class, Eterm value, Eterm cv; Eterm mess; Uint meta_flags, *tracee_flags; + int ts_type; #ifdef ERTS_SMP Eterm tracee; #endif @@ -1486,15 +1670,17 @@ erts_trace_exception(Process* p, BeamInstr mfa[3], Eterm class, Eterm value, * meta trace => * use fixed flag set instead of process flags */ - meta_flags = F_TRACE_CALLS | F_TIMESTAMP; + meta_flags = F_TRACE_CALLS | F_NOW_TS; tracee_flags = &meta_flags; #ifdef ERTS_SMP tracee = NIL; #endif } + ts_type = ERTS_TFLGS2TSTYPE(*tracee_flags); + if (is_internal_port(*tracer_pid)) { -#define LOCAL_HEAP_SIZE (4+3+6+5) +#define LOCAL_HEAP_SIZE (4+3+6+ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); UseTmpHeapNoproc(LOCAL_HEAP_SIZE); @@ -1507,10 +1693,7 @@ erts_trace_exception(Process* p, BeamInstr mfa[3], Eterm class, Eterm value, hp += 6; ASSERT((hp - local_heap) <= LOCAL_HEAP_SIZE); erts_smp_mtx_lock(&smq_mtx); - if (*tracee_flags & F_TIMESTAMP) { - hp = patch_ts(mess, hp); /* hp += 5 */ - ASSERT((hp - local_heap) == LOCAL_HEAP_SIZE); - } + PATCH_TS(ts_type, mess, hp, NULL, NULL); send_to_port(p, mess, tracer_pid, tracee_flags); UnUseTmpHeapNoproc(LOCAL_HEAP_SIZE); #undef LOCAL_HEAP_SIZE @@ -1521,24 +1704,15 @@ erts_trace_exception(Process* p, BeamInstr mfa[3], Eterm class, Eterm value, ERTS_TRACER_REF_TYPE tracer_ref; unsigned size; unsigned value_size; -#ifdef DEBUG - Eterm* limit; -#endif ASSERT(is_internal_pid(*tracer_pid)); ERTS_GET_TRACER_REF(tracer_ref, *tracer_pid, *tracee_flags); value_size = size_object(value); - size = 6 + 4 + 3 + value_size; - if (*tracee_flags & F_TIMESTAMP) { - size += 1+4; - } + size = 6 + 4 + 3 + value_size + patch_ts_size(ts_type); hp = ERTS_ALLOC_SYSMSG_HEAP(size, &bp, &off_heap, tracer_ref); -#ifdef DEBUG - limit = hp + size; -#endif /* * Build the trace tuple and put it into receive queue of the tracer process. @@ -1555,11 +1729,7 @@ erts_trace_exception(Process* p, BeamInstr mfa[3], Eterm class, Eterm value, erts_smp_mtx_lock(&smq_mtx); - if (*tracee_flags & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } - - ASSERT(hp == limit); + PATCH_TS(ts_type, mess, hp, bp, tracer_ref); ERTS_ENQ_TRACE_MSG(tracee, tracer_ref, mess, bp); erts_smp_mtx_unlock(&smq_mtx); @@ -1592,6 +1762,7 @@ erts_call_trace(Process* p, BeamInstr mfa[3], Binary *match_spec, Eterm pam_result = am_true; Eterm mess; Uint meta_flags, *tracee_flags; + int ts_type; #ifdef ERTS_SMP Eterm tracee; #endif @@ -1633,7 +1804,7 @@ erts_call_trace(Process* p, BeamInstr mfa[3], Binary *match_spec, /* No trace messages for sensitive processes. */ return 0; } - meta_flags = F_TRACE_CALLS | F_TIMESTAMP; + meta_flags = F_TRACE_CALLS | F_NOW_TS; tracee_flags = &meta_flags; #ifdef ERTS_SMP tracee = NIL; @@ -1676,12 +1847,14 @@ erts_call_trace(Process* p, BeamInstr mfa[3], Binary *match_spec, } args = transformed_args; + ts_type = ERTS_TFLGS2TSTYPE(*tracee_flags); + if (is_internal_port(*tracer_pid)) { #if HEAP_ON_C_STACK - Eterm local_heap[64+MAX_ARG]; + Eterm local_heap[60+ERTS_TRACE_PATCH_TS_MAX_SIZE+MAX_ARG]; #else Eterm *local_heap = erts_alloc(ERTS_ALC_T_TEMP_TERM, - sizeof(Eterm)*(64+MAX_ARG)); + sizeof(Eterm)*(60+ERTS_TRACE_PATCH_TS_MAX_SIZE+MAX_ARG)); #endif hp = local_heap; @@ -1796,9 +1969,7 @@ erts_call_trace(Process* p, BeamInstr mfa[3], Binary *match_spec, *hp++ = pam_result; } erts_smp_mtx_lock(&smq_mtx); - if (*tracee_flags & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(ts_type, mess, hp, NULL, NULL); send_to_port(p, mess, tracer_pid, tracee_flags); erts_smp_mtx_unlock(&smq_mtx); erts_match_set_release_result(p); @@ -1820,9 +1991,6 @@ erts_call_trace(Process* p, BeamInstr mfa[3], Binary *match_spec, unsigned sizes[MAX_ARG]; unsigned pam_result_size = 0; int invalid_tracer; -#ifdef DEBUG - Eterm* limit; -#endif ASSERT(is_internal_pid(*tracer_pid)); @@ -1915,10 +2083,7 @@ erts_call_trace(Process* p, BeamInstr mfa[3], Binary *match_spec, size += sizes[i]; } } - if (*tracee_flags & F_TIMESTAMP) { - size += 1 + 4; - /* One element in trace tuple + timestamp tuple. */ - } + size += patch_ts_size(ts_type); if (pam_result != am_true) { pam_result_size = size_object(pam_result); size += 1 + pam_result_size; @@ -1926,9 +2091,6 @@ erts_call_trace(Process* p, BeamInstr mfa[3], Binary *match_spec, } hp = ERTS_ALLOC_SYSMSG_HEAP(size, &bp, &off_heap, tracer_ref); -#ifdef DEBUG - limit = hp + size; -#endif /* * Build the the {M,F,A} tuple in the message buffer. @@ -1971,11 +2133,7 @@ erts_call_trace(Process* p, BeamInstr mfa[3], Binary *match_spec, erts_smp_mtx_lock(&smq_mtx); - if (*tracee_flags & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } - - ASSERT(hp == limit); + PATCH_TS(ts_type, mess, hp, bp, tracer_ref); ERTS_ENQ_TRACE_MSG(tracee, tracer_ref, mess, bp); erts_smp_mtx_unlock(&smq_mtx); UnUseTmpHeap(ERL_SUB_BIN_SIZE,p); @@ -2010,9 +2168,7 @@ trace_proc(Process *c_p, Process *t_p, Eterm what, Eterm data) mess = TUPLE4(hp, am_trace, t_p->common.id, what, data); hp += 5; erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(t_p) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(TFLGS_TS_TYPE(t_p), mess, hp, NULL, NULL); send_to_port( #ifndef ERTS_SMP /* No fake schedule out and in again after an exit */ @@ -2042,7 +2198,7 @@ trace_proc(Process *c_p, Process *t_p, Eterm what, Eterm data) sz_data = size_object(data); - need = sz_data + 5 + TS_SIZE(t_p); + need = sz_data + 5 + PATCH_TS_SIZE(t_p); hp = ERTS_ALLOC_SYSMSG_HEAP(need, &bp, &off_heap, tracer_ref); @@ -2052,9 +2208,7 @@ trace_proc(Process *c_p, Process *t_p, Eterm what, Eterm data) erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(t_p) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(TFLGS_TS_TYPE(t_p), mess, hp, bp, tracer_ref); ERTS_ENQ_TRACE_MSG(t_p->common.id, tracer_ref, mess, bp); erts_smp_mtx_unlock(&smq_mtx); @@ -2088,9 +2242,7 @@ trace_proc_spawn(Process *p, Eterm pid, mess = TUPLE5(hp, am_trace, p->common.id, am_spawn, pid, mfa); hp += 6; erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(p) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(TFLGS_TS_TYPE(p), mess, hp, NULL, NULL); send_to_port(p, mess, &ERTS_TRACER_PROC(p), &ERTS_TRACE_FLAGS(p)); UnUseTmpHeapNoproc(LOCAL_HEAP_SIZE); #undef LOCAL_HEAP_SIZE @@ -2111,7 +2263,7 @@ trace_proc_spawn(Process *p, Eterm pid, sz_args = size_object(args); sz_pid = size_object(pid); - need = sz_args + 4 + 6 + TS_SIZE(p); + need = sz_args + 4 + 6 + PATCH_TS_SIZE(p); hp = ERTS_ALLOC_SYSMSG_HEAP(need, &bp, &off_heap, tracer_ref); @@ -2124,9 +2276,7 @@ trace_proc_spawn(Process *p, Eterm pid, erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(p) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(TFLGS_TS_TYPE(p), mess, hp, bp, tracer_ref); ERTS_ENQ_TRACE_MSG(p->common.id, tracer_ref, mess, bp); erts_smp_mtx_unlock(&smq_mtx); @@ -2208,11 +2358,8 @@ trace_gc(Process *p, Eterm what) #define LOCAL_HEAP_SIZE \ (sizeof(values)/sizeof(*values)) * \ (2/*cons*/ + 3/*2-tuple*/ + BIG_UINT_HEAP_SIZE) + \ - 5/*4-tuple */ + TS_HEAP_WORDS + 5/*4-tuple */ + ERTS_TRACE_PATCH_TS_MAX_SIZE DeclareTmpHeap(local_heap,LOCAL_HEAP_SIZE,p); -#ifdef DEBUG - Eterm* limit; -#endif ERTS_CT_ASSERT(sizeof(values)/sizeof(*values) == sizeof(tags)/sizeof(Eterm)); @@ -2227,7 +2374,7 @@ trace_gc(Process *p, Eterm what) sizeof(values)/sizeof(*values), tags, values); - size += 5/*4-tuple*/ + TS_SIZE(p); + size += 5/*4-tuple*/ + PATCH_TS_SIZE(p); #endif } else { ASSERT(is_internal_pid(ERTS_TRACER_PROC(p))); @@ -2242,15 +2389,12 @@ trace_gc(Process *p, Eterm what) sizeof(values)/sizeof(*values), tags, values); - size += 5/*4-tuple*/ + TS_SIZE(p); + size += 5/*4-tuple*/ + PATCH_TS_SIZE(p); hp = ERTS_ALLOC_SYSMSG_HEAP(size, &bp, &off_heap, tracer_ref); } -#ifdef DEBUG - limit = hp + size; ASSERT(size <= LOCAL_HEAP_SIZE); -#endif msg = erts_bld_atom_uword_2tup_list(&hp, NULL, @@ -2263,14 +2407,14 @@ trace_gc(Process *p, Eterm what) erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(p) & F_TIMESTAMP) { - hp = patch_ts(msg, hp); - } - ASSERT(hp == limit); - if (is_internal_port(ERTS_TRACER_PROC(p))) + if (is_internal_port(ERTS_TRACER_PROC(p))) { + PATCH_TS(TFLGS_TS_TYPE(p), msg, hp, NULL, NULL); send_to_port(p, msg, &ERTS_TRACER_PROC(p), &ERTS_TRACE_FLAGS(p)); - else + } + else { + PATCH_TS(TFLGS_TS_TYPE(p), msg, hp, bp, tracer_ref); ERTS_ENQ_TRACE_MSG(p->common.id, tracer_ref, msg, bp); + } erts_smp_mtx_unlock(&smq_mtx); UnUseTmpHeap(LOCAL_HEAP_SIZE,p); #undef LOCAL_HEAP_SIZE @@ -2574,19 +2718,18 @@ monitor_generic(Process *p, Eterm type, Eterm spec) { void profile_scheduler(Eterm scheduler_id, Eterm state) { - Eterm *hp, msg, timestamp; - Uint Ms, s, us; + Eterm *hp, msg; + ErlHeapFragment *bp = NULL; #ifndef ERTS_SMP -#define LOCAL_HEAP_SIZE (4 + 7) +#define LOCAL_HEAP_SIZE (7 + ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); UseTmpHeapNoproc(LOCAL_HEAP_SIZE); hp = local_heap; #else - ErlHeapFragment *bp; Uint hsz; - hsz = 4 + 7; + hsz = 7 + patch_ts_size(erts_system_profile_ts_type)-1; bp = new_message_buffer(hsz); hp = bp->mem; @@ -2606,10 +2749,13 @@ profile_scheduler(Eterm scheduler_id, Eterm state) { break; } - GET_NOW(&Ms, &s, &us); - timestamp = TUPLE3(hp, make_small(Ms), make_small(s), make_small(us)); hp += 4; - msg = TUPLE6(hp, am_profile, am_scheduler, scheduler_id, state, - make_small(active_sched), timestamp); hp += 7; + msg = TUPLE6(hp, am_profile, am_scheduler, scheduler_id, + state, make_small(active_sched), + NIL /* Will be overwritten by timestamp */); + hp += 7; + + /* Write timestamp in element 6 of the 'msg' tuple */ + hp[-1] = write_ts(erts_system_profile_ts_type, hp, bp, NULL); #ifndef ERTS_SMP profile_send(NIL, msg); @@ -2680,7 +2826,7 @@ trace_port_open(Port *p, Eterm calling_pid, Eterm drv_name) { Eterm* hp; if (is_internal_port(ERTS_TRACER_PROC(p))) { -#define LOCAL_HEAP_SIZE (5+6) +#define LOCAL_HEAP_SIZE (6+ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); UseTmpHeapNoproc(LOCAL_HEAP_SIZE); @@ -2689,9 +2835,7 @@ trace_port_open(Port *p, Eterm calling_pid, Eterm drv_name) { mess = TUPLE5(hp, am_trace, calling_pid, am_open, p->common.id, drv_name); hp += 6; erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(p) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(TFLGS_TS_TYPE(p), mess, hp, NULL, NULL); /* No fake schedule */ send_to_port(NULL, mess, &ERTS_TRACER_PROC(p), &ERTS_TRACE_FLAGS(p)); UnUseTmpHeapNoproc(LOCAL_HEAP_SIZE); @@ -2705,7 +2849,7 @@ trace_port_open(Port *p, Eterm calling_pid, Eterm drv_name) { ASSERT(is_internal_pid(ERTS_TRACER_PROC(p))); - sz_data = 6 + TS_SIZE(p); + sz_data = 6 + PATCH_TS_SIZE(p); ERTS_GET_TRACER_REF(tracer_ref, ERTS_TRACER_PROC(p), @@ -2718,9 +2862,7 @@ trace_port_open(Port *p, Eterm calling_pid, Eterm drv_name) { erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(p) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(TFLGS_TS_TYPE(p), mess, hp, bp, tracer_ref); ERTS_ENQ_TRACE_MSG(p->common.id, tracer_ref, mess, bp); erts_smp_mtx_unlock(&smq_mtx); @@ -2744,7 +2886,7 @@ trace_port(Port *t_p, Eterm what, Eterm data) { || erts_thr_progress_is_blocking()); if (is_internal_port(ERTS_TRACER_PROC(t_p))) { -#define LOCAL_HEAP_SIZE (5+5) +#define LOCAL_HEAP_SIZE (5+ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); UseTmpHeapNoproc(LOCAL_HEAP_SIZE); @@ -2752,9 +2894,7 @@ trace_port(Port *t_p, Eterm what, Eterm data) { mess = TUPLE4(hp, am_trace, t_p->common.id, what, data); hp += 5; erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(t_p) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(TFLGS_TS_TYPE(t_p), mess, hp, NULL, NULL); /* No fake schedule */ send_to_port(NULL,mess,&ERTS_TRACER_PROC(t_p),&ERTS_TRACE_FLAGS(t_p)); UnUseTmpHeapNoproc(LOCAL_HEAP_SIZE); @@ -2768,7 +2908,7 @@ trace_port(Port *t_p, Eterm what, Eterm data) { ASSERT(is_internal_pid(ERTS_TRACER_PROC(t_p))); - sz_data = 5 + TS_SIZE(t_p); + sz_data = 5 + PATCH_TS_SIZE(t_p); ERTS_GET_TRACER_REF(tracer_ref, ERTS_TRACER_PROC(t_p), @@ -2781,9 +2921,7 @@ trace_port(Port *t_p, Eterm what, Eterm data) { erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(t_p) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + PATCH_TS(TFLGS_TS_TYPE(t_p), mess, hp, bp, tracer_ref); ERTS_ENQ_TRACE_MSG(t_p->common.id, tracer_ref, mess, bp); erts_smp_mtx_unlock(&smq_mtx); @@ -2811,7 +2949,7 @@ trace_sched_ports_where(Port *p, Eterm what, Eterm where) { Eterm sched_id = am_undefined; if (is_internal_port(ERTS_TRACER_PROC(p))) { -#define LOCAL_HEAP_SIZE (5+6) +#define LOCAL_HEAP_SIZE (6+ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); UseTmpHeapNoproc(LOCAL_HEAP_SIZE); @@ -2834,9 +2972,8 @@ trace_sched_ports_where(Port *p, Eterm what, Eterm where) { hp += ws; erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(p) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } + + PATCH_TS(TFLGS_TS_TYPE(p), mess, hp, NULL, NULL); /* No fake scheduling */ send_to_port(NULL, mess, &ERTS_TRACER_PROC(p), &ERTS_TRACE_FLAGS(p)); @@ -2856,7 +2993,7 @@ trace_sched_ports_where(Port *p, Eterm what, Eterm where) { ERTS_TRACER_PROC(p), ERTS_TRACE_FLAGS(p)); - hp = ERTS_ALLOC_SYSMSG_HEAP(ws+TS_SIZE(p), &bp, &off_heap, tracer_ref); + hp = ERTS_ALLOC_SYSMSG_HEAP(ws+PATCH_TS_SIZE(p), &bp, &off_heap, tracer_ref); if (IS_TRACED_FL(p, F_TRACE_SCHED_NO)) { #ifdef ERTS_SMP @@ -2874,10 +3011,7 @@ trace_sched_ports_where(Port *p, Eterm what, Eterm where) { erts_smp_mtx_lock(&smq_mtx); - if (ERTS_TRACE_FLAGS(p) & F_TIMESTAMP) { - hp = patch_ts(mess, hp); - } - + PATCH_TS(TFLGS_TS_TYPE(p), mess, hp, bp, tracer_ref); ERTS_ENQ_TRACE_MSG(p->common.id, tracer_ref, mess, bp); erts_smp_mtx_unlock(&smq_mtx); } @@ -2887,13 +3021,12 @@ trace_sched_ports_where(Port *p, Eterm what, Eterm where) { void profile_runnable_port(Port *p, Eterm status) { - Uint Ms, s, us; - Eterm *hp, msg, timestamp; - + Eterm *hp, msg; + ErlHeapFragment *bp = NULL; Eterm count = make_small(0); #ifndef ERTS_SMP -#define LOCAL_HEAP_SIZE (4 + 6) +#define LOCAL_HEAP_SIZE (6 + ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); UseTmpHeapNoproc(LOCAL_HEAP_SIZE); @@ -2901,10 +3034,9 @@ profile_runnable_port(Port *p, Eterm status) { hp = local_heap; #else - ErlHeapFragment *bp; Uint hsz; - hsz = 4 + 6; + hsz = 6 + patch_ts_size(erts_system_profile_ts_type)-1; bp = new_message_buffer(hsz); hp = bp->mem; @@ -2912,9 +3044,12 @@ profile_runnable_port(Port *p, Eterm status) { erts_smp_mtx_lock(&smq_mtx); - GET_NOW(&Ms, &s, &us); - timestamp = TUPLE3(hp, make_small(Ms), make_small(s), make_small(us)); hp += 4; - msg = TUPLE5(hp, am_profile, p->common.id, status, count, timestamp); hp += 6; + msg = TUPLE5(hp, am_profile, p->common.id, status, count, + NIL /* Will be overwritten by timestamp */); + hp += 6; + + /* Write timestamp in element 5 of the 'msg' tuple */ + hp[-1] = write_ts(erts_system_profile_ts_type, hp, bp, NULL); #ifndef ERTS_SMP profile_send(p->common.id, msg); @@ -2929,20 +3064,19 @@ profile_runnable_port(Port *p, Eterm status) { /* Process profiling */ void profile_runnable_proc(Process *p, Eterm status){ - Uint Ms, s, us; - Eterm *hp, msg, timestamp; + Eterm *hp, msg; Eterm where = am_undefined; + ErlHeapFragment *bp = NULL; #ifndef ERTS_SMP -#define LOCAL_HEAP_SIZE (4 + 6 + 4) +#define LOCAL_HEAP_SIZE (4 + 6 + ERTS_TRACE_PATCH_TS_MAX_SIZE) DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); UseTmpHeapNoproc(LOCAL_HEAP_SIZE); hp = local_heap; #else - ErlHeapFragment *bp; - Uint hsz = 4 + 6 + 4; + Uint hsz = 4 + 6 + patch_ts_size(erts_system_profile_ts_type)-1; #endif if (!p->current) { @@ -2951,7 +3085,7 @@ profile_runnable_proc(Process *p, Eterm status){ #ifdef ERTS_SMP if (!p->current) { - hsz = 4 + 6; + hsz -= 4; } bp = new_message_buffer(hsz); @@ -2966,9 +3100,13 @@ profile_runnable_proc(Process *p, Eterm status){ erts_smp_mtx_lock(&smq_mtx); - GET_NOW(&Ms, &s, &us); - timestamp = TUPLE3(hp, make_small(Ms), make_small(s), make_small(us)); hp += 4; - msg = TUPLE5(hp, am_profile, p->common.id, status, where, timestamp); hp += 6; + msg = TUPLE5(hp, am_profile, p->common.id, status, where, + NIL /* Will be overwritten by timestamp */); + hp += 6; + + /* Write timestamp in element 5 of the 'msg' tuple */ + hp[-1] = write_ts(erts_system_profile_ts_type, hp, bp, NULL); + #ifndef ERTS_SMP profile_send(p->common.id, msg); UnUseTmpHeapNoproc(LOCAL_HEAP_SIZE); diff --git a/erts/emulator/beam/erl_trace.h b/erts/emulator/beam/erl_trace.h index 7405490f76..a0058264d7 100644 --- a/erts/emulator/beam/erl_trace.h +++ b/erts/emulator/beam/erl_trace.h @@ -18,8 +18,38 @@ * %CopyrightEnd% */ +#ifndef ERL_TRACE_H__FLAGS__ +#define ERL_TRACE_H__FLAGS__ +/* + * NOTE! The bits used for these flags matter. The flag with + * the least significant bit will take precedence! + * + * The "now timestamp" has highest precedence due to + * compatibility reasons. + */ +#define ERTS_TRACE_FLG_NOW_TIMESTAMP (1 << 0) +#define ERTS_TRACE_FLG_STRICT_MONOTONIC_TIMESTAMP (1 << 1) +#define ERTS_TRACE_FLG_MONOTONIC_TIMESTAMP (1 << 2) + +/* + * The bits used effects trace flags (of processes and ports) + * as well as sequential trace flags. If changed make sure + * these arn't messed up... + */ +#define ERTS_TRACE_TS_TYPE_BITS 3 +#define ERTS_TRACE_TS_TYPE_MASK \ + ((1 << ERTS_TRACE_TS_TYPE_BITS) - 1) + +#define ERTS_TFLGS2TSTYPE(TFLGS) \ + ((int) (((TFLGS) >> ERTS_TRACE_FLAGS_TS_TYPE_SHIFT) \ + & ERTS_TRACE_TS_TYPE_MASK)) +#define ERTS_SEQTFLGS2TSTYPE(SEQTFLGS) \ + ((int) (((SEQTFLGS) >> ERTS_SEQ_TRACE_FLAGS_TS_TYPE_SHIFT) \ + & ERTS_TRACE_TS_TYPE_MASK)) + +#endif /* ERL_TRACE_H__FLAGS__ */ -#ifndef ERL_TRACE_H__ +#if !defined(ERL_TRACE_H__) && !defined(ERTS_ONLY_INCLUDE_TRACE_FLAGS) #define ERL_TRACE_H__ struct binary; diff --git a/erts/emulator/beam/io.c b/erts/emulator/beam/io.c index c64c8802b9..2bd31ee97e 100644 --- a/erts/emulator/beam/io.c +++ b/erts/emulator/beam/io.c @@ -50,6 +50,7 @@ #include "erl_map.h" #include "erl_bif_unique.h" #include "erl_hl_timer.h" +#include "erl_time.h" extern ErlDrvEntry fd_driver_entry; #ifndef __OSE__ @@ -6762,6 +6763,28 @@ driver_get_now(ErlDrvNowData *now_data) return 0; } +ErlDrvTime +erl_drv_monotonic_time(ErlDrvTimeUnit time_unit) +{ + return (ErlDrvTime) erts_napi_monotonic_time((int) time_unit); +} + +ErlDrvTime +erl_drv_time_offset(ErlDrvTimeUnit time_unit) +{ + return (ErlDrvTime) erts_napi_time_offset((int) time_unit); +} + +ErlDrvTime +erl_drv_convert_time_unit(ErlDrvTime val, + ErlDrvTimeUnit from, + ErlDrvTimeUnit to) +{ + return (ErlDrvTime) erts_napi_convert_time_unit((ErtsMonotonicTime) val, + (int) from, + (int) to); +} + static void ref_to_driver_monitor(Eterm ref, ErlDrvMonitor *mon) { RefThing *refp; diff --git a/erts/emulator/beam/sys.h b/erts/emulator/beam/sys.h index ec94e3a596..03e30573de 100644 --- a/erts/emulator/beam/sys.h +++ b/erts/emulator/beam/sys.h @@ -819,6 +819,10 @@ int local_to_univ(Sint *year, Sint *month, Sint *day, void get_now(Uint*, Uint*, Uint*); struct ErtsSchedulerData_; ErtsMonotonicTime erts_get_monotonic_time(struct ErtsSchedulerData_ *); +ErtsMonotonicTime erts_get_time_offset(void); +void +erts_make_timestamp_value(Uint* megasec, Uint* sec, Uint* microsec, + ErtsMonotonicTime mtime, ErtsMonotonicTime offset); void get_sys_now(Uint*, Uint*, Uint*); void set_break_quit(void (*)(void), void (*)(void)); diff --git a/erts/emulator/drivers/common/efile_drv.c b/erts/emulator/drivers/common/efile_drv.c index 3b6abec25e..a5a5dfb7f8 100644 --- a/erts/emulator/drivers/common/efile_drv.c +++ b/erts/emulator/drivers/common/efile_drv.c @@ -1532,10 +1532,10 @@ static void invoke_writev(void *data) { * with errno. */ errno = EINVAL; - if (! (status = - erts_gzwrite((ErtsGzFile)d->fd, - iov[i].iov_base, - iov[i].iov_len)) == iov[i].iov_len) { + status = erts_gzwrite((ErtsGzFile)d->fd, + iov[i].iov_base, + iov[i].iov_len) == iov[i].iov_len; + if (! status) { d->errInfo.posix_errno = d->errInfo.os_errno = errno; /* XXX Correct? */ break; diff --git a/erts/emulator/drivers/common/inet_drv.c b/erts/emulator/drivers/common/inet_drv.c index 89011d89ad..43cb15a25f 100644 --- a/erts/emulator/drivers/common/inet_drv.c +++ b/erts/emulator/drivers/common/inet_drv.c @@ -1048,7 +1048,7 @@ typedef union { #endif typedef struct _multi_timer_data { - ErlDrvNowData when; + ErlDrvTime when; ErlDrvTermData caller; void (*timeout_function)(ErlDrvData drv_data, ErlDrvTermData caller); struct _multi_timer_data *next; @@ -12144,115 +12144,18 @@ make_noninheritable_handle(SOCKET s) * Multi-timers */ -static void absolute_timeout(unsigned millis, ErlDrvNowData *out) -{ - unsigned rest; - unsigned long millipart; - unsigned long secpart; - unsigned long megasecpart; - unsigned tmo_secs = (millis / 1000U); - unsigned tmo_millis = (millis % 1000); - driver_get_now(out); - rest = (out->microsecs) % 1000; - millipart = ((out->microsecs) / 1000UL); - if (rest >= 500) { - ++millipart; - } - secpart = out->secs; - megasecpart = out->megasecs; - millipart += tmo_millis; - secpart += (millipart / 1000000UL); - millipart %= 1000000UL; - secpart += tmo_secs; - megasecpart += (secpart / 1000000UL); - secpart %= 1000000UL; - out->megasecs = megasecpart; - out->secs = secpart; - out->microsecs = (millipart * 1000UL); -} - -static unsigned relative_timeout(ErlDrvNowData *in) -{ - ErlDrvNowData now; - unsigned rest; - unsigned long millipart, in_millis, in_secs, in_megasecs; - - driver_get_now(&now); - - in_secs = in->secs; - in_megasecs = in->megasecs; - - rest = (now.microsecs) % 1000; - millipart = ((now.microsecs) / 1000UL); - if (rest >= 500) { - ++millipart; - } - in_millis = ((in->microsecs) / 1000UL); - if ( in_millis < millipart ) { - if (in_secs > 0) { - --in_secs; - } else { - in_secs = (1000000UL - 1UL); - if (in_megasecs <= now.megasecs) { - return 0; - } else { - --in_megasecs; - } - } - in_millis += 1000UL; - } - in_millis -= millipart; - - if (in_secs < now.secs) { - if (in_megasecs <= now.megasecs) { - return 0; - } else { - --in_megasecs; - } - in_secs += 1000000; - } - in_secs -= now.secs; - if (in_megasecs < now.megasecs) { - return 0; - } else { - in_megasecs -= now.megasecs; - } - return (unsigned) ((in_megasecs * 1000000000UL) + - (in_secs * 1000UL) + - in_millis); -} - -#ifdef DEBUG -static int nowcmp(ErlDrvNowData *d1, ErlDrvNowData *d2) -{ - /* Assume it's not safe to do signed conversion on megasecs... */ - if (d1->megasecs < d2->megasecs) { - return -1; - } else if (d1->megasecs > d2->megasecs) { - return 1; - } else if (d1->secs != d2->secs) { - return ((int) d1->secs) - ((int) d2->secs); - } - return ((int) d1->microsecs) - ((int) d2->microsecs); -} -#endif - static void fire_multi_timers(MultiTimerData **first, ErlDrvPort port, ErlDrvData data) { - unsigned next_timeout; + ErlDrvTime next_timeout; if (!*first) { ASSERT(0); return; } #ifdef DEBUG { - ErlDrvNowData chk; - driver_get_now(&chk); - chk.microsecs /= 10000UL; - chk.microsecs *= 10000UL; - chk.microsecs += 10000; - ASSERT(nowcmp(&chk,&((*first)->when)) >= 0); + ErlDrvTime chk = erl_drv_monotonic_time(ERL_DRV_MSEC); + ASSERT(chk >= (*first)->when); } #endif do { @@ -12264,9 +12167,9 @@ static void fire_multi_timers(MultiTimerData **first, ErlDrvPort port, return; } (*first)->prev = NULL; - next_timeout = relative_timeout(&((*first)->when)); - } while (next_timeout == 0); - driver_set_timer(port,next_timeout); + next_timeout = (*first)->when - erl_drv_monotonic_time(ERL_DRV_MSEC); + } while (next_timeout <= 0); + driver_set_timer(port, (unsigned long) next_timeout); } static void clean_multi_timers(MultiTimerData **first, ErlDrvPort port) @@ -12289,8 +12192,10 @@ static void remove_multi_timer(MultiTimerData **first, ErlDrvPort port, MultiTim driver_cancel_timer(port); *first = p->next; if (*first) { - unsigned ntmo = relative_timeout(&((*first)->when)); - driver_set_timer(port,ntmo); + ErlDrvTime ntmo = (*first)->when - erl_drv_monotonic_time(ERL_DRV_MSEC); + if (ntmo < 0) + ntmo = 0; + driver_set_timer(port, (unsigned long) ntmo); } } if (p->next != NULL) { @@ -12304,26 +12209,14 @@ static MultiTimerData *add_multi_timer(MultiTimerData **first, ErlDrvPort port, void (*timeout_fun)(ErlDrvData drv_data, ErlDrvTermData caller)) { -#define eq_mega(a, b) ((a)->when.megasecs == (b)->when.megasecs) -#define eq_sec(a, b) ((a)->when.secs == (b)->when.secs) MultiTimerData *mtd, *p, *s; mtd = ALLOC(sizeof(MultiTimerData)); - absolute_timeout(timeout, &(mtd->when)); + mtd->when = erl_drv_monotonic_time(ERL_DRV_MSEC) + ((ErlDrvTime) timeout) + 1; mtd->timeout_function = timeout_fun; mtd->caller = caller; mtd->next = mtd->prev = NULL; for(p = *first,s = NULL; p != NULL; s = p, p = p->next) { - if (p->when.megasecs >= mtd->when.megasecs) { - break; - } - } - for (; p!= NULL && eq_mega(p, mtd); s = p, p = p->next) { - if (p->when.secs >= mtd->when.secs) { - break; - } - } - for (; p!= NULL && eq_mega(p, mtd) && eq_sec(p, mtd); s = p, p = p->next) { - if (p->when.microsecs >= mtd->when.microsecs) { + if (p->when >= mtd->when) { break; } } @@ -12353,12 +12246,6 @@ static MultiTimerData *add_multi_timer(MultiTimerData **first, ErlDrvPort port, } return mtd; } -#undef eq_mega -#undef eq_sec - - - - /*----------------------------------------------------------------------------- diff --git a/erts/emulator/drivers/unix/unix_efile.c b/erts/emulator/drivers/unix/unix_efile.c index 46eccc6568..00da48b107 100644 --- a/erts/emulator/drivers/unix/unix_efile.c +++ b/erts/emulator/drivers/unix/unix_efile.c @@ -39,6 +39,11 @@ #ifdef HAVE_SYS_UIO_H #include <sys/types.h> #include <sys/uio.h> +#if defined(HAVE_SENDFILE) && (defined(__FreeBSD__) || defined(__DragonFly__)) +/* Need to define __BSD_VISIBLE in order to expose prototype of sendfile */ +#define __BSD_VISIBLE 1 +#include <sys/socket.h> +#endif #endif #if defined(HAVE_SENDFILE) && (defined(__linux__) || (defined(__sun) && defined(__SVR4))) #include <sys/sendfile.h> diff --git a/erts/emulator/hipe/hipe_x86_signal.c b/erts/emulator/hipe/hipe_x86_signal.c index 69d4ea10c2..b7dae88417 100644 --- a/erts/emulator/hipe/hipe_x86_signal.c +++ b/erts/emulator/hipe/hipe_x86_signal.c @@ -234,7 +234,29 @@ static void do_init(void) #define INIT() do { if (!init_done()) do_init(); } while (0) #endif /* __sun__ */ -#if !(defined(__GLIBC__) || defined(__DARWIN__) || defined(__NetBSD__) || defined(__sun__)) +#if defined(__FreeBSD__) +/* + * This is a copy of Darwin code for FreeBSD. + * CAVEAT: detailed semantics are not verified yet. + */ +#include <dlfcn.h> +static int (*__next_sigaction)(int, const struct sigaction*, struct sigaction*); +#define init_done() (__next_sigaction != 0) +extern int _sigaction(int, const struct sigaction*, struct sigaction*); +#define __SIGACTION _sigaction +static void do_init(void) +{ + __next_sigaction = dlsym(RTLD_NEXT, "sigaction"); + if (__next_sigaction != 0) + return; + perror("dlsym_freebsd"); + abort(); +} +#define _NSIG NSIG +#define INIT() do { if (!init_done()) do_init(); } while (0) +#endif /* __FreeBSD__ */ + +#if !(defined(__GLIBC__) || defined(__DARWIN__) || defined(__NetBSD__) || defined(__FreeBSD__) || defined(__sun__)) /* * Unknown libc -- assume musl. Note: musl deliberately does not provide a musl-specific * feature test macro, so we cannot check for it. @@ -259,7 +281,7 @@ static void do_init(void) #define _NSIG NSIG #endif #define INIT() do { if (!init_done()) do_init(); } while (0) -#endif /* !(__GLIBC__ || __DARWIN__ || __NetBSD__ || __sun__) */ +#endif /* !(__GLIBC__ || __DARWIN__ || __NetBSD__ || __FreeBSD__ || __sun__) */ #if !defined(__NetBSD__) /* @@ -299,7 +321,7 @@ int __SIGACTION(int signum, const struct sigaction *act, struct sigaction *oldac /* * This catches the application's own sigaction() calls. */ -#if !defined(__DARWIN__) && !defined(__NetBSD__) +#if !defined(__DARWIN__) && !defined(__NetBSD__) && !defined(__FreeBSD__) int sigaction(int signum, const struct sigaction *act, struct sigaction *oldact) { return my_sigaction(signum, act, oldact); diff --git a/erts/emulator/sys/win32/erl_win_dyn_driver.h b/erts/emulator/sys/win32/erl_win_dyn_driver.h index baac7c903e..9c699fdba0 100644 --- a/erts/emulator/sys/win32/erl_win_dyn_driver.h +++ b/erts/emulator/sys/win32/erl_win_dyn_driver.h @@ -103,6 +103,11 @@ WDD_TYPEDEF(ErlDrvSInt, driver_pdl_inc_refc, (ErlDrvPDL)); WDD_TYPEDEF(ErlDrvSInt, driver_pdl_dec_refc, (ErlDrvPDL)); WDD_TYPEDEF(void, driver_system_info, (ErlDrvSysInfo *, size_t)); WDD_TYPEDEF(int, driver_get_now, (ErlDrvNowData *)); +WDD_TYPEDEF(ErlDrvTime, erl_drv_monotonic_time, (ErlDrvTimeUnit)); +WDD_TYPEDEF(ErlDrvTime, erl_drv_time_offset, (ErlDrvTimeUnit)); +WDD_TYPEDEF(ErlDrvTime, erl_drv_convert_time_unit, (ErlDrvTime, + ErlDrvTimeUnit, + ErlDrvTimeUnit)); WDD_TYPEDEF(int, driver_monitor_process, (ErlDrvPort port, ErlDrvTermData process, ErlDrvMonitor *monitor)); @@ -217,6 +222,9 @@ typedef struct { WDD_FTYPE(driver_pdl_dec_refc) *driver_pdl_dec_refc; WDD_FTYPE(driver_system_info) *driver_system_info; WDD_FTYPE(driver_get_now) *driver_get_now; + WDD_FTYPE(erl_drv_monotonic_time) *erl_drv_monotonic_time; + WDD_FTYPE(erl_drv_time_offset) *erl_drv_time_offset; + WDD_FTYPE(erl_drv_convert_time_unit) *erl_drv_convert_time_unit; WDD_FTYPE(driver_monitor_process) *driver_monitor_process; WDD_FTYPE(driver_demonitor_process) *driver_demonitor_process; WDD_FTYPE(driver_get_monitored_process) *driver_get_monitored_process; @@ -328,6 +336,9 @@ extern TWinDynDriverCallbacks WinDynDriverCallbacks; #define driver_pdl_dec_refc (WinDynDriverCallbacks.driver_pdl_dec_refc) #define driver_system_info (WinDynDriverCallbacks.driver_system_info) #define driver_get_now (WinDynDriverCallbacks.driver_get_now) +#define erl_drv_monotonic_time (WinDynDriverCallbacks.erl_drv_monotonic_time) +#define erl_drv_time_offset (WinDynDriverCallbacks.erl_drv_time_offset) +#define erl_drv_convert_time_unit (WinDynDriverCallbacks.erl_drv_convert_time_unit) #define driver_monitor_process \ (WinDynDriverCallbacks.driver_monitor_process) #define driver_demonitor_process \ @@ -463,6 +474,9 @@ do { \ ((W).driver_pdl_dec_refc) = driver_pdl_dec_refc; \ ((W).driver_system_info) = driver_system_info; \ ((W).driver_get_now) = driver_get_now; \ +((W).erl_drv_monotonic_time) = erl_drv_monotonic_time; \ +((W).erl_drv_time_offset) = erl_drv_time_offset; \ +((W).erl_drv_convert_time_unit) = erl_drv_convert_time_unit; \ ((W).driver_monitor_process) = driver_monitor_process; \ ((W).driver_demonitor_process) = driver_demonitor_process; \ ((W).driver_get_monitored_process) = driver_get_monitored_process; \ diff --git a/erts/emulator/test/alloc_SUITE_data/threads.c b/erts/emulator/test/alloc_SUITE_data/threads.c index a8a6a23695..2f5f841e3d 100644 --- a/erts/emulator/test/alloc_SUITE_data/threads.c +++ b/erts/emulator/test/alloc_SUITE_data/threads.c @@ -396,7 +396,7 @@ alloc_op(int t_no, Allctr_t *a, block *bp, int id, int clean_up) bp->p = (unsigned char *) ALLOC(a, bp->s); if(!bp->p) fail(t_no, "ALLOC(%lu) failed [id=%d])\n", bp->s, id); - memset((void *) bp->p, id, (size_t) bp->s); + memset((void *) bp->p, (unsigned char)id, (size_t) bp->s); } else { unsigned char *p = (unsigned char *) REALLOC(a, bp->p, bp->as[bp->i]); @@ -406,7 +406,7 @@ alloc_op(int t_no, Allctr_t *a, block *bp, int id, int clean_up) if(bp->s < bp->as[bp->i]) { CHECK_BLOCK_DATA(t_no, p, bp->s, id); - memset((void *) p, id, (size_t) bp->as[bp->i]); + memset((void *) p, (unsigned char)id, (size_t) bp->as[bp->i]); } else CHECK_BLOCK_DATA(t_no, p, bp->as[bp->i], id); diff --git a/erts/emulator/test/nif_SUITE.erl b/erts/emulator/test/nif_SUITE.erl index af2b955184..3d478654b1 100644 --- a/erts/emulator/test/nif_SUITE.erl +++ b/erts/emulator/test/nif_SUITE.erl @@ -42,7 +42,8 @@ otp_9668/1, consume_timeslice/1, dirty_nif/1, dirty_nif_send/1, dirty_nif_exception/1, call_dirty_nif_exception/1, nif_schedule/1, nif_exception/1, call_nif_exception/1, - nif_nan_and_inf/1, nif_atom_too_long/1 + nif_nan_and_inf/1, nif_atom_too_long/1, + nif_monotonic_time/1, nif_time_offset/1, nif_convert_time_unit/1 ]). -export([many_args_100/100]). @@ -72,7 +73,8 @@ all() -> otp_9828, otp_9668, consume_timeslice, nif_schedule, dirty_nif, dirty_nif_send, dirty_nif_exception, - nif_exception, nif_nan_and_inf, nif_atom_too_long + nif_exception, nif_nan_and_inf, nif_atom_too_long, + nif_monotonic_time, nif_time_offset, nif_convert_time_unit ]. groups() -> @@ -1783,6 +1785,148 @@ nif_raise_exceptions(NifFunc) -> end end, ok, ExcTerms). +-define(ERL_NIF_TIME_ERROR, -9223372036854775808). +-define(TIME_UNITS, [seconds, milli_seconds, micro_seconds, nano_seconds]). + +nif_monotonic_time(Config) -> + ?ERL_NIF_TIME_ERROR = monotonic_time(invalid_time_unit), + mtime_loop(1000000). + +mtime_loop(0) -> + ok; +mtime_loop(N) -> + chk_mtime(?TIME_UNITS), + mtime_loop(N-1). + +chk_mtime([]) -> + ok; +chk_mtime([TU|TUs]) -> + A = erlang:monotonic_time(TU), + B = monotonic_time(TU), + C = erlang:monotonic_time(TU), + try + true = A =< B, + true = B =< C + catch + _ : _ -> + ?t:fail({monotonic_time_missmatch, TU, A, B, C}) + end, + chk_mtime(TUs). + +nif_time_offset(Config) -> + ?ERL_NIF_TIME_ERROR = time_offset(invalid_time_unit), + toffs_loop(1000000). + +toffs_loop(0) -> + ok; +toffs_loop(N) -> + chk_toffs(?TIME_UNITS), + toffs_loop(N-1). + +chk_toffs([]) -> + ok; +chk_toffs([TU|TUs]) -> + TO = erlang:time_offset(TU), + NifTO = time_offset(TU), + case TO =:= NifTO of + true -> + ok; + false -> + case erlang:system_info(time_warp_mode) of + no_time_warp -> + ?t:fail({time_offset_mismatch, TU, TO, NifTO}); + _ -> + %% Most frequent time offset change + %% is currently only every 15:th + %% second so this should currently + %% work... + NTO = erlang:time_offset(TU), + case NifTO =:= NTO of + true -> + ok; + false -> + ?t:fail({time_offset_mismatch, TU, TO, NifTO, NTO}) + end + end + end, + chk_toffs(TUs). + +nif_convert_time_unit(Config) -> + ?ERL_NIF_TIME_ERROR = convert_time_unit(0, seconds, invalid_time_unit), + ?ERL_NIF_TIME_ERROR = convert_time_unit(0, invalid_time_unit, seconds), + ?ERL_NIF_TIME_ERROR = convert_time_unit(0, invalid_time_unit, invalid_time_unit), + lists:foreach(fun (Offset) -> + lists:foreach(fun (Diff) -> + chk_ctu(Diff+(Offset*1000*1000*1000)) + end, + [999999999999, + 99999999999, + 9999999999, + 999999999, + 99999999, + 9999999, + 999999, + 99999, + 999, + 99, + 9, + 1, + 11, + 101, + 1001, + 10001, + 100001, + 1000001, + 10000001, + 100000001, + 1000000001, + 100000000001, + 1000000000001, + 5, + 50, + 500, + 5000, + 50000, + 500000, + 5000000, + 50000000, + 500000000, + 5000000000, + 50000000000, + 500000000000]) + end, + [-4711, -1000, -475, -5, -4, -3, -2, -1, 0, + 1, 2, 3, 4, 5, 475, 1000, 4711]), + ctu_loop(1000000). + +ctu_loop(0) -> + ok; +ctu_loop(N) -> + chk_ctu(erlang:monotonic_time(nano_seconds)), + ctu_loop(N-1). + +chk_ctu(Time) -> + chk_ctu(Time, ?TIME_UNITS). + +chk_ctu(_Time, []) -> + ok; +chk_ctu(Time, [FromTU|FromTUs]) -> + chk_ctu(Time, FromTU, ?TIME_UNITS), + chk_ctu(Time, FromTUs). + +chk_ctu(_Time, _FromTU, []) -> + ok; +chk_ctu(Time, FromTU, [ToTU|ToTUs]) -> + T = erlang:convert_time_unit(Time, nano_seconds, FromTU), + TE = erlang:convert_time_unit(T, FromTU, ToTU), + TN = convert_time_unit(T, FromTU, ToTU), + case TE =:= TN of + false -> + ?t:fail({conversion_mismatch, FromTU, T, ToTU, TE, TN}); + true -> + chk_ctu(Time, FromTU, ToTUs) + end. + %% The NIFs: lib_version() -> undefined. call_history() -> ?nif_stub. @@ -1852,6 +1996,11 @@ make_map_remove_nif(_,_) -> ?nif_stub. maps_from_list_nif(_) -> ?nif_stub. sorted_list_from_maps_nif(_) -> ?nif_stub. +%% Time +monotonic_time(_) -> ?nif_stub. +time_offset(_) -> ?nif_stub. +convert_time_unit(_,_,_) -> ?nif_stub. + nif_stub_error(Line) -> exit({nif_not_loaded,module,?MODULE,line,Line}). diff --git a/erts/emulator/test/nif_SUITE_data/nif_SUITE.c b/erts/emulator/test/nif_SUITE_data/nif_SUITE.c index 98e1efe18f..8ebce4fef4 100644 --- a/erts/emulator/test/nif_SUITE_data/nif_SUITE.c +++ b/erts/emulator/test/nif_SUITE_data/nif_SUITE.c @@ -34,6 +34,10 @@ static ERL_NIF_TERM atom_self; static ERL_NIF_TERM atom_ok; static ERL_NIF_TERM atom_join; static ERL_NIF_TERM atom_binary_resource_type; +static ERL_NIF_TERM atom_seconds; +static ERL_NIF_TERM atom_milli_seconds; +static ERL_NIF_TERM atom_micro_seconds; +static ERL_NIF_TERM atom_nano_seconds; typedef struct @@ -138,6 +142,10 @@ static int load(ErlNifEnv* env, void** priv_data, ERL_NIF_TERM load_info) atom_ok = enif_make_atom(env,"ok"); atom_join = enif_make_atom(env,"join"); atom_binary_resource_type = enif_make_atom(env,"binary_resource_type"); + atom_seconds = enif_make_atom(env,"seconds"); + atom_milli_seconds = enif_make_atom(env,"milli_seconds"); + atom_micro_seconds = enif_make_atom(env,"micro_seconds"); + atom_nano_seconds = enif_make_atom(env,"nano_seconds"); *priv_data = data; return 0; @@ -1885,6 +1893,87 @@ static ERL_NIF_TERM sorted_list_from_maps_nif(ErlNifEnv* env, int argc, const ER return enif_make_tuple2(env, list_f, list_b); } + +static ERL_NIF_TERM monotonic_time(ErlNifEnv* env, int argc, const ERL_NIF_TERM argv[]) +{ + ErlNifTimeUnit time_unit; + + if (argc != 1) + return atom_false; + + if (enif_compare(argv[0], atom_seconds) == 0) + time_unit = ERL_NIF_SEC; + else if (enif_compare(argv[0], atom_milli_seconds) == 0) + time_unit = ERL_NIF_MSEC; + else if (enif_compare(argv[0], atom_micro_seconds) == 0) + time_unit = ERL_NIF_USEC; + else if (enif_compare(argv[0], atom_nano_seconds) == 0) + time_unit = ERL_NIF_NSEC; + else + time_unit = 4711; /* invalid time unit */ + + return enif_make_int64(env, enif_monotonic_time(time_unit)); +} + +static ERL_NIF_TERM time_offset(ErlNifEnv* env, int argc, const ERL_NIF_TERM argv[]) +{ + ErlNifTimeUnit time_unit; + + if (argc != 1) + return atom_false; + + if (enif_compare(argv[0], atom_seconds) == 0) + time_unit = ERL_NIF_SEC; + else if (enif_compare(argv[0], atom_milli_seconds) == 0) + time_unit = ERL_NIF_MSEC; + else if (enif_compare(argv[0], atom_micro_seconds) == 0) + time_unit = ERL_NIF_USEC; + else if (enif_compare(argv[0], atom_nano_seconds) == 0) + time_unit = ERL_NIF_NSEC; + else + time_unit = 4711; /* invalid time unit */ + return enif_make_int64(env, enif_time_offset(time_unit)); +} + +static ERL_NIF_TERM convert_time_unit(ErlNifEnv* env, int argc, const ERL_NIF_TERM argv[]) +{ + ErlNifSInt64 i64; + ErlNifTime val; + ErlNifTimeUnit from, to; + + if (argc != 3) + return atom_false; + + if (!enif_get_int64(env, argv[0], &i64)) + return enif_make_badarg(env); + + val = (ErlNifTime) i64; + + if (enif_compare(argv[1], atom_seconds) == 0) + from = ERL_NIF_SEC; + else if (enif_compare(argv[1], atom_milli_seconds) == 0) + from = ERL_NIF_MSEC; + else if (enif_compare(argv[1], atom_micro_seconds) == 0) + from = ERL_NIF_USEC; + else if (enif_compare(argv[1], atom_nano_seconds) == 0) + from = ERL_NIF_NSEC; + else + from = 4711; /* invalid time unit */ + + if (enif_compare(argv[2], atom_seconds) == 0) + to = ERL_NIF_SEC; + else if (enif_compare(argv[2], atom_milli_seconds) == 0) + to = ERL_NIF_MSEC; + else if (enif_compare(argv[2], atom_micro_seconds) == 0) + to = ERL_NIF_USEC; + else if (enif_compare(argv[2], atom_nano_seconds) == 0) + to = ERL_NIF_NSEC; + else + to = 4711; /* invalid time unit */ + + return enif_make_int64(env, enif_convert_time_unit(val, from, to)); +} + static ErlNifFunc nif_funcs[] = { {"lib_version", 0, lib_version}, @@ -1954,7 +2043,10 @@ static ErlNifFunc nif_funcs[] = {"make_map_update_nif", 3, make_map_update_nif}, {"make_map_remove_nif", 2, make_map_remove_nif}, {"maps_from_list_nif", 1, maps_from_list_nif}, - {"sorted_list_from_maps_nif", 1, sorted_list_from_maps_nif} + {"sorted_list_from_maps_nif", 1, sorted_list_from_maps_nif}, + {"monotonic_time", 1, monotonic_time}, + {"time_offset", 1, time_offset}, + {"convert_time_unit", 3, convert_time_unit} }; ERL_NIF_INIT(nif_SUITE,nif_funcs,load,reload,upgrade,unload) diff --git a/erts/emulator/test/system_profile_SUITE.erl b/erts/emulator/test/system_profile_SUITE.erl index e4b6511d1f..2ecb4a28a7 100644 --- a/erts/emulator/test/system_profile_SUITE.erl +++ b/erts/emulator/test/system_profile_SUITE.erl @@ -113,13 +113,27 @@ runnable_procs(suite) -> runnable_procs(doc) -> ["Tests system_profiling with runnable_procs."]; runnable_procs(Config) when is_list(Config) -> + lists:foreach(fun (TsType) -> + Arg = case TsType of + no_timestamp -> + {timestamp, []}; + _ -> + {TsType, [TsType]} + end, + do_runnable_procs(Arg), + receive after 1000 -> ok end + end, + [no_timestamp, timestamp, monotonic_timestamp, + strict_monotonic_timestamp]). + +do_runnable_procs({TsType, TsTypeFlag}) -> Pid = start_profiler_process(), % start a ring of processes % FIXME: Set #laps and #nodes in config file Nodes = 10, Laps = 10, Master = ring(Nodes), - undefined = erlang:system_profile(Pid, [runnable_procs]), + undefined = erlang:system_profile(Pid, [runnable_procs]++TsTypeFlag), % loop a message ok = ring_message(Master, message, Laps), Events = get_profiler_events(), @@ -127,9 +141,9 @@ runnable_procs(Config) when is_list(Config) -> erlang:system_profile(undefined, []), put(master, Master), put(laps, Laps), - true = has_runnable_event(Events), + true = has_runnable_event(TsType, Events), Pids = sort_events_by_pid(Events), - ok = check_events(Pids), + ok = check_events(TsType, Pids), erase(), exit(Pid,kill), ok. @@ -139,8 +153,22 @@ runnable_ports(suite) -> runnable_ports(doc) -> ["Tests system_profiling with runnable_port."]; runnable_ports(Config) when is_list(Config) -> + lists:foreach(fun (TsType) -> + Arg = case TsType of + no_timestamp -> + {timestamp, []}; + _ -> + {TsType, [TsType]} + end, + do_runnable_ports(Arg, Config), + receive after 1000 -> ok end + end, + [no_timestamp, timestamp, monotonic_timestamp, + strict_monotonic_timestamp]). + +do_runnable_ports({TsType, TsTypeFlag}, Config) -> Pid = start_profiler_process(), - undefined = erlang:system_profile(Pid, [runnable_ports]), + undefined = erlang:system_profile(Pid, [runnable_ports]++TsTypeFlag), EchoPid = echo(Config), % FIXME: Set config to number_of_echos Laps = 10, @@ -149,9 +177,9 @@ runnable_ports(Config) when is_list(Config) -> Events = get_profiler_events(), kill_em_all = kill_echo(EchoPid), erlang:system_profile(undefined, []), - true = has_runnable_event(Events), + true = has_runnable_event(TsType, Events), Pids = sort_events_by_pid(Events), - ok = check_events(Pids), + ok = check_events(TsType, Pids), erase(), exit(Pid,kill), ok. @@ -166,8 +194,19 @@ scheduler(Config) when is_list(Config) -> {_, 1} -> {skipped, "No need for scheduler test when only one scheduler online."}; _ -> Nodes = 10, - ok = check_block_system(Nodes), - ok = check_multi_scheduling_block(Nodes) + lists:foreach(fun (TsType) -> + Arg = case TsType of + no_timestamp -> + {timestamp, []}; + _ -> + {TsType, [TsType]} + end, + ok = check_block_system(Arg, Nodes), + ok = check_multi_scheduling_block(Arg, Nodes), + receive after 1000 -> ok end + end, + [no_timestamp, timestamp, monotonic_timestamp, + strict_monotonic_timestamp]) end. % the profiler pid should not be profiled @@ -195,9 +234,9 @@ dont_profile_profiler(Config) when is_list(Config) -> %%% Check scheduler profiling -check_multi_scheduling_block(Nodes) -> +check_multi_scheduling_block({TsType, TsTypeFlag}, Nodes) -> Pid = start_profiler_process(), - undefined = erlang:system_profile(Pid, [scheduler]), + undefined = erlang:system_profile(Pid, [scheduler]++TsTypeFlag), {ok, Supervisor} = start_load(Nodes), wait(600), erlang:system_flag(multi_scheduling, block), @@ -205,23 +244,23 @@ check_multi_scheduling_block(Nodes) -> erlang:system_flag(multi_scheduling, unblock), {Pid, [scheduler]} = erlang:system_profile(undefined, []), Events = get_profiler_events(), - true = has_scheduler_event(Events), + true = has_scheduler_event(TsType, Events), stop_load(Supervisor), exit(Pid,kill), erase(), ok. -check_block_system(Nodes) -> +check_block_system({TsType, TsTypeFlag}, Nodes) -> Dummy = spawn(?MODULE, profiler_process, [[]]), Pid = start_profiler_process(), - undefined = erlang:system_profile(Pid, [scheduler]), + undefined = erlang:system_profile(Pid, [scheduler]++TsTypeFlag), {ok, Supervisor} = start_load(Nodes), wait(300), undefined = erlang:system_monitor(Dummy, [busy_port]), {Dummy, [busy_port]} = erlang:system_monitor(undefined, []), {Pid, [scheduler]} = erlang:system_profile(undefined, []), Events = get_profiler_events(), - true = has_scheduler_event(Events), + true = has_scheduler_event(TsType, Events), stop_load(Supervisor), exit(Pid,kill), exit(Dummy,kill), @@ -230,40 +269,49 @@ check_block_system(Nodes) -> %%% Check events -check_events([]) -> ok; -check_events([Pid | Pids]) -> +check_events(_TsType, []) -> ok; +check_events(TsType, [Pid | Pids]) -> Master = get(master), Laps = get(laps), CheckPids = get(pids), {Events, N} = get_pid_events(Pid), ok = check_event_flow(Events), - ok = check_event_ts(Events), + ok = check_event_ts(TsType, Events), IsMember = lists:member(Pid, CheckPids), case Pid of Master -> io:format("Expected ~p and got ~p profile events from ~p: ok~n", [Laps*2+2, N, Pid]), N = Laps*2 + 2, - check_events(Pids); + check_events(TsType, Pids); Pid when IsMember == true -> io:format("Expected ~p and got ~p profile events from ~p: ok~n", [Laps*2, N, Pid]), N = Laps*2, - check_events(Pids); + check_events(TsType, Pids); Pid -> - check_events(Pids) + check_events(TsType, Pids) end. %% timestamp consistency check for descending timestamps -check_event_ts(Events) -> - check_event_ts(Events, undefined). -check_event_ts([], _) -> ok; -check_event_ts([Event | Events], undefined) -> - check_event_ts(Events, Event); -check_event_ts([{Pid, _, _, TS1}=Event | Events], {Pid,_,_,TS0}) -> - Time = timer:now_diff(TS1, TS0), +check_event_ts(TsType, Events) -> + check_event_ts(TsType, Events, undefined). +check_event_ts(_TsType, [], _) -> ok; +check_event_ts(TsType, [Event | Events], undefined) -> + check_event_ts(TsType, Events, Event); +check_event_ts(TsType, [{Pid, _, _, TS1}=Event | Events], {Pid,_,_,TS0}) -> + Time = case TsType of + timestamp -> + timer:now_diff(TS1, TS0); + monotonic_timestamp -> + TS1 - TS0; + strict_monotonic_timestamp -> + {MT1, _} = TS1, + {MT0, _} = TS0, + MT1 - MT0 + end, if Time < 0.0 -> timestamp_error; - true -> check_event_ts(Events, Event) + true -> check_event_ts(TsType, Events, Event) end. %% consistency check for active vs. inactive activity (runnable) @@ -428,6 +476,44 @@ port_echo_loop(Port) -> %% Helpers %%% +check_ts(no_timestamp, Ts) -> + try + no_timestamp = Ts + catch + _ : _ -> + ?t:fail({unexpected_timestamp, Ts}) + end, + ok; +check_ts(timestamp, Ts) -> + try + {Ms,S,Us} = Ts, + true = is_integer(Ms), + true = is_integer(S), + true = is_integer(Us) + catch + _ : _ -> + ?t:fail({unexpected_timestamp, Ts}) + end, + ok; +check_ts(monotonic_timestamp, Ts) -> + try + true = is_integer(Ts) + catch + _ : _ -> + ?t:fail({unexpected_timestamp, Ts}) + end, + ok; +check_ts(strict_monotonic_timestamp, Ts) -> + try + {MT, UMI} = Ts, + true = is_integer(MT), + true = is_integer(UMI) + catch + _ : _ -> + ?t:fail({unexpected_timestamp, Ts}) + end, + ok. + start_load(N) -> Pid = spawn_link(?MODULE, run_load, [N, []]), {ok, Pid}. @@ -454,21 +540,24 @@ list_load() -> end, list_load(). - -has_scheduler_event(Events) -> +has_scheduler_event(TsType, Events) -> lists:any( fun (Pred) -> case Pred of - {profile, scheduler, _ID, _Activity, _NR, _TS} -> true; + {profile, scheduler, _ID, _Activity, _NR, TS} -> + check_ts(TsType, TS), + true; _ -> false end end, Events). -has_runnable_event(Events) -> +has_runnable_event(TsType, Events) -> lists:any( fun (Pred) -> case Pred of - {profile, _Pid, _Activity, _MFA, _TS} -> true; + {profile, _Pid, _Activity, _MFA, TS} -> + check_ts(TsType, TS), + true; _ -> false end end, Events). diff --git a/erts/emulator/test/time_SUITE.erl b/erts/emulator/test/time_SUITE.erl index 33076c7461..787870588d 100644 --- a/erts/emulator/test/time_SUITE.erl +++ b/erts/emulator/test/time_SUITE.erl @@ -320,7 +320,41 @@ timestamp(suite) -> timestamp(doc) -> ["Test that os:timestamp works."]; timestamp(Config) when is_list(Config) -> - repeating_timestamp_check(100000). + try + repeating_timestamp_check(100000) + catch + throw : {fail, Failure} -> + %% + %% Our time warping test machines currently warps + %% time every 6:th second. If we get a warp during + %% 10 seconds, assume this is a time warping test + %% and ignore the failure. + %% + case had_time_warp(10) of + true -> + {skip, "Seems to be time warp test run..."}; + false -> + test_server:fail(Failure) + end + end. + +os_system_time_offset() -> + erlang:convert_time_unit(os:system_time() - erlang:monotonic_time(), + native, micro_seconds). + +had_time_warp(Secs) -> + had_time_warp(os_system_time_offset(), Secs). + +had_time_warp(OrigOffs, 0) -> + false; +had_time_warp(OrigOffs, N) -> + receive after 1000 -> ok end, + case OrigOffs - os_system_time_offset() of + Diff when Diff > 500000; Diff < -500000 -> + true; + _Diff -> + had_time_warp(OrigOffs, N-1) + end. repeating_timestamp_check(0) -> ok; @@ -346,15 +380,15 @@ repeating_timestamp_check(N) -> NSecs = NA*1000000+NB+round(NC/1000000), case Secs - NSecs of TooLarge when TooLarge > 3600 -> - test_server:fail( - lists:flatten( + throw({fail, + lists:flatten( io_lib:format("os:timestamp/0 is ~w s more than erlang:now/0", - [TooLarge]))); + [TooLarge]))}); TooSmall when TooSmall < -3600 -> - test_server:fail( + throw({fail, lists:flatten( io_lib:format("os:timestamp/0 is ~w s less than erlang:now/0", - [-TooSmall]))); + [-TooSmall]))}); _ -> ok end, diff --git a/erts/emulator/test/trace_bif_SUITE.erl b/erts/emulator/test/trace_bif_SUITE.erl index a12c41a3aa..760666d077 100644 --- a/erts/emulator/test/trace_bif_SUITE.erl +++ b/erts/emulator/test/trace_bif_SUITE.erl @@ -67,7 +67,8 @@ trace_on_and_off(Config) when is_list(Config) -> ?line Pid = spawn(?MODULE, bif_process, []), ?line Self = self(), ?line 1 = erlang:trace(Pid, true, [call,timestamp]), - ?line {flags,[timestamp,call]} = erlang:trace_info(Pid,flags), + ?line {flags, Flags} = erlang:trace_info(Pid,flags), + ?line [call,timestamp] = lists:sort(Flags), ?line {tracer, Self} = erlang:trace_info(Pid,tracer), ?line 1 = erlang:trace(Pid, false, [timestamp]), ?line {flags,[call]} = erlang:trace_info(Pid,flags), @@ -111,93 +112,145 @@ do_trace_bif(Flags) -> trace_bif_timestamp(doc) -> "Test tracing BIFs with timestamps."; trace_bif_timestamp(Config) when is_list(Config) -> - do_trace_bif_timestamp([]). - + do_trace_bif_timestamp([], timestamp, [timestamp]), + do_trace_bif_timestamp([], timestamp, + [timestamp, + monotonic_timestamp, + strict_monotonic_timestamp]), + do_trace_bif_timestamp([], strict_monotonic_timestamp, + [strict_monotonic_timestamp]), + do_trace_bif_timestamp([], strict_monotonic_timestamp, + [monotonic_timestamp, strict_monotonic_timestamp]), + do_trace_bif_timestamp([], monotonic_timestamp, [monotonic_timestamp]). + trace_bif_timestamp_local(doc) -> "Test tracing BIFs with timestamps and local flag."; trace_bif_timestamp_local(Config) when is_list(Config) -> - do_trace_bif_timestamp([local]). - -do_trace_bif_timestamp(Flags) -> - ?line Pid=spawn(?MODULE, bif_process, []), - ?line 1 = erlang:trace(Pid, true, [call,timestamp]), - ?line erlang:trace_pattern({erlang,'_','_'}, [], Flags), - - ?line Pid ! {do_bif, time, []}, - ?line receive_trace_msg_ts({trace_ts,Pid,call,{erlang,time,[]}}), - - ?line Pid ! {do_bif, statistics, [runtime]}, - ?line receive_trace_msg_ts({trace_ts,Pid,call, - {erlang,statistics, [runtime]}}), - - ?line Pid ! {do_time_bif}, - ?line receive_trace_msg_ts({trace_ts,Pid,call, - {erlang,time, []}}), - - ?line Pid ! {do_statistics_bif}, - ?line receive_trace_msg_ts({trace_ts,Pid,call, - {erlang,statistics, [runtime]}}), + do_trace_bif_timestamp([local], timestamp, [timestamp]), + do_trace_bif_timestamp([local], timestamp, + [timestamp, + monotonic_timestamp, + strict_monotonic_timestamp]), + do_trace_bif_timestamp([local], strict_monotonic_timestamp, + [strict_monotonic_timestamp]), + do_trace_bif_timestamp([local], strict_monotonic_timestamp, + [monotonic_timestamp, strict_monotonic_timestamp]), + do_trace_bif_timestamp([local], monotonic_timestamp, [monotonic_timestamp]). + +do_trace_bif_timestamp(Flags, TsType, TsFlags) -> + io:format("Testing with TsType=~p TsFlags=~p~n", [TsType, TsFlags]), + Pid=spawn(?MODULE, bif_process, []), + 1 = erlang:trace(Pid, true, [call]++TsFlags), + erlang:trace_pattern({erlang,'_','_'}, [], Flags), + + Ts0 = make_ts(TsType), + Pid ! {do_bif, time, []}, + Ts1 = receive_trace_msg_ts({trace_ts,Pid,call,{erlang,time,[]}}, + Ts0,TsType), + + Pid ! {do_bif, statistics, [runtime]}, + Ts2 = receive_trace_msg_ts({trace_ts,Pid,call, + {erlang,statistics, [runtime]}}, + Ts1, TsType), + + Pid ! {do_time_bif}, + Ts3 = receive_trace_msg_ts({trace_ts,Pid,call, + {erlang,time, []}}, + Ts2, TsType), + + Pid ! {do_statistics_bif}, + Ts4 = receive_trace_msg_ts({trace_ts,Pid,call, + {erlang,statistics, [runtime]}}, + Ts3, TsType), + + check_ts(TsType, Ts4, make_ts(TsType)), %% We should be able to turn off the timestamp. - ?line 1 = erlang:trace(Pid, false, [timestamp]), + 1 = erlang:trace(Pid, false, TsFlags), - ?line Pid ! {do_statistics_bif}, - ?line receive_trace_msg({trace,Pid,call, - {erlang,statistics, [runtime]}}), + Pid ! {do_statistics_bif}, + receive_trace_msg({trace,Pid,call, + {erlang,statistics, [runtime]}}), - ?line Pid ! {do_bif, statistics, [runtime]}, - ?line receive_trace_msg({trace,Pid,call, - {erlang,statistics, [runtime]}}), + Pid ! {do_bif, statistics, [runtime]}, + receive_trace_msg({trace,Pid,call, + {erlang,statistics, [runtime]}}), - ?line 1 = erlang:trace(Pid, false, [call]), - ?line erlang:trace_pattern({erlang,'_','_'}, false, Flags), + 1 = erlang:trace(Pid, false, [call]), + erlang:trace_pattern({erlang,'_','_'}, false, Flags), - ?line exit(Pid, die), + exit(Pid, die), ok. trace_bif_return(doc) -> "Test tracing BIF's with return/return_to trace."; trace_bif_return(Config) when is_list(Config) -> - ?line Pid=spawn(?MODULE, bif_process, []), - ?line 1 = erlang:trace(Pid, true, [call,timestamp,return_to]), - ?line erlang:trace_pattern({erlang,'_','_'}, [{'_',[],[{return_trace}]}], - [local]), - - - ?line Pid ! {do_bif, time, []}, - ?line receive_trace_msg_ts({trace_ts,Pid,call,{erlang,time,[]}}), - ?line receive_trace_msg_ts_return_from({trace_ts,Pid,return_from, - {erlang,time,0}}), - ?line receive_trace_msg_ts_return_to({trace_ts,Pid,return_to, - {?MODULE, bif_process,0}}), - - - ?line Pid ! {do_bif, statistics, [runtime]}, - ?line receive_trace_msg_ts({trace_ts,Pid,call, - {erlang,statistics, [runtime]}}), - ?line receive_trace_msg_ts_return_from({trace_ts,Pid,return_from, - {erlang,statistics,1}}), - ?line receive_trace_msg_ts_return_to({trace_ts,Pid,return_to, - {?MODULE, bif_process,0}}), - - - ?line Pid ! {do_time_bif}, - ?line receive_trace_msg_ts({trace_ts,Pid,call, - {erlang,time, []}}), - ?line receive_trace_msg_ts_return_from({trace_ts,Pid,return_from, - {erlang,time,0}}), - ?line receive_trace_msg_ts_return_to({trace_ts,Pid,return_to, - {?MODULE, bif_process,0}}), - - - - ?line Pid ! {do_statistics_bif}, - ?line receive_trace_msg_ts({trace_ts,Pid,call, - {erlang,statistics, [runtime]}}), - ?line receive_trace_msg_ts_return_from({trace_ts,Pid,return_from, - {erlang,statistics,1}}), - ?line receive_trace_msg_ts_return_to({trace_ts,Pid,return_to, - {?MODULE, bif_process,0}}), + do_trace_bif_return(timestamp, [timestamp]), + do_trace_bif_return(timestamp, + [timestamp, + monotonic_timestamp, + strict_monotonic_timestamp]), + do_trace_bif_return(strict_monotonic_timestamp, + [strict_monotonic_timestamp]), + do_trace_bif_return(strict_monotonic_timestamp, + [monotonic_timestamp, strict_monotonic_timestamp]), + do_trace_bif_return(monotonic_timestamp, [monotonic_timestamp]). + +do_trace_bif_return(TsType, TsFlags) -> + io:format("Testing with TsType=~p TsFlags=~p~n", [TsType, TsFlags]), + Pid=spawn(?MODULE, bif_process, []), + 1 = erlang:trace(Pid, true, [call,return_to]++TsFlags), + erlang:trace_pattern({erlang,'_','_'}, [{'_',[],[{return_trace}]}], + [local]), + + Ts0 = make_ts(TsType), + Pid ! {do_bif, time, []}, + Ts1 = receive_trace_msg_ts({trace_ts,Pid,call,{erlang,time,[]}}, + Ts0, TsType), + Ts2 = receive_trace_msg_ts_return_from({trace_ts,Pid,return_from, + {erlang,time,0}}, + Ts1, TsType), + Ts3 = receive_trace_msg_ts_return_to({trace_ts,Pid,return_to, + {?MODULE, bif_process,0}}, + Ts2, TsType), + + + Pid ! {do_bif, statistics, [runtime]}, + Ts4 = receive_trace_msg_ts({trace_ts,Pid,call, + {erlang,statistics, [runtime]}}, + Ts3, TsType), + Ts5 = receive_trace_msg_ts_return_from({trace_ts,Pid,return_from, + {erlang,statistics,1}}, + Ts4, TsType), + Ts6 = receive_trace_msg_ts_return_to({trace_ts,Pid,return_to, + {?MODULE, bif_process,0}}, + Ts5, TsType), + + + Pid ! {do_time_bif}, + Ts7 = receive_trace_msg_ts({trace_ts,Pid,call, + {erlang,time, []}}, + Ts6, TsType), + Ts8 = receive_trace_msg_ts_return_from({trace_ts,Pid,return_from, + {erlang,time,0}}, + Ts7, TsType), + Ts9 = receive_trace_msg_ts_return_to({trace_ts,Pid,return_to, + {?MODULE, bif_process,0}}, + Ts8, TsType), + + + + Pid ! {do_statistics_bif}, + Ts10 = receive_trace_msg_ts({trace_ts,Pid,call, + {erlang,statistics, [runtime]}}, + Ts9, TsType), + Ts11 = receive_trace_msg_ts_return_from({trace_ts,Pid,return_from, + {erlang,statistics,1}}, + Ts10, TsType), + Ts12 = receive_trace_msg_ts_return_to({trace_ts,Pid,return_to, + {?MODULE, bif_process,0}}, + Ts11, TsType), + check_ts(TsType, Ts12, make_ts(TsType)), ok. @@ -213,10 +266,11 @@ receive_trace_msg(Mess) -> ?t:fail() end. -receive_trace_msg_ts({trace_ts, Pid, call, {erlang,F,A}}) -> +receive_trace_msg_ts({trace_ts, Pid, call, {erlang,F,A}}, PrevTs, TsType) -> receive - {trace_ts, Pid, call, {erlang, F, A}, _Ts} -> - ok; + {trace_ts, Pid, call, {erlang, F, A}, Ts} -> + check_ts(TsType, PrevTs, Ts), + Ts; Other -> io:format("Expected: {trace, ~p, call, {~p, ~p, ~p}, TimeStamp}},~n" "Got: ~p~n", @@ -227,10 +281,11 @@ receive_trace_msg_ts({trace_ts, Pid, call, {erlang,F,A}}) -> ?t:fail() end. -receive_trace_msg_ts_return_from({trace_ts, Pid, return_from, {erlang,F,A}}) -> +receive_trace_msg_ts_return_from({trace_ts, Pid, return_from, {erlang,F,A}}, PrevTs, TsType) -> receive - {trace_ts, Pid, return_from, {erlang, F, A}, _Value, _Ts} -> - ok; + {trace_ts, Pid, return_from, {erlang, F, A}, _Value, Ts} -> + check_ts(TsType, PrevTs, Ts), + Ts; Other -> io:format("Expected: {trace_ts, ~p, return_from, {~p, ~p, ~p}, Value, TimeStamp}},~n" "Got: ~p~n", @@ -241,10 +296,11 @@ receive_trace_msg_ts_return_from({trace_ts, Pid, return_from, {erlang,F,A}}) -> ?t:fail() end. -receive_trace_msg_ts_return_to({trace_ts, Pid, return_to, {M,F,A}}) -> +receive_trace_msg_ts_return_to({trace_ts, Pid, return_to, {M,F,A}}, PrevTs, TsType) -> receive - {trace_ts, Pid, return_to, {M, F, A}, _Ts} -> - ok; + {trace_ts, Pid, return_to, {M, F, A}, Ts} -> + check_ts(TsType, PrevTs, Ts), + Ts; Other -> io:format("Expected: {trace_ts, ~p, return_to, {~p, ~p, ~p}, TimeStamp}},~n" "Got: ~p~n", @@ -255,6 +311,33 @@ receive_trace_msg_ts_return_to({trace_ts, Pid, return_to, {M,F,A}}) -> ?t:fail() end. +make_ts(timestamp) -> + erlang:now(); +make_ts(monotonic_timestamp) -> + erlang:monotonic_time(); +make_ts(strict_monotonic_timestamp) -> + MT = erlang:monotonic_time(), + UMI = erlang:unique_integer([monotonic]), + {MT, UMI}. + +check_ts(timestamp, PrevTs, Ts) -> + {Ms, S, Us} = Ts, + true = is_integer(Ms), + true = is_integer(S), + true = is_integer(Us), + true = PrevTs < Ts, + Ts; +check_ts(monotonic_timestamp, PrevTs, Ts) -> + true = is_integer(Ts), + true = PrevTs =< Ts, + Ts; +check_ts(strict_monotonic_timestamp, PrevTs, Ts) -> + {MT, UMI} = Ts, + true = is_integer(MT), + true = is_integer(UMI), + true = PrevTs < Ts, + Ts. + bif_process() -> receive {do_bif, Name, Args} -> |