diff options
author | Micael Karlberg <[email protected]> | 2019-07-31 11:53:48 +0200 |
---|---|---|
committer | Micael Karlberg <[email protected]> | 2019-07-31 11:53:48 +0200 |
commit | 369718a77d4bd14dc92e3613e896cfcc10802f7b (patch) | |
tree | e235bac9a35bb3cb52ce8a16821c366bd7c8803a | |
parent | 7c4bd2f442c48807d448f665da0036da4742bc83 (diff) | |
download | otp-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.erl | 77 | ||||
-rw-r--r-- | lib/megaco/test/megaco_test_mgc.erl | 82 | ||||
-rw-r--r-- | lib/megaco/test/megaco_trans_test.erl | 35 |
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(), |