Introduce time warp safe trace timestamp formats

New timestamp options for trace, sequential trace, and
system profile:
- monotonic_timestamp
- strict_monotonic_timestamp

2 files changed, 288 insertions, 116 deletions

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} ->