diff options
Diffstat (limited to 'lib/kernel/test/seq_trace_SUITE.erl')
| -rw-r--r-- | lib/kernel/test/seq_trace_SUITE.erl | 604 |
1 files changed, 343 insertions, 261 deletions
diff --git a/lib/kernel/test/seq_trace_SUITE.erl b/lib/kernel/test/seq_trace_SUITE.erl index 47eeb4df4c..be23a1933f 100644 --- a/lib/kernel/test/seq_trace_SUITE.erl +++ b/lib/kernel/test/seq_trace_SUITE.erl @@ -1,18 +1,19 @@ %% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 1998-2011. All Rights Reserved. +%% Copyright Ericsson AB 1998-2016. All Rights Reserved. %% -%% The contents of this file are subject to the Erlang Public License, -%% Version 1.1, (the "License"); you may not use this file except in -%% compliance with the License. You should have received a copy of the -%% Erlang Public License along with this software. If not, it can be -%% retrieved online at http://www.erlang.org/. +%% Licensed under the Apache License, Version 2.0 (the "License"); +%% you may not use this file except in compliance with the License. +%% You may obtain a copy of the License at %% -%% Software distributed under the License is distributed on an "AS IS" -%% basis, WITHOUT WARRANTY OF ANY KIND, either express or implied. See -%% the License for the specific language governing rights and limitations -%% under the License. +%% http://www.apache.org/licenses/LICENSE-2.0 +%% +%% Unless required by applicable law or agreed to in writing, software +%% distributed under the License is distributed on an "AS IS" BASIS, +%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +%% See the License for the specific language governing permissions and +%% limitations under the License. %% %% %CopyrightEnd% %% @@ -26,17 +27,21 @@ trace_exit/1, distributed_exit/1, call/1, port/1, match_set_seq_token/1, gc_seq_token/1]). -% internal exports +%% internal exports -export([simple_tracer/2, one_time_receiver/0, one_time_receiver/1, start_tracer/0, stop_tracer/1, do_match_set_seq_token/1, do_gc_seq_token/1, countdown_start/2]). - %-define(line_trace, 1). --include_lib("test_server/include/test_server.hrl"). +-include_lib("common_test/include/ct.hrl"). --define(default_timeout, ?t:minutes(1)). +-define(TIMESTAMP_MODES, [no_timestamp, + timestamp, + monotonic_timestamp, + strict_monotonic_timestamp]). -suite() -> [{ct_hooks,[ts_install_cth]}]. +suite() -> + [{ct_hooks,[ts_install_cth]}, + {timetrap,{minutes,1}}]. all() -> [token_set_get, tracer_set_get, print, send, @@ -61,343 +66,373 @@ end_per_group(_GroupName, Config) -> init_per_testcase(_Case, Config) -> - ?line Dog = test_server:timetrap(?default_timeout), - [{watchdog, Dog}|Config]. + Config. -end_per_testcase(_Case, Config) -> - Dog=?config(watchdog, Config), - test_server:timetrap_cancel(Dog), +end_per_testcase(_Case, _Config) -> ok. %% Verifies that the set_token and get_token functions work as expected -token_set_get(doc) -> []; -token_set_get(suite) -> []; token_set_get(Config) when is_list(Config) -> - ?line Self = self(), - ?line seq_trace:reset_trace(), + do_token_set_get(timestamp), + do_token_set_get(monotonic_timestamp), + do_token_set_get(strict_monotonic_timestamp). + +do_token_set_get(TsType) -> + io:format("Testing ~p~n", [TsType]), + Flags = case TsType of + timestamp -> 15; + strict_monotonic_timestamp -> 23; + monotonic_timestamp -> 39 + end, + Self = self(), + seq_trace:reset_trace(), %% Test that initial seq_trace is disabled - ?line [] = seq_trace:get_token(), + [] = seq_trace:get_token(), %% Test setting and reading the different fields - ?line 0 = seq_trace:set_token(label,17), - ?line {label,17} = seq_trace:get_token(label), - ?line false = seq_trace:set_token(print,true), - ?line {print,true} = seq_trace:get_token(print), - ?line false = seq_trace:set_token(send,true), - ?line {send,true} = seq_trace:get_token(send), - ?line false = seq_trace:set_token('receive',true), - ?line {'receive',true} = seq_trace:get_token('receive'), - ?line false = seq_trace:set_token(timestamp,true), - ?line {timestamp,true} = seq_trace:get_token(timestamp), + 0 = seq_trace:set_token(label,17), + {label,17} = seq_trace:get_token(label), + false = seq_trace:set_token(print,true), + {print,true} = seq_trace:get_token(print), + false = seq_trace:set_token(send,true), + {send,true} = seq_trace:get_token(send), + false = seq_trace:set_token('receive',true), + {'receive',true} = seq_trace:get_token('receive'), + false = seq_trace:set_token(TsType,true), + {TsType,true} = seq_trace:get_token(TsType), %% Check the whole token - ?line {15,17,0,Self,0} = seq_trace:get_token(), % all flags are set + {Flags,17,0,Self,0} = seq_trace:get_token(), % all flags are set %% Test setting and reading the 'serial' field - ?line {0,0} = seq_trace:set_token(serial,{3,5}), - ?line {serial,{3,5}} = seq_trace:get_token(serial), + {0,0} = seq_trace:set_token(serial,{3,5}), + {serial,{3,5}} = seq_trace:get_token(serial), %% Check the whole token, test that a whole token can be set and get - ?line {15,17,5,Self,3} = seq_trace:get_token(), - ?line seq_trace:set_token({15,19,7,Self,5}), - ?line {15,19,7,Self,5} = seq_trace:get_token(), + {Flags,17,5,Self,3} = seq_trace:get_token(), + seq_trace:set_token({Flags,19,7,Self,5}), + {Flags,19,7,Self,5} = seq_trace:get_token(), %% Check that receive timeout does not reset token - ?line receive after 0 -> ok end, - ?line {15,19,7,Self,5} = seq_trace:get_token(), + receive after 0 -> ok end, + {Flags,19,7,Self,5} = seq_trace:get_token(), %% Check that token can be unset - ?line {15,19,7,Self,5} = seq_trace:set_token([]), - ?line [] = seq_trace:get_token(), + {Flags,19,7,Self,5} = seq_trace:set_token([]), + [] = seq_trace:get_token(), %% Check that Previous serial counter survived unset token - ?line 0 = seq_trace:set_token(label, 17), - ?line {0,17,0,Self,5} = seq_trace:get_token(), + 0 = seq_trace:set_token(label, 17), + {0,17,0,Self,5} = seq_trace:get_token(), %% Check that reset_trace resets the token and clears %% the Previous serial counter - ?line seq_trace:reset_trace(), - ?line [] = seq_trace:get_token(), - ?line 0 = seq_trace:set_token(label, 19), - ?line {0,19,0,Self,0} = seq_trace:get_token(), + seq_trace:reset_trace(), + [] = seq_trace:get_token(), + 0 = seq_trace:set_token(label, 19), + {0,19,0,Self,0} = seq_trace:get_token(), %% Cleanup - ?line seq_trace:reset_trace(), + seq_trace:reset_trace(), ok. -tracer_set_get(doc) -> []; -tracer_set_get(suite) -> []; tracer_set_get(Config) when is_list(Config) -> - ?line Self = self(), - ?line seq_trace:set_system_tracer(self()), - ?line Self = seq_trace:get_system_tracer(), - ?line Self = seq_trace:set_system_tracer(false), - ?line false = seq_trace:get_system_tracer(), + Self = self(), + seq_trace:set_system_tracer(self()), + Self = seq_trace:get_system_tracer(), + Self = seq_trace:set_system_tracer(false), + false = seq_trace:get_system_tracer(), %% Set the system tracer to a port. - ?line Port = load_tracer(Config), - ?line seq_trace:set_system_tracer(Port), - ?line Port = seq_trace:get_system_tracer(), - ?line Port = seq_trace:set_system_tracer(false), - ?line false = seq_trace:get_system_tracer(), + Port = load_tracer(Config), + seq_trace:set_system_tracer(Port), + Port = seq_trace:get_system_tracer(), + Port = seq_trace:set_system_tracer(false), + false = seq_trace:get_system_tracer(), ok. -print(doc) -> []; -print(suite) -> []; print(Config) when is_list(Config) -> - ?line start_tracer(), - ?line seq_trace:set_token(print,true), - ?line seq_trace:print(0,print1), - ?line seq_trace:print(1,print2), - ?line seq_trace:print(print3), - ?line seq_trace:reset_trace(), - ?line [{0,{print,_,_,[],print1}}, - {0,{print,_,_,[],print3}}] = stop_tracer(2). + lists:foreach(fun do_print/1, ?TIMESTAMP_MODES). + +do_print(TsType) -> + start_tracer(), + set_token_flags([print, TsType]), + seq_trace:print(0,print1), + seq_trace:print(1,print2), + seq_trace:print(print3), + seq_trace:reset_trace(), + [{0,{print,_,_,[],print1}, Ts0}, + {0,{print,_,_,[],print3}, Ts1}] = stop_tracer(2), + check_ts(TsType, Ts0), + check_ts(TsType, Ts1). -send(doc) -> []; -send(suite) -> []; send(Config) when is_list(Config) -> - ?line seq_trace:reset_trace(), - ?line start_tracer(), - ?line Receiver = spawn(?MODULE,one_time_receiver,[]), - ?line seq_trace:set_token(send,true), - ?line Receiver ! send, - ?line Self = self(), - ?line seq_trace:reset_trace(), - ?line [{0,{send,_,Self,Receiver,send}}] = stop_tracer(1). - -distributed_send(doc) -> []; -distributed_send(suite) -> []; + lists:foreach(fun do_send/1, ?TIMESTAMP_MODES). + +do_send(TsType) -> + seq_trace:reset_trace(), + start_tracer(), + Receiver = spawn(?MODULE,one_time_receiver,[]), + set_token_flags([send, TsType]), + Receiver ! send, + Self = self(), + seq_trace:reset_trace(), + [{0,{send,_,Self,Receiver,send}, Ts}] = stop_tracer(1), + check_ts(TsType, Ts). + distributed_send(Config) when is_list(Config) -> - ?line {ok,Node} = start_node(seq_trace_other,[]), - ?line {_,Dir} = code:is_loaded(?MODULE), - ?line Mdir = filename:dirname(Dir), - ?line true = rpc:call(Node,code,add_patha,[Mdir]), - ?line seq_trace:reset_trace(), - ?line start_tracer(), - ?line Receiver = spawn(Node,?MODULE,one_time_receiver,[]), - ?line seq_trace:set_token(send,true), - ?line Receiver ! send, - ?line Self = self(), - ?line seq_trace:reset_trace(), - ?line stop_node(Node), - ?line [{0,{send,_,Self,Receiver,send}}] = stop_tracer(1). - -recv(doc) -> []; -recv(suite) -> []; + lists:foreach(fun do_distributed_send/1, ?TIMESTAMP_MODES). + +do_distributed_send(TsType) -> + {ok,Node} = start_node(seq_trace_other,[]), + {_,Dir} = code:is_loaded(?MODULE), + Mdir = filename:dirname(Dir), + true = rpc:call(Node,code,add_patha,[Mdir]), + seq_trace:reset_trace(), + start_tracer(), + Receiver = spawn(Node,?MODULE,one_time_receiver,[]), + set_token_flags([send,TsType]), + Receiver ! send, + Self = self(), + seq_trace:reset_trace(), + stop_node(Node), + [{0,{send,_,Self,Receiver,send}, Ts}] = stop_tracer(1), + check_ts(TsType, Ts). + + recv(Config) when is_list(Config) -> - ?line seq_trace:reset_trace(), - ?line start_tracer(), - ?line Receiver = spawn(?MODULE,one_time_receiver,[]), - ?line seq_trace:set_token('receive',true), - ?line Receiver ! 'receive', + lists:foreach(fun do_recv/1, ?TIMESTAMP_MODES). + +do_recv(TsType) -> + seq_trace:reset_trace(), + start_tracer(), + Receiver = spawn(?MODULE,one_time_receiver,[]), + set_token_flags(['receive',TsType]), + Receiver ! 'receive', %% let the other process receive the message: - ?line receive after 1 -> ok end, - ?line Self = self(), - ?line seq_trace:reset_trace(), - ?line [{0,{'receive',_,Self,Receiver,'receive'}}] = stop_tracer(1). + receive after 1 -> ok end, + Self = self(), + seq_trace:reset_trace(), + [{0,{'receive',_,Self,Receiver,'receive'}, Ts}] = stop_tracer(1), + check_ts(TsType, Ts). -distributed_recv(doc) -> []; -distributed_recv(suite) -> []; distributed_recv(Config) when is_list(Config) -> - ?line {ok,Node} = start_node(seq_trace_other,[]), - ?line {_,Dir} = code:is_loaded(?MODULE), - ?line Mdir = filename:dirname(Dir), - ?line true = rpc:call(Node,code,add_patha,[Mdir]), - ?line seq_trace:reset_trace(), - ?line rpc:call(Node,?MODULE,start_tracer,[]), - ?line Receiver = spawn(Node,?MODULE,one_time_receiver,[]), - ?line seq_trace:set_token('receive',true), - ?line Receiver ! 'receive', + lists:foreach(fun do_distributed_recv/1, ?TIMESTAMP_MODES). + +do_distributed_recv(TsType) -> + {ok,Node} = start_node(seq_trace_other,[]), + {_,Dir} = code:is_loaded(?MODULE), + Mdir = filename:dirname(Dir), + true = rpc:call(Node,code,add_patha,[Mdir]), + seq_trace:reset_trace(), + rpc:call(Node,?MODULE,start_tracer,[]), + Receiver = spawn(Node,?MODULE,one_time_receiver,[]), + set_token_flags(['receive',TsType]), + Receiver ! 'receive', %% let the other process receive the message: - ?line receive after 1 -> ok end, - ?line Self = self(), - ?line seq_trace:reset_trace(), - ?line Result = rpc:call(Node,?MODULE,stop_tracer,[1]), - ?line stop_node(Node), - ?line ok = io:format("~p~n",[Result]), - ?line [{0,{'receive',_,Self,Receiver,'receive'}}] = Result. - -trace_exit(doc) -> []; -trace_exit(suite) -> []; + receive after 1 -> ok end, + Self = self(), + seq_trace:reset_trace(), + Result = rpc:call(Node,?MODULE,stop_tracer,[1]), + stop_node(Node), + ok = io:format("~p~n",[Result]), + [{0,{'receive',_,Self,Receiver,'receive'}, Ts}] = Result, + check_ts(TsType, Ts). + trace_exit(Config) when is_list(Config) -> - ?line seq_trace:reset_trace(), - ?line start_tracer(), - ?line Receiver = spawn_link(?MODULE, one_time_receiver, [exit]), - ?line process_flag(trap_exit, true), - ?line seq_trace:set_token(send,true), - ?line Receiver ! {before, exit}, + lists:foreach(fun do_trace_exit/1, ?TIMESTAMP_MODES). + +do_trace_exit(TsType) -> + seq_trace:reset_trace(), + start_tracer(), + Receiver = spawn_link(?MODULE, one_time_receiver, [exit]), + process_flag(trap_exit, true), + set_token_flags([send, TsType]), + Receiver ! {before, exit}, %% let the other process receive the message: - ?line receive + receive {'EXIT', Receiver, {exit, {before, exit}}} -> seq_trace:set_token([]); Other -> seq_trace:set_token([]), - ?t:fail({received, Other}) + ct:fail({received, Other}) end, - ?line Self = self(), - ?line Result = stop_tracer(2), - ?line seq_trace:reset_trace(), - ?line ok = io:format("~p~n", [Result]), - ?line [{0, {send, {0,1}, Self, Receiver, {before, exit}}}, + Self = self(), + Result = stop_tracer(2), + seq_trace:reset_trace(), + ok = io:format("~p~n", [Result]), + [{0, {send, {0,1}, Self, Receiver, {before, exit}}, Ts0}, {0, {send, {1,2}, Receiver, Self, - {'EXIT', Receiver, {exit, {before, exit}}}}}] = Result. + {'EXIT', Receiver, {exit, {before, exit}}}}, Ts1}] = Result, + check_ts(TsType, Ts0), + check_ts(TsType, Ts1). -distributed_exit(doc) -> []; -distributed_exit(suite) -> []; distributed_exit(Config) when is_list(Config) -> - ?line {ok, Node} = start_node(seq_trace_other, []), - ?line {_, Dir} = code:is_loaded(?MODULE), - ?line Mdir = filename:dirname(Dir), - ?line true = rpc:call(Node, code, add_patha, [Mdir]), - ?line seq_trace:reset_trace(), - ?line rpc:call(Node, ?MODULE, start_tracer,[]), - ?line Receiver = spawn_link(Node, ?MODULE, one_time_receiver, [exit]), - ?line process_flag(trap_exit, true), - ?line seq_trace:set_token(send, true), - ?line Receiver ! {before, exit}, + lists:foreach(fun do_distributed_exit/1, ?TIMESTAMP_MODES). + +do_distributed_exit(TsType) -> + {ok, Node} = start_node(seq_trace_other, []), + {_, Dir} = code:is_loaded(?MODULE), + Mdir = filename:dirname(Dir), + true = rpc:call(Node, code, add_patha, [Mdir]), + seq_trace:reset_trace(), + rpc:call(Node, ?MODULE, start_tracer,[]), + Receiver = spawn_link(Node, ?MODULE, one_time_receiver, [exit]), + process_flag(trap_exit, true), + set_token_flags([send, TsType]), + Receiver ! {before, exit}, %% let the other process receive the message: - ?line receive + receive {'EXIT', Receiver, {exit, {before, exit}}} -> seq_trace:set_token([]); Other -> seq_trace:set_token([]), - ?t:fail({received, Other}) + ct:fail({received, Other}) end, - ?line Self = self(), - ?line Result = rpc:call(Node, ?MODULE, stop_tracer, [1]), - ?line seq_trace:reset_trace(), - ?line stop_node(Node), - ?line ok = io:format("~p~n", [Result]), - ?line [{0, {send, {1, 2}, Receiver, Self, - {'EXIT', Receiver, {exit, {before, exit}}}}}] = Result. + Self = self(), + Result = rpc:call(Node, ?MODULE, stop_tracer, [1]), + seq_trace:reset_trace(), + stop_node(Node), + ok = io:format("~p~n", [Result]), + [{0, {send, {1, 2}, Receiver, Self, + {'EXIT', Receiver, {exit, {before, exit}}}}, Ts}] = Result, + check_ts(TsType, Ts). call(doc) -> "Tests special forms {is_seq_trace} and {get_seq_token} " "in trace match specs."; -call(suite) -> - []; call(Config) when is_list(Config) -> - ?line Self = self(), - ?line seq_trace:reset_trace(), - ?line TrA = transparent_tracer(), - ?line 1 = + Self = self(), + seq_trace:reset_trace(), + TrA = transparent_tracer(), + 1 = erlang:trace(Self, true, [call, set_on_spawn, {tracer, TrA(pid)}]), - ?line 1 = + 1 = erlang:trace_pattern({?MODULE, call_tracee_1, 1}, [{'_', [], [{message, {{{self}, {get_seq_token}}}}]}], [local]), - ?line 1 = + 1 = erlang:trace_pattern({?MODULE, call_tracee_2, 1}, [{'_', [{is_seq_trace}], [{message, {{{self}, {get_seq_token}}}}]}], [local]), - ?line RefA = make_ref(), - ?line Pid2A = spawn_link( + RefA = make_ref(), + Pid2A = spawn_link( fun() -> receive {_, msg, RefA} -> ok end, RefA = call_tracee_2(RefA), Self ! {self(), msg, RefA} end), - ?line Pid1A = spawn_link( + Pid1A = spawn_link( fun() -> receive {_, msg, RefA} -> ok end, RefA = call_tracee_1(RefA), Pid2A ! {self(), msg, RefA} end), - ?line Pid1A ! {Self, msg, RefA}, + Pid1A ! {Self, msg, RefA}, %% The message is passed Self -> Pid1B -> Pid2B -> Self. %% Traced functions are called in Pid1B and Pid2B. - ?line receive {Pid2A, msg, RefA} -> ok end, + receive {Pid2A, msg, RefA} -> ok end, %% Only call_tracee1 will be traced since the guard for %% call_tracee2 requires a sequential trace. The trace %% token is undefined. - ?line Token2A = [], - ?line {ok, [{trace, Pid1A, call, + Token2A = [], + {ok, [{trace, Pid1A, call, {?MODULE, call_tracee_1, [RefA]}, {Pid1A, Token2A}}]} = TrA({stop, 1}), - ?line seq_trace:reset_trace(), + seq_trace:reset_trace(), - ?line TrB = transparent_tracer(), - ?line 1 = + TrB = transparent_tracer(), + 1 = erlang:trace(Self, true, [call, set_on_spawn, {tracer, TrB(pid)}]), - ?line Label = 17, - ?line seq_trace:set_token(label, Label), % Token enters here!! - ?line RefB = make_ref(), - ?line Pid2B = spawn_link( + Label = 17, + seq_trace:set_token(label, Label), % Token enters here!! + RefB = make_ref(), + Pid2B = spawn_link( fun() -> receive {_, msg, RefB} -> ok end, RefB = call_tracee_2(RefB), Self ! {self(), msg, RefB} end), - ?line Pid1B = spawn_link( + Pid1B = spawn_link( fun() -> receive {_, msg, RefB} -> ok end, RefB = call_tracee_1(RefB), Pid2B ! {self(), msg, RefB} end), - ?line Pid1B ! {Self, msg, RefB}, + Pid1B ! {Self, msg, RefB}, %% The message is passed Self -> Pid1B -> Pid2B -> Self, and the %% seq_trace token follows invisibly. Traced functions are %% called in Pid1B and Pid2B. Seq_trace flags == 0 so no %% seq_trace messages are generated. - ?line receive {Pid2B, msg, RefB} -> ok end, + receive {Pid2B, msg, RefB} -> ok end, %% The values of these counters {.., 1, _, 0}, {.., 2, _, 1} %% depend on that seq_trace has been reset just before this test. - ?line Token1B = {0, Label, 1, Self, 0}, - ?line Token2B = {0, Label, 2, Pid1B, 1}, - ?line {ok, [{trace, Pid1B, call, + Token1B = {0, Label, 1, Self, 0}, + Token2B = {0, Label, 2, Pid1B, 1}, + {ok, [{trace, Pid1B, call, {?MODULE, call_tracee_1, [RefB]}, {Pid1B, Token1B}}, {trace, Pid2B, call, {?MODULE, call_tracee_2, [RefB]}, {Pid2B, Token2B}}]} = TrB({stop,2}), - ?line seq_trace:reset_trace(), + seq_trace:reset_trace(), ok. -port(doc) -> - "Send trace messages to a port."; -port(suite) -> []; +%% Send trace messages to a port. port(Config) when is_list(Config) -> - ?line Port = load_tracer(Config), - ?line seq_trace:set_system_tracer(Port), - - ?line seq_trace:set_token(print, true), - ?line Small = [small,term], - ?line seq_trace:print(0, Small), - ?line case get_port_message(Port) of - {seq_trace,0,{print,_,_,[],Small}} -> + lists:foreach(fun (TsType) -> do_port(TsType, Config) end, + ?TIMESTAMP_MODES). + +do_port(TsType, Config) -> + io:format("Testing ~p~n",[TsType]), + Port = load_tracer(Config), + seq_trace:set_system_tracer(Port), + + set_token_flags([print, TsType]), + Small = [small,term], + seq_trace:print(0, Small), + case get_port_message(Port) of + {seq_trace,0,{print,_,_,[],Small}} when TsType == no_timestamp -> + ok; + {seq_trace,0,{print,_,_,[],Small},Ts0} when TsType /= no_timestamp -> + check_ts(TsType, Ts0), ok; Other -> - ?line seq_trace:reset_trace(), - ?line ?t:fail({unexpected,Other}) + seq_trace:reset_trace(), + ct:fail({unexpected,Other}) end, %% OTP-4218 Messages from ports should not affect seq trace token. %% %% Check if trace token still is active on this process after %% the get_port_message/1 above that receives from a port. - ?line OtherSmall = [other | Small], - ?line seq_trace:print(0, OtherSmall), - ?line seq_trace:reset_trace(), - ?line case get_port_message(Port) of - {seq_trace,0,{print,_,_,[],OtherSmall}} -> + OtherSmall = [other | Small], + seq_trace:print(0, OtherSmall), + seq_trace:reset_trace(), + case get_port_message(Port) of + {seq_trace,0,{print,_,_,[],OtherSmall}} when TsType == no_timestamp -> + ok; + {seq_trace,0,{print,_,_,[],OtherSmall}, Ts1} when TsType /= no_timestamp -> + check_ts(TsType, Ts1), ok; Other1 -> - ?line ?t:fail({unexpected,Other1}) + ct:fail({unexpected,Other1}) end, - ?line seq_trace:set_token(print, true), - ?line Huge = huge_data(), - ?line seq_trace:print(0, Huge), - ?line seq_trace:reset_trace(), - ?line case get_port_message(Port) of + seq_trace:set_token(print, true), + Huge = huge_data(), + seq_trace:print(0, Huge), + seq_trace:reset_trace(), + case get_port_message(Port) of {seq_trace,0,{print,_,_,[],Huge}} -> ok; Other2 -> - ?line ?t:fail({unexpected,Other2}) + ct:fail({unexpected,Other2}) end, + unlink(Port), + exit(Port,kill), ok. get_port_message(Port) -> @@ -405,21 +440,19 @@ get_port_message(Port) -> {Port,{data,Bin}} when is_binary(Bin) -> binary_to_term(Bin); Other -> - ?t:fail({unexpected,Other}) + ct:fail({unexpected,Other}) after 5000 -> - ?t:fail(timeout) + ct:fail(timeout) end. -match_set_seq_token(suite) -> - []; match_set_seq_token(doc) -> ["Tests that match spec function set_seq_token does not " "corrupt the heap"]; match_set_seq_token(Config) when is_list(Config) -> - ?line Parent = self(), - ?line Timetrap = test_server:timetrap(test_server:seconds(20)), + Parent = self(), + %% OTP-4222 Match spec 'set_seq_token' corrupts heap %% %% This test crashes the emulator if the bug in question is present, @@ -427,13 +460,13 @@ match_set_seq_token(Config) when is_list(Config) -> %% %% All the timeout stuff is here to get decent accuracy of the error %% return value, instead of just 'timeout'. - % - ?line {ok, Sandbox} = start_node(seq_trace_other, []), - ?line true = rpc:call(Sandbox, code, add_patha, + %% + {ok, Sandbox} = start_node(seq_trace_other, []), + true = rpc:call(Sandbox, code, add_patha, [filename:dirname(code:which(?MODULE))]), - ?line Lbl = 4711, + Lbl = 4711, %% Do the possibly crashing test - ?line P1 = + P1 = spawn( fun () -> Parent ! {self(), @@ -441,16 +474,16 @@ match_set_seq_token(Config) when is_list(Config) -> ?MODULE, do_match_set_seq_token, [Lbl])} end), %% Probe the node with a simple rpc request, to see if it is alive. - ?line P2 = + P2 = spawn( fun () -> receive after 4000 -> ok end, Parent ! {self(), rpc:call(Sandbox, erlang, abs, [-1])} end), %% If the test node hangs completely, this timer expires. - ?line R3 = erlang:start_timer(8000, self(), void), + R3 = erlang:start_timer(8000, self(), void), %% - ?line {ok, Log} = + {ok, Log} = receive {P1, Result} -> exit(P2, done), @@ -465,10 +498,15 @@ match_set_seq_token(Config) when is_list(Config) -> exit(P2, timeout), {error, "Test node hung"} end, - ?line ok = check_match_set_seq_token_log(Lbl, Log), + + %% Sort the log on Pid, as events from different processes + %% are not guaranteed to arrive in a certain order to the + %% tracer + SortedLog = lists:keysort(2, Log), + + ok = check_match_set_seq_token_log(Lbl, SortedLog), %% - ?line stop_node(Sandbox), - ?line test_server:timetrap_cancel(Timetrap), + stop_node(Sandbox), ok. %% OTP-4222 Match spec 'set_seq_token' corrupts heap @@ -519,13 +557,13 @@ do_match_set_seq_token(Label) -> check_match_set_seq_token_log( Label, - [{trace,C,call,{?MODULE,countdown,[B,Ref]}, {0,Label,0,C,0}}, + [{trace,B,call,{?MODULE,bounce, [Ref]}, {0,Label,2,B,1}}, + {trace,B,call,{?MODULE,bounce, [Ref]}, {0,Label,4,B,3}}, + {trace,B,call,{?MODULE,bounce, [Ref]}, {0,Label,6,B,5}}, + {trace,C,call,{?MODULE,countdown,[B,Ref]}, {0,Label,0,C,0}}, {trace,C,call,{?MODULE,countdown,[B,Ref,3]},{0,Label,0,C,0}}, - {trace,B,call,{?MODULE,bounce, [Ref]}, {0,Label,2,B,1}}, {trace,C,call,{?MODULE,countdown,[B,Ref,2]},{0,Label,2,B,1}}, - {trace,B,call,{?MODULE,bounce, [Ref]}, {0,Label,4,B,3}}, {trace,C,call,{?MODULE,countdown,[B,Ref,1]},{0,Label,4,B,3}}, - {trace,B,call,{?MODULE,bounce, [Ref]}, {0,Label,6,B,5}}, {trace,C,call,{?MODULE,countdown,[B,Ref,0]},{0,Label,6,B,5}} ]) -> ok; @@ -560,14 +598,12 @@ bounce(Ref) -> -gc_seq_token(suite) -> - []; gc_seq_token(doc) -> ["Tests that a seq_trace token on a message in the inqueue ", "can be garbage collected."]; gc_seq_token(Config) when is_list(Config) -> - ?line Parent = self(), - ?line Timetrap = test_server:timetrap(test_server:seconds(20)), + Parent = self(), + %% OTP-4555 Seq trace token causes free mem read in gc %% %% This test crashes the emulator if the bug in question is present, @@ -575,13 +611,13 @@ gc_seq_token(Config) when is_list(Config) -> %% %% All the timeout stuff is here to get decent accuracy of the error %% return value, instead of just 'timeout'. - % - ?line {ok, Sandbox} = start_node(seq_trace_other, []), - ?line true = rpc:call(Sandbox, code, add_patha, + %% + {ok, Sandbox} = start_node(seq_trace_other, []), + true = rpc:call(Sandbox, code, add_patha, [filename:dirname(code:which(?MODULE))]), - ?line Label = 4711, + Label = 4711, %% Do the possibly crashing test - ?line P1 = + P1 = spawn( fun () -> Parent ! {self(), @@ -589,16 +625,16 @@ gc_seq_token(Config) when is_list(Config) -> ?MODULE, do_gc_seq_token, [Label])} end), %% Probe the node with a simple rpc request, to see if it is alive. - ?line P2 = + P2 = spawn( fun () -> receive after 4000 -> ok end, Parent ! {self(), rpc:call(Sandbox, erlang, abs, [-1])} end), %% If the test node hangs completely, this timer expires. - ?line R3 = erlang:start_timer(8000, self(), void), + R3 = erlang:start_timer(8000, self(), void), %% - ?line ok = + ok = receive {P1, Result} -> exit(P2, done), @@ -614,8 +650,7 @@ gc_seq_token(Config) when is_list(Config) -> {error, "Test node hung"} end, %% - ?line stop_node(Sandbox), - ?line test_server:timetrap_cancel(Timetrap), + stop_node(Sandbox), ok. do_gc_seq_token(Label) -> @@ -733,7 +768,7 @@ simple_tracer(Data, DN) -> {seq_trace,Label,Info,Ts} -> simple_tracer([{Label,Info,Ts}|Data], DN+1); {seq_trace,Label,Info} -> - simple_tracer([{Label,Info}|Data], DN+1); + simple_tracer([{Label,Info, no_timestamp}|Data], DN+1); {stop,N,From} when DN >= N -> From ! {tracerlog,lists:reverse(Data)} end. @@ -758,8 +793,55 @@ start_tracer() -> seq_trace:set_system_tracer(Pid), Pid. - - +set_token_flags([]) -> + ok; +set_token_flags([no_timestamp|Flags]) -> + seq_trace:set_token(timestamp, false), + seq_trace:set_token(monotonic_timestamp, false), + seq_trace:set_token(strict_monotonic_timestamp, false), + set_token_flags(Flags); +set_token_flags([Flag|Flags]) -> + seq_trace:set_token(Flag, true), + set_token_flags(Flags). + +check_ts(no_timestamp, Ts) -> + try + no_timestamp = Ts + catch + _ : _ -> + ct: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 + _ : _ -> + ct:fail({unexpected_timestamp, Ts}) + end, + ok; +check_ts(monotonic_timestamp, Ts) -> + try + true = is_integer(Ts) + catch + _ : _ -> + ct: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 + _ : _ -> + ct:fail({unexpected_timestamp, Ts}) + end, + ok. + start_node(Name, Param) -> test_server:start_node(Name, slave, [{args, Param}]). @@ -767,7 +849,7 @@ stop_node(Node) -> test_server:stop_node(Node). load_tracer(Config) -> - Path = ?config(data_dir, Config), + Path = proplists:get_value(data_dir, Config), ok = erl_ddll:load_driver(Path, echo_drv), open_port({spawn,echo_drv}, [eof,binary]). |