aboutsummaryrefslogtreecommitdiffstats
path: root/erts/emulator/test
diff options
context:
space:
mode:
authorRickard Green <[email protected]>2016-02-02 10:17:05 +0100
committerRickard Green <[email protected]>2016-02-02 10:17:05 +0100
commit178cff0a09223da707ca8472a71dbe4125466493 (patch)
treedf849d4a871940a13ae53e28e6de25a030f54ffb /erts/emulator/test
parent5dac3400b00e499cb7c436b6b71c510c718d92cf (diff)
parent3f33428db9aea0d767295322c4e882a5c6bbf7db (diff)
downloadotp-178cff0a09223da707ca8472a71dbe4125466493.tar.gz
otp-178cff0a09223da707ca8472a71dbe4125466493.tar.bz2
otp-178cff0a09223da707ca8472a71dbe4125466493.zip
Merge branch 'rickard/monotonic-time-improvements/OTP-13222' into maint
* rickard/monotonic-time-improvements/OTP-13222: Introduce time management in native APIs Introduce time warp safe replacement for safe_fixed option Introduce time warp safe trace timestamp formats
Diffstat (limited to 'erts/emulator/test')
-rw-r--r--erts/emulator/test/nif_SUITE.erl153
-rw-r--r--erts/emulator/test/nif_SUITE_data/nif_SUITE.c94
-rw-r--r--erts/emulator/test/system_profile_SUITE.erl155
-rw-r--r--erts/emulator/test/trace_bif_SUITE.erl249
4 files changed, 532 insertions, 119 deletions
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/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} ->