1%%
2%% %CopyrightBegin%
3%%
4%% Copyright Ericsson AB 1998-2017. All Rights Reserved.
5%%
6%% Licensed under the Apache License, Version 2.0 (the "License");
7%% you may not use this file except in compliance with the License.
8%% You may obtain a copy of the License at
9%%
10%%     http://www.apache.org/licenses/LICENSE-2.0
11%%
12%% Unless required by applicable law or agreed to in writing, software
13%% distributed under the License is distributed on an "AS IS" BASIS,
14%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
15%% See the License for the specific language governing permissions and
16%% limitations under the License.
17%%
18%% %CopyrightEnd%
19%%
20
21-module(trace_bif_SUITE).
22
23-include_lib("common_test/include/ct.hrl").
24
25-export([all/0, suite/0]).
26-export([trace_bif/1, trace_bif_timestamp/1, trace_on_and_off/1,
27	 trace_bif_local/1,
28	 trace_bif_timestamp_local/1, trace_bif_return/1, not_run/1,
29	 trace_info_old_code/1]).
30
31-export([bif_process/0]).
32
33suite() -> [{ct_hooks,[ts_install_cth]}].
34
35all() ->
36    case test_server:is_native(trace_bif_SUITE) of
37	true -> [not_run];
38	false ->
39	    [trace_bif, trace_bif_timestamp, trace_on_and_off,
40	     trace_bif_local, trace_bif_timestamp_local,
41	     trace_bif_return, trace_info_old_code]
42    end.
43
44
45not_run(Config) when is_list(Config) ->
46    {skipped,"Native code"}.
47
48%% Tests switching tracing on and off.
49trace_on_and_off(Config) when is_list(Config) ->
50    Pid = spawn_link(?MODULE, bif_process, []),
51    Self = self(),
52    1 = erlang:trace(Pid, true, [call,timestamp]),
53    {flags, Flags} = erlang:trace_info(Pid,flags),
54    [call,timestamp] = lists:sort(Flags),
55    {tracer, Self} = erlang:trace_info(Pid,tracer),
56    1 = erlang:trace(Pid, false, [timestamp]),
57    {flags,[call]} =  erlang:trace_info(Pid,flags),
58    {tracer, Self} = erlang:trace_info(Pid,tracer),
59    1 = erlang:trace(Pid, false, [call]),
60    {flags,[]} =  erlang:trace_info(Pid,flags),
61    {tracer, []} = erlang:trace_info(Pid,tracer),
62    unlink(Pid),
63    exit(Pid,kill),
64    ok.
65
66%% Test tracing BIFs.
67trace_bif(Config) when is_list(Config) ->
68    do_trace_bif([]).
69
70%% Test tracing BIFs with local flag.
71trace_bif_local(Config) when is_list(Config) ->
72    do_trace_bif([local]).
73
74do_trace_bif(Flags) ->
75    Pid = spawn_link(?MODULE, bif_process, []),
76    1 = erlang:trace(Pid, true, [call]),
77    erlang:trace_pattern({erlang,'_','_'}, [], Flags),
78    Pid ! {do_bif, time, []},
79    receive_trace_msg({trace,Pid,call,{erlang,time, []}}),
80    Pid ! {do_bif, statistics, [runtime]},
81    receive_trace_msg({trace,Pid,call,
82                       {erlang,statistics, [runtime]}}),
83
84    Pid ! {do_time_bif},
85    receive_trace_msg({trace,Pid,call,
86                       {erlang,time, []}}),
87
88    Pid ! {do_statistics_bif},
89    receive_trace_msg({trace,Pid,call,
90                       {erlang,statistics, [runtime]}}),
91
92    1 = erlang:trace(Pid, false, [call]),
93    erlang:trace_pattern({erlang,'_','_'}, false, Flags),
94    unlink(Pid),
95    exit(Pid, die),
96    ok.
97
98%% Test tracing BIFs with timestamps.
99trace_bif_timestamp(Config) when is_list(Config) ->
100    do_trace_bif_timestamp([], timestamp, [timestamp]),
101    do_trace_bif_timestamp([], timestamp,
102                           [timestamp,
103                            monotonic_timestamp,
104                            strict_monotonic_timestamp]),
105    do_trace_bif_timestamp([], strict_monotonic_timestamp,
106                           [strict_monotonic_timestamp]),
107    do_trace_bif_timestamp([], strict_monotonic_timestamp,
108                           [monotonic_timestamp, strict_monotonic_timestamp]),
109    do_trace_bif_timestamp([], monotonic_timestamp, [monotonic_timestamp]).
110
111%% Test tracing BIFs with timestamps and local flag.
112trace_bif_timestamp_local(Config) when is_list(Config) ->
113    do_trace_bif_timestamp([local], timestamp, [timestamp]),
114    do_trace_bif_timestamp([local], timestamp,
115                           [timestamp,
116                            monotonic_timestamp,
117                            strict_monotonic_timestamp]),
118    do_trace_bif_timestamp([local], strict_monotonic_timestamp,
119                           [strict_monotonic_timestamp]),
120    do_trace_bif_timestamp([local], strict_monotonic_timestamp,
121                           [monotonic_timestamp, strict_monotonic_timestamp]),
122    do_trace_bif_timestamp([local], monotonic_timestamp, [monotonic_timestamp]).
123
124do_trace_bif_timestamp(Flags, TsType, TsFlags) ->
125    io:format("Testing with TsType=~p TsFlags=~p~n", [TsType, TsFlags]),
126    Pid = spawn_link(?MODULE, bif_process, []),
127    1 = erlang:trace(Pid, true, [call]++TsFlags),
128    erlang:trace_pattern({erlang,'_','_'}, [], Flags),
129
130    Ts0 = make_ts(TsType),
131    Pid ! {do_bif, time, []},
132    Ts1 = receive_trace_msg_ts({trace_ts,Pid,call,{erlang,time,[]}},
133                               Ts0,TsType),
134
135    Pid ! {do_bif, statistics, [runtime]},
136    Ts2 = receive_trace_msg_ts({trace_ts,Pid,call,
137                                {erlang,statistics, [runtime]}},
138                               Ts1, TsType),
139
140    Pid ! {do_time_bif},
141    Ts3 = receive_trace_msg_ts({trace_ts,Pid,call,
142                                {erlang,time, []}},
143                               Ts2, TsType),
144
145    Pid ! {do_statistics_bif},
146    Ts4 = receive_trace_msg_ts({trace_ts,Pid,call,
147                                {erlang,statistics, [runtime]}},
148                               Ts3, TsType),
149
150    check_ts(TsType, Ts4, make_ts(TsType)),
151
152    %% We should be able to turn off the timestamp.
153    1 = erlang:trace(Pid, false, TsFlags),
154
155    Pid ! {do_statistics_bif},
156    receive_trace_msg({trace,Pid,call,
157                       {erlang,statistics, [runtime]}}),
158
159    Pid ! {do_bif, statistics, [runtime]},
160    receive_trace_msg({trace,Pid,call,
161                       {erlang,statistics, [runtime]}}),
162
163    1 = erlang:trace(Pid, false, [call]),
164    erlang:trace_pattern({erlang,'_','_'}, false, Flags),
165
166    unlink(Pid),
167    exit(Pid, die),
168    ok.
169
170%% Test tracing BIF's with return/return_to trace.
171trace_bif_return(Config) when is_list(Config) ->
172    do_trace_bif_return(timestamp, [timestamp]),
173    do_trace_bif_return(timestamp,
174                        [timestamp,
175                         monotonic_timestamp,
176                         strict_monotonic_timestamp]),
177    do_trace_bif_return(strict_monotonic_timestamp,
178                        [strict_monotonic_timestamp]),
179    do_trace_bif_return(strict_monotonic_timestamp,
180                        [monotonic_timestamp, strict_monotonic_timestamp]),
181    do_trace_bif_return(monotonic_timestamp, [monotonic_timestamp]).
182
183do_trace_bif_return(TsType, TsFlags) ->
184    io:format("Testing with TsType=~p TsFlags=~p~n", [TsType, TsFlags]),
185    Pid = spawn_link(?MODULE, bif_process, []),
186    1 = erlang:trace(Pid, true, [call,return_to]++TsFlags),
187    erlang:trace_pattern({erlang,'_','_'}, [{'_',[],[{return_trace}]}],
188                         [local]),
189
190    Ts0 = make_ts(TsType),
191    Pid ! {do_bif, time, []},
192    Ts1 = receive_trace_msg_ts({trace_ts,Pid,call,{erlang,time,[]}},
193                               Ts0, TsType),
194    Ts2 = receive_trace_msg_ts_return_from({trace_ts,Pid,return_from,
195                                            {erlang,time,0}},
196                                           Ts1, TsType),
197    Ts3 = receive_trace_msg_ts_return_to({trace_ts,Pid,return_to,
198                                          {?MODULE, bif_process,0}},
199                                         Ts2, TsType),
200
201
202    Pid ! {do_bif, statistics, [runtime]},
203    Ts4 = receive_trace_msg_ts({trace_ts,Pid,call,
204                                {erlang,statistics, [runtime]}},
205                               Ts3, TsType),
206    Ts5 = receive_trace_msg_ts_return_from({trace_ts,Pid,return_from,
207                                            {erlang,statistics,1}},
208                                           Ts4, TsType),
209    Ts6 = receive_trace_msg_ts_return_to({trace_ts,Pid,return_to,
210                                          {?MODULE, bif_process,0}},
211                                         Ts5, TsType),
212
213
214    Pid ! {do_time_bif},
215    Ts7 = receive_trace_msg_ts({trace_ts,Pid,call,
216                                {erlang,time, []}},
217                               Ts6, TsType),
218    Ts8 = receive_trace_msg_ts_return_from({trace_ts,Pid,return_from,
219                                            {erlang,time,0}},
220                                           Ts7, TsType),
221    Ts9 = receive_trace_msg_ts_return_to({trace_ts,Pid,return_to,
222                                          {?MODULE, bif_process,0}},
223                                         Ts8, TsType),
224
225
226
227    Pid ! {do_statistics_bif},
228    Ts10 = receive_trace_msg_ts({trace_ts,Pid,call,
229                                 {erlang,statistics, [runtime]}},
230                                Ts9, TsType),
231    Ts11 = receive_trace_msg_ts_return_from({trace_ts,Pid,return_from,
232                                             {erlang,statistics,1}},
233                                            Ts10, TsType),
234    Ts12 = receive_trace_msg_ts_return_to({trace_ts,Pid,return_to,
235                                           {?MODULE, bif_process,0}},
236                                          Ts11, TsType),
237    check_ts(TsType, Ts12, make_ts(TsType)),
238    erlang:trace_pattern({erlang,'_','_'}, false, [local]),
239    ok.
240
241
242receive_trace_msg(Mess) ->
243    receive
244        Mess ->
245            ok;
246        Other ->
247            ct:fail("Expected: ~p,~nGot: ~p~n", [Mess, Other])
248    after 5000 ->
249              ct:fail("Expected: ~p,~nGot: timeout~n", [Mess])
250    end.
251
252receive_trace_msg_ts({trace_ts, Pid, call, {erlang,F,A}}, PrevTs, TsType) ->
253    receive
254        {trace_ts, Pid, call, {erlang, F, A}, Ts} = M ->
255            io:format("~p (PrevTs: ~p)~n",[M, PrevTs]),
256            check_ts(TsType, PrevTs, Ts),
257            Ts;
258        Other ->
259            ct:fail("Expected: {trace, ~p, call, {~p, ~p, ~p}, TimeStamp}},~n"
260                    "Got: ~p~n",
261                    [Pid, erlang, F, A, Other])
262    after 5000 ->
263              ct:fail("Got timeout~n", [])
264    end.
265
266receive_trace_msg_ts_return_from({trace_ts, Pid, return_from, {erlang,F,A}}, PrevTs, TsType) ->
267    receive
268        {trace_ts, Pid, return_from, {erlang, F, A}, _Value, Ts} = M ->
269            io:format("~p (PrevTs: ~p)~n",[M, PrevTs]),
270            check_ts(TsType, PrevTs, Ts),
271            Ts;
272        Other ->
273            ct:fail("Expected: {trace_ts, ~p, return_from, {~p, ~p, ~p}, Value, TimeStamp}},~n"
274                    "Got: ~p~n", [Pid, erlang, F, A, Other])
275    after 5000 ->
276              ct:fail("Got timeout~n", [])
277    end.
278
279receive_trace_msg_ts_return_to({trace_ts, Pid, return_to, {M,F,A}}, PrevTs, TsType) ->
280    receive
281        {trace_ts, Pid, return_to, {M, F, A}, Ts} = Msg ->
282            io:format("~p (PrevTs: ~p)~n",[Msg, PrevTs]),
283            check_ts(TsType, PrevTs, Ts),
284            Ts;
285        Other ->
286            ct:fail("Expected: {trace_ts, ~p, return_to, {~p, ~p, ~p}, TimeStamp}},~n"
287                    "Got: ~p~n", [Pid, M, F, A, Other])
288    after 5000 ->
289              ct:fail("Got timeout~n", [])
290    end.
291
292make_ts(timestamp) ->
293    erlang:now();
294make_ts(monotonic_timestamp) ->
295    erlang:monotonic_time(nanosecond);
296make_ts(strict_monotonic_timestamp) ->
297    MT = erlang:monotonic_time(nanosecond),
298    UMI = erlang:unique_integer([monotonic]),
299    {MT, UMI}.
300
301check_ts(timestamp, PrevTs, Ts) ->
302    {Ms, S, Us} = Ts,
303    true = is_integer(Ms),
304    true = is_integer(S),
305    true = is_integer(Us),
306    true = PrevTs < Ts,
307    Ts;
308check_ts(monotonic_timestamp, PrevTs, Ts) ->
309    true = is_integer(Ts),
310    true = PrevTs =< Ts,
311    Ts;
312check_ts(strict_monotonic_timestamp, PrevTs, Ts) ->
313    {MT, UMI} = Ts,
314    true = is_integer(MT),
315    true = is_integer(UMI),
316    true = PrevTs < Ts,
317    Ts.
318
319bif_process() ->
320    receive
321        {do_bif, Name, Args} ->
322            apply(erlang, Name, Args),
323            bif_process();
324        {do_time_bif} ->
325            %% Match the return value to ensure that the time() call
326            %% is not optimized away.
327            {_,_,_} = time(),
328            bif_process();
329        {do_statistics_bif} ->
330            statistics(runtime),
331            bif_process();
332        _Stuff ->
333            bif_process()
334    end.
335
336
337
338%% trace_info on deleted module (OTP-5057).
339trace_info_old_code(Config) when is_list(Config) ->
340    MFA = {M,F,0} = {test,foo,0},
341    Fname = atom_to_list(M)++".erl",
342    AbsForms =
343    [{attribute,a(1),module,M},                % -module(M).
344     {attribute,a(2),export,[{F,0}]},          % -export([F/0]).
345     {function,a(3),F,0,                       % F() ->
346      [{clause,a(4),[],[],[{atom,a(4),F}]}]}], %     F.
347    %%
348    {ok,M,Mbin} = compile:forms(AbsForms),
349    {module,M} = code:load_binary(M, Fname, Mbin),
350    true  = erlang:delete_module(M),
351    {traced,undefined} = erlang:trace_info(MFA, traced),
352    ok.
353
354a(L) ->
355    erl_anno:new(L).
356