aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorMicael Karlberg <[email protected]>2019-07-31 11:53:48 +0200
committerMicael Karlberg <[email protected]>2019-07-31 11:53:48 +0200
commit369718a77d4bd14dc92e3613e896cfcc10802f7b (patch)
treee235bac9a35bb3cb52ce8a16821c366bd7c8803a
parent7c4bd2f442c48807d448f665da0036da4742bc83 (diff)
downloadotp-369718a77d4bd14dc92e3613e896cfcc10802f7b.tar.gz
otp-369718a77d4bd14dc92e3613e896cfcc10802f7b.tar.bz2
otp-369718a77d4bd14dc92e3613e896cfcc10802f7b.zip
[megaco|test] Add an event list to the test MGC/MG
To provide more info when analyzing failed test cases an "event" queue (of max size 10) is added to both the test MG and MGC. This event queue is printed when the process exist. Also, the multi_ack_timeout is wonky, so add anther platform (sunos) to the skip list...
-rw-r--r--lib/megaco/test/megaco_test_mg.erl77
-rw-r--r--lib/megaco/test/megaco_test_mgc.erl82
-rw-r--r--lib/megaco/test/megaco_trans_test.erl35
3 files changed, 99 insertions, 95 deletions
diff --git a/lib/megaco/test/megaco_test_mg.erl b/lib/megaco/test/megaco_test_mg.erl
index b7b220dfa9..38883c94f0 100644
--- a/lib/megaco/test/megaco_test_mg.erl
+++ b/lib/megaco/test/megaco_test_mg.erl
@@ -79,7 +79,10 @@
reply_counter = 0,
mload_info = undefined,
parent = undefined,
- dsi_timer}).
+ dsi_timer,
+ evs = []}).
+
+-define(EVS_MAX, 10).
%%% --------------------------------------------------------------------
@@ -364,7 +367,7 @@ mg(Parent, Verbosity, Config) ->
MG = #mg{parent = Parent, mid = Mid, dsi_timer = DSITimer},
i("mg -> started"),
put(verbosity, Verbosity),
- case (catch loop(MG)) of
+ case (catch loop(evs(MG, started))) of
{'EXIT', normal} ->
exit(normal);
{'EXIT', Reason} ->
@@ -438,12 +441,12 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
{display_system_info, Time} ->
display_system_info(S#mg.mid),
NewTimer = create_timer(Time, display_system_info),
- loop(S#mg{dsi_timer = NewTimer});
+ loop(evs(S#mg{dsi_timer = NewTimer}, {dsi, Time}));
{verbosity, V, Parent} ->
i("loop -> received new verbosity: ~p", [V]),
put(verbosity,V),
- loop(S);
+ loop(evs(S, {verb, V}));
{stop, Parent} ->
@@ -453,7 +456,7 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
Res = do_stop(Mid),
d("loop -> stop result: ~p", [Res]),
server_reply(Parent, stopped, {ok, Res}),
- exit(normal);
+ done(evs(S, stop), normal);
{{enable_test_code, Tag, Fun}, Parent} ->
i("loop -> enable_test_code: ~p, ~p", [Tag, Fun]),
@@ -463,52 +466,52 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
"~n ets:tab2list(megaco_test_data): ~p",
[Reply,ets:tab2list(megaco_test_data)]),
server_reply(Parent, enable_test_code_reply, Reply),
- loop(S);
+ loop(evs(S, {enable_test_code, Tag}));
{{encode_ar_first, EAF}, Parent} ->
i("loop -> encode_ar_first: ~p", [EAF]),
{Reply, S1} = handle_encode_ar_first(S, EAF),
server_reply(Parent, encode_ar_first_reply, Reply),
- loop(S1#mg{encode_ar_first = EAF});
+ loop(evs(S1#mg{encode_ar_first = EAF}, {enc_arf, EAF}));
%% Give me statistics
{statistics, Parent} ->
i("loop -> got request for statistics", []),
Stats = do_get_statistics(Mid),
server_reply(Parent, statistics_reply, {ok, Stats}),
- loop(S);
+ loop(evs(S, stats));
{reset_stats, Parent} ->
i("loop -> got request to reset stats counters", []),
do_reset_stats(Mid),
server_reply(Parent, reset_stats_ack, ok),
- loop(S);
+ loop(evs(S, rst_stats));
{{user_info, Tag}, Parent} ->
i("loop -> got user_info request for ~w", [Tag]),
Res = do_get_user_info(Mid, Tag),
d("loop -> Res: ~p", [Res]),
server_reply(Parent, user_info_ack, Res),
- loop(S);
+ loop(evs(S, {ui, Tag}));
{{update_user_info, Tag, Val}, Parent} ->
i("loop -> got update_user_info: ~w -> ~p", [Tag, Val]),
Res = do_update_user_info(Mid, Tag, Val),
d("loop -> Res: ~p", [Res]),
server_reply(Parent, update_user_info_ack, Res),
- loop(S);
+ loop(evs(S, {uui, {Tag, Val}}));
{{conn_info, Tag}, Parent} ->
i("loop -> got conn_info request for ~w", [Tag]),
Res = do_get_conn_info(Mid, Tag),
server_reply(Parent, conn_info_ack, Res),
- loop(S);
+ loop(evs(S, {ci, Tag}));
{{update_conn_info, Tag, Val}, Parent} ->
i("loop -> got update_conn_info: ~w -> ~p", [Tag, Val]),
Res = do_update_conn_info(Mid, Tag, Val),
server_reply(Parent, update_conn_info_ack, Res),
- loop(S);
+ loop(evs(S, {uci, {Tag, Val}}));
%% Do a service change
@@ -526,28 +529,28 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
server_reply(Parent, service_change_reply, Error),
S
end,
- loop(S1);
+ loop(evs(S1, svc_ch));
{{group_requests, N}, Parent} when N > 0 ->
i("loop -> received group_requests ~p", [N]),
Reply = {ok, S#mg.group_size},
server_reply(Parent, group_requests_reply, Reply),
- loop(S#mg{group_size = N});
+ loop(evs(S#mg{group_size = N}, {grp_reqs, N}));
{{ack_info, To}, Parent} ->
i("loop -> received request to inform about received ack's ", []),
- loop(S#mg{ack_info = To});
+ loop(evs(S#mg{ack_info = To}, {acki, To}));
{{rep_info, To}, Parent} ->
i("loop -> received request to inform about received rep's ", []),
- loop(S#mg{rep_info = To});
+ loop(evs(S#mg{rep_info = To}, {repi, To}));
%% Make a sync-call
{notify_request, Parent} ->
i("loop -> received request to send notify request ", []),
{Res, S1} = do_handle_notify_request(S),
d("loop -> notify request result: ~p", [Res]),
- loop(S1);
+ loop(evs(S1, not_req));
%% sync-call complete
{notify_request_complete, NotifyReply, Pid} ->
@@ -556,7 +559,7 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
"~n NotifyReply: ~p",
[Pid, NotifyReply]),
server_reply(Parent, notify_request_reply, NotifyReply),
- loop(S#mg{req_handler = undefined});
+ loop(evs(S#mg{req_handler = undefined}, {not_reqc, NotifyReply}));
%% cancel requests
@@ -564,14 +567,14 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
i("loop -> received request to cancel (all) megaco requests ", []),
Res = do_cancel_requests(Mid, Reason),
server_reply(Parent, cancel_request_reply, Res),
- loop(S);
+ loop(evs(S, {creq, Reason}));
%% Apply multi-load
{apply_multi_load, {NL, NR}, Parent} ->
i("loop -> received apply_multi_load request: ~w, ~w", [NL, NR]),
S1 = start_loaders(S, NL, NR),
- loop(S1);
+ loop(evs(S1, {apply_mload, {NL, NR}}));
%% Apply some load
@@ -587,12 +590,12 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
server_reply(Parent, apply_load_ack, Error),
S
end,
- loop(S1);
+ loop(evs(S1, {apply_load, Times}));
{apply_load_timeout, _} ->
d("loop -> received apply_load timeout", []),
S1 = do_apply_load(S),
- loop(S1);
+ loop(evs(S1, apply_loadto));
%% Megaco callback messages
@@ -604,22 +607,35 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
{Reply, S1} = handle_megaco_request(S, Request),
d("loop -> send (megaco callback) request reply: ~n~p", [Reply]),
From ! {reply, Reply, self()},
- loop(S1);
+ loop(evs(S1, {req, {Request, Mid, From}}));
{'EXIT', Pid, Reason} ->
- i("loop -> received exit signal from ~p: ~n~p", [Pid, Reason]),
+ i("loop -> received exit signal from ~p: "
+ "~n ~p", [Pid, Reason]),
S1 = handle_exit(S, Pid, Reason),
- loop(S1);
+ loop(evs(S1, {exit, {Pid, Reason}}));
Invalid ->
error_msg("received invalid request: ~n~p", [Invalid]),
- loop(S)
+ loop(evs(S, {invalid, Invalid}))
end.
+evs(#mg{evs = EVS} = S, Ev) when (length(EVS) < ?EVS_MAX) ->
+ S#mg{evs = [{?FTS(), Ev}|EVS]};
+evs(#mg{evs = EVS} = S, Ev) ->
+ S#mg{evs = [{?FTS(), Ev}|lists:droplast(EVS)]}.
+
+done(#mg{evs = EVS}, Reason) ->
+ info_msg("Exiting with latest event(s): "
+ "~n ~p"
+ "~n", [EVS]),
+ exit(Reason).
+
+
handle_encode_ar_first(#mg{encode_ar_first = Old} = MG, New)
when (New =:= true) orelse (New =:= false) ->
{{ok, Old}, MG#mg{encode_ar_first = New}};
@@ -776,7 +792,7 @@ do_service_change(#mg{state = State} = MG) ->
{{error, {invalid_state, State}}, MG}.
do_service_change(ConnHandle, Method, EAF, Reason) ->
- d("sending service change using:"
+ d("send service change using:"
"~n ConnHandle: ~p"
"~n Method: ~p"
"~n EAF: ~p"
@@ -844,10 +860,10 @@ loader_main(EAF, N, CH) ->
-handle_exit(#mg{parent = Pid}, Pid, Reason) ->
+handle_exit(#mg{parent = Pid} = S, Pid, Reason) ->
error_msg("received exit from the parent:"
"~n ~p", [Reason]),
- exit({parent_terminated, Reason});
+ done(S, {parent_terminated, Reason});
handle_exit(#mg{parent = Parent, req_handler = Pid} = MG, Pid, Reason) ->
error_msg("received unexpected exit from the request handler:"
@@ -1423,6 +1439,7 @@ sleep(X) ->
receive after X -> ok end.
+info_msg(F,A) -> error_logger:info_msg("MG: " ++ F ++ "~n",A).
error_msg(F,A) -> error_logger:error_msg("MG: " ++ F ++ "~n",A).
diff --git a/lib/megaco/test/megaco_test_mgc.erl b/lib/megaco/test/megaco_test_mgc.erl
index 9021efa656..a9027ca68e 100644
--- a/lib/megaco/test/megaco_test_mgc.erl
+++ b/lib/megaco/test/megaco_test_mgc.erl
@@ -75,7 +75,10 @@
abort_info = undefined,
req_info = undefined,
mg = [],
- dsi_timer}).
+ dsi_timer,
+ evs = []}).
+
+-define(EVS_MAX, 10).
%%% ------------------------------------------------------------------
@@ -297,7 +300,7 @@ mgc(Parent, Verbosity, Config) ->
dsi_timer = DSITimer},
i("mgc -> started"),
display_system_info("at start "),
- loop(S)
+ loop(evs(S, started))
end.
init(Config) ->
@@ -359,7 +362,7 @@ loop(S) ->
{display_system_info, Time} ->
display_system_info(S#mgc.mid),
NewTimer = create_timer(Time, display_system_info),
- loop(S#mgc{dsi_timer = NewTimer});
+ loop(evs(S#mgc{dsi_timer = NewTimer}, {dsi, Time}));
{stop, Parent} when S#mgc.parent =:= Parent ->
i("loop -> stopping", []),
@@ -371,7 +374,7 @@ loop(S) ->
application:stop(megaco),
i("loop -> stopped", []),
server_reply(Parent, stopped, ok),
- exit(normal);
+ done(evs(S, stop), normal);
{{disconnect, Reason}, Parent} when S#mgc.parent == Parent ->
i("loop -> disconnecting", []),
@@ -379,22 +382,22 @@ loop(S) ->
[Conn|_] = megaco:user_info(Mid, connections),
Res = megaco:disconnect(Conn, {self(), Reason}),
server_reply(Parent, disconnected, Res),
- loop(S);
+ loop(evs(S, {disconnect, Reason}));
{{update_user_info, Tag, Val}, Parent} when S#mgc.parent == Parent ->
i("loop -> got update_user_info: ~w -> ~p", [Tag, Val]),
Res = (catch megaco:update_user_info(S#mgc.mid, Tag, Val)),
d("loop -> Res: ~p", [Res]),
server_reply(Parent, update_user_info_ack, Res),
- loop(S);
-
- {{user_info, Tag}, Parent} when S#mgc.parent == Parent ->
- i("loop -> got user_info request for ~w", [Tag]),
- Res = (catch megaco:user_info(S#mgc.mid, Tag)),
- d("loop -> Res: ~p", [Res]),
- server_reply(Parent, user_info_ack, Res),
- loop(S);
-
+ loop(evs(S, {uui, {Tag, Val}}));
+
+ {{user_info, Tag}, Parent} when S#mgc.parent == Parent ->
+ i("loop -> got user_info request for ~w", [Tag]),
+ Res = (catch megaco:user_info(S#mgc.mid, Tag)),
+ d("loop -> Res: ~p", [Res]),
+ server_reply(Parent, user_info_ack, Res),
+ loop(evs(S, {ui, Tag}));
+
{{update_conn_info, Tag, Val}, Parent} when S#mgc.parent == Parent ->
i("loop -> got update_conn_info: ~w -> ~p", [Tag, Val]),
Conns = megaco:user_info(S#mgc.mid, connections),
@@ -404,7 +407,7 @@ loop(S) ->
Res = lists:map(Fun, Conns),
d("loop -> Res: ~p", [Res]),
server_reply(Parent, update_conn_info_ack, Res),
- loop(S);
+ loop(evs(S, {uci, {Tag, Val}}));
{{conn_info, Tag}, Parent} when S#mgc.parent == Parent ->
i("loop -> got conn_info request for ~w", [Tag]),
@@ -415,11 +418,11 @@ loop(S) ->
Res = lists:map(Fun, Conns),
d("loop -> Res: ~p", [Res]),
server_reply(Parent, conn_info_ack, Res),
- loop(S);
+ loop(evs(S, {ci, Tag}));
%%
- {request_action, {Action, To}, Parent} when S#mgc.parent == Parent ->
+ {request_action, {Action, To}, Parent} when S#mgc.parent == Parent ->
i("loop -> got new request_action: ~p:~w", [Action,To]),
{Reply, S1} =
case lists:member(Action, ?valid_actions) of
@@ -432,7 +435,7 @@ loop(S) ->
{{error, {invalid_action, Action}}, S}
end,
server_reply(Parent, request_action_ack, Reply),
- loop(S1);
+ loop(evs(S1, {req_act, {Action, To}}));
%% Reset stats
@@ -440,7 +443,7 @@ loop(S) ->
i("loop -> got request to reset stats counters"),
do_reset_stats(S#mgc.mid),
server_reply(Parent, reset_stats_ack, ok),
- loop(S);
+ loop(evs(S, rst_stats));
%% Give me statistics
@@ -466,7 +469,7 @@ loop(S) ->
lists:map(GetTrans, megaco:user_info(Mid, connections)),
Reply = {ok, [{gen, Gen}, {trans, Trans}]},
server_reply(Parent, {statistics_reply, 1}, Reply),
- loop(S);
+ loop(evs(S, {stats, 1}));
{{statistics, 2}, Parent} when S#mgc.parent == Parent ->
@@ -477,7 +480,7 @@ loop(S) ->
UdpStats = get_trans_stats(UdpSup, megaco_udp),
Reply = {ok, [{gen, Gen}, {trans, [TcpStats, UdpStats]}]},
server_reply(Parent, {statistics_reply, 2}, Reply),
- loop(S);
+ loop(evs(S, {stats, 2}));
%% Megaco callback messages
@@ -487,28 +490,28 @@ loop(S) ->
{Reply, S1} = handle_megaco_request(Request, S),
d("loop -> send request reply: ~n~p", [Reply]),
reply(From, Reply),
- loop(S1);
+ loop(evs(S1, {req, Request}));
{ack_info, To, Parent} when S#mgc.parent == Parent ->
i("loop -> received request to inform about received ack's ", []),
- loop(S#mgc{ack_info = To});
+ loop(evs(S#mgc{ack_info = To}, {acki, To}));
{abort_info, To, Parent} when S#mgc.parent == Parent ->
i("loop -> received request to inform about received aborts ", []),
- loop(S#mgc{abort_info = To});
+ loop(evs(S#mgc{abort_info = To}, {abi, To}));
{req_info, To, Parent} when S#mgc.parent == Parent ->
i("loop -> received request to inform about received req's ", []),
- loop(S#mgc{req_info = To});
+ loop(evs(S#mgc{req_info = To}, {reqi, To}));
{verbosity, V, Parent} when S#mgc.parent == Parent ->
i("loop -> received new verbosity: ~p", [V]),
put(verbosity,V),
- loop(S);
+ loop(evs(S, {verb, V}));
{'EXIT', Pid, Reason} when S#mgc.tcp_sup =:= Pid ->
@@ -525,7 +528,7 @@ loop(S) ->
i("loop -> stopped", []),
StopReason = {error, {tcp_terminated, Pid, Reason}},
server_reply(S#mgc.parent, stopped, StopReason),
- exit(StopReason);
+ done(evs(S, {tcp_sup_exit, Reason}), StopReason);
{'EXIT', Pid, Reason} when S#mgc.udp_sup =:= Pid ->
@@ -542,15 +545,27 @@ loop(S) ->
i("loop -> stopped", []),
StopReason = {error, {udp_terminated, Pid, Reason}},
server_reply(S#mgc.parent, stopped, StopReason),
- exit(StopReason);
+ done(evs(S, {udp_sup_exit, Reason}), StopReason);
Invalid ->
i("loop -> received invalid request: ~p", [Invalid]),
- loop(S)
+ loop(evs(S, {invalid, Invalid}))
end.
+evs(#mgc{evs = EVS} = S, Ev) when (length(EVS) < ?EVS_MAX) ->
+ S#mgc{evs = [{?FTS(), Ev}|EVS]};
+evs(#mgc{evs = EVS} = S, Ev) ->
+ S#mgc{evs = [{?FTS(), Ev}|lists:droplast(EVS)]}.
+
+done(#mgc{evs = EVS}, Reason) ->
+ info_msg("Exiting with latest event(s): "
+ "~n ~p"
+ "~n", [EVS]),
+ exit(Reason).
+
+
do_reset_stats(Mid) ->
megaco:reset_stats(),
do_reset_trans_stats(megaco:user_info(Mid, connections), []).
@@ -825,10 +840,10 @@ handle_megaco_request({handle_trans_ack, CH, PV, AS, AD},
handle_megaco_request({handle_trans_ack, CH, PV, AS, AD}, S) ->
d("handle_megaco_request(handle_trans_ack) -> entry with"
- "~n CH: ~p"
- "~n PV: ~p"
- "~n AS: ~p"
- "~n AD: ~p", [CH, PV, AS, AD]),
+ "~n Conn Handle: ~p"
+ "~n Prot Version: ~p"
+ "~n Ack Status: ~p"
+ "~n Ack Data: ~p", [CH, PV, AS, AD]),
{ok, S};
handle_megaco_request({handle_unexpected_trans, CH, PV, TR}, S) ->
@@ -1090,6 +1105,7 @@ sleep(X) ->
receive after X -> ok end.
+info_msg(F,A) -> error_logger:info_msg("MGC: " ++ F ++ "~n",A).
error_msg(F,A) -> error_logger:error_msg("MGC: " ++ F ++ "~n",A).
diff --git a/lib/megaco/test/megaco_trans_test.erl b/lib/megaco/test/megaco_trans_test.erl
index fb44a3c6e6..37bc134c8d 100644
--- a/lib/megaco/test/megaco_trans_test.erl
+++ b/lib/megaco/test/megaco_trans_test.erl
@@ -295,7 +295,7 @@ multi_ack_timeout(doc) ->
[];
multi_ack_timeout(Config) when is_list(Config) ->
%% <CONDITIONAL-SKIP>
- Skippable = [win32, {unix, [darwin, linux]}],
+ Skippable = [win32, {unix, [darwin, linux, sunos]}], % Is there any left?
Condition = fun() -> ?OS_BASED_SKIP(Skippable) end,
?NON_PC_TC_MAYBE_SKIP(Config, Condition),
%% </CONDITIONAL-SKIP>
@@ -9247,10 +9247,10 @@ await_ack(User, N, Timeout, Expected) when (N > 0) andalso is_integer(Timeout) -
T = tim(),
receive
{ack_received, User, Expected} ->
- d("await_ack -> received another ack"),
+ d("await_ack -> received another expected ack"),
await_ack(User, N-1, Timeout - (tim() - T), Expected);
{ack_received, User, UnExpected} ->
- e("await_ack -> unexpected ack result: ~p", [UnExpected]),
+ e("await_ack -> received unexpected ack result: ~p", [UnExpected]),
exit({unexpected_ack_result, UnExpected, Expected})
after Timeout ->
exit({await_ack_timeout, N})
@@ -9266,35 +9266,6 @@ await_ack(User, N, infinity, Expected) when N > 0 ->
exit({unexpected_ack_result, UnExpected, Expected})
end.
-%% await_req(_User, 0, Timeout) ->
-%% d("await_req -> done when Timeout = ~p", [Timeout]),
-%% ok;
-%% await_req(User, N, Timeout) when (N > 0) andalso is_integer(Timeout) ->
-%% d("await_req -> entry with N: ~p, Timeout: ~p", [N,Timeout]),
-%% T = tim(),
-%% receive
-%% {req_received, User, ARs} ->
-%% d("await_req -> received req(s) when N = ~w", [N]),
-%% N1 = await_req1(N, ARs),
-%% await_req(User, N1, Timeout - (tim() - T))
-%% after Timeout ->
-%% exit({await_req_timeout, N})
-%% end;
-%% await_req(User, N, infinity) when N > 0 ->
-%% d("await_req -> entry with N: ~p", [N]),
-%% receive
-%% {req_received, User, ARs} ->
-%% d("await_req -> received req(s) when N = ~2",[N]),
-%% N1 = await_req1(N, ARs),
-%% await_req(User, N1, infinity)
-%% end.
-
-%% await_req1(N, []) when N >= 0 ->
-%% N;
-%% await_req1(N, [AR|ARs]) when (N > 0) andalso is_record(AR, 'ActionRequest') ->
-%% await_req1(N-1, ARs);
-%% await_req1(N, ARs) ->
-%% exit({unexpected_req_result, N, ARs}).
tim() ->
{A,B,C} = erlang:timestamp(),