diff --git a/src/ergw_aaa_diameter_srv.erl b/src/ergw_aaa_diameter_srv.erl index f2525cd..7b98719 100644 --- a/src/ergw_aaa_diameter_srv.erl +++ b/src/ergw_aaa_diameter_srv.erl @@ -180,7 +180,7 @@ call(App, Request, #{function := Function} = Config, CallOpts) -> encode -> ?LOG(critical, "failed to encode DIAMETER requests: ~0p", [Request]); Other -> - ?LOG(notice, "non-critical diameter API: ~p", [Other]) + ?LOG(notice, "non-critical diameter API return: ~p", [Other]) end, SI = diameter:service_info(Function, applications), handle_plain_error(Result, Request, Function, App, CallOpts, SI); @@ -250,8 +250,8 @@ handle_call({start_request, SvcName, Peer, RPid}, _From, #state{peers = Peers0} {reply, Reply, State#state{peers = Peers}}; handle_call({finish_request, SvcName, Peer, RPid}, _From, #state{peers = Peers0} = State) -> - {Reply, Peers} = finish_request_h(SvcName, Peer, RPid, Peers0), - {reply, Reply, State#state{peers = Peers}}; + Peers = finish_request_h(SvcName, Peer, RPid, Peers0), + {reply, ok, State#state{peers = Peers}}; handle_call(peers_info, _, #state{peers = Peers} = State) -> {reply, Peers, State}. @@ -264,19 +264,11 @@ handle_cast(stop, State) -> handle_info({'DOWN', MRef, _Type, Pid, Info}, #state{peers = Peers0} = State) when is_map_key(MRef, Peers0) -> - ?LOG(alert, "got down for pending request ~0p (~p) with ~p", - [maps:get(MRef, Peers0), Pid, Info]), + ?LOG(alert, "Diameter request process terminated unexpected with ~0tp (req: ~0tp, pid: ~0p)", + [Info, maps:get(MRef, Peers0), Pid]), {_, _, PeerRef, Caps} = maps:get(MRef, Peers0), - {Result, Peers} = release_peer(PeerRef, Caps, maps:without([Pid, MRef], Peers0)), - case Result of - {error, Error} -> - ?LOG(critical, "release peer failed with ~0p", [Error]), - ct:fail("release peer failed with ~0p", [Error]), - ok; - ok -> - ok - end, + Peers = release_peer(PeerRef, Caps, maps:without([Pid, MRef], Peers0)), ets:match_delete(?MODULE, {{'_', Pid}, MRef}), {noreply, State#state{peers = Peers}}; @@ -285,7 +277,8 @@ handle_info({'DOWN', MRef, _Type, Pid, _Info}, State) -> {noreply, State}; handle_info(Info, State) -> - ?LOG(warning, "handle_info: ~p", [Info]), + ?LOG(alert, "unexpected info message, something important might have been missed: ~p", + [Info]), {noreply, State}. terminate(_Reason, _State) -> @@ -389,11 +382,13 @@ start_request_h(SvcName, {PeerRef, #diameter_caps{origin_host = {_, OH}} = Caps capacity = Cap, tokens = Tokens} = Peer, if Cnt >= Cap -> - ?LOG(debug, "peer ~0p over capacity (~p > ~p)", [OH, Cnt, Cap]), - {{discard, rate_limit}, Peers0#{OH => inc_stats(no_tokens, Peer)}}; - Tokens == 0 -> - ?LOG(debug, "peer ~0p over rate", [OH]), + ?LOG(notice, + "Diameter peer ~0p traffic is over the configured outstanding request capacity (~p > ~p)", + [OH, Cnt, Cap]), {{discard, rate_limit}, Peers0#{OH => inc_stats(no_capacity, Peer)}}; + Tokens == 0 -> + ?LOG(notice, "Diameter peer ~0p traffic is over the configured rate", [OH]), + {{discard, rate_limit}, Peers0#{OH => inc_stats(no_tokens, Peer)}}; true -> ?LOG(debug, "outstanding inc: ~p", [Cnt + 1]), Peers1 = @@ -415,9 +410,10 @@ release_peer_oh(#diameter_caps{origin_host = {_, OH}}, Peers) -> case Peer of #peer{outstanding = Cnt} when Cnt > 0 -> ?LOG(debug, "outstanding dec #1: ~p", [Cnt - 1]), - {ok, Peers#{OH => Peer#peer{outstanding = Cnt - 1}}}; + Peers#{OH => Peer#peer{outstanding = Cnt - 1}}; _ -> - {{error, underflow}, Peers#{OH => Peer}} + ?LOG(emergency, "reference counting underflow for Diameter peer ~0tp", [OH]), + Peers#{OH => Peer} end. release_peer(PeerRef, Caps, Peers) -> diff --git a/src/ergw_aaa_gx.erl b/src/ergw_aaa_gx.erl index 6df392f..25eedca 100644 --- a/src/ergw_aaa_gx.erl +++ b/src/ergw_aaa_gx.erl @@ -164,14 +164,14 @@ handle_response(_Promise, _Msg, Session, Events, _Opts, State) -> %%=================================================================== %% peer_up/3 -peer_up(_SvcName, _Peer, State) -> - ?LOG(debug, "peer_up: ~p~n", [_Peer]), +peer_up(_SvcName, {_, #diameter_caps{origin_host = {OH, _}}}, State) -> + ?LOG(info, "Diameter peer FSM for ~p changed to state UP", [OH]), State. %% peer_down/3 -peer_down(SvcName, Peer, State) -> +peer_down(SvcName, {_, #diameter_caps{origin_host = {OH, _}}} = Peer, State) -> ergw_aaa_diameter_srv:peer_down(?MODULE, SvcName, Peer), - ?LOG(debug, "peer_down: ~p~n", [Peer]), + ?LOG(info, "Diameter peer FSM for ~p changed to state DOWN", [OH]), State. %% pick_peer/5 @@ -218,9 +218,11 @@ prepare_retransmit(_Pkt, _SvcName, _Peer, _CallOpts) -> %% handle_answer/5 handle_answer(#diameter_packet{msg = Msg, errors = Errors}, - _Request, SvcName, Peer, _CallOpts) - when length(Errors) /= 0 -> - ?LOG(error, "~p: decode of answer from ~p failed, errors ~p", [SvcName, Peer, Errors]), + _Request, SvcName, {_, #diameter_caps{origin_host = {OH, _}}} = Peer, _CallOpts) + when length(Errors) /= 0 -> + %% the exact content of Errors is a bit unclear, dumping them is best we can do + ?LOG(error, "~0tp: decode of Diameter answer ~0tp from ~0tp failed, errors ~0tp", + [SvcName, Msg, OH, Errors]), ok = ergw_aaa_diameter_srv:finish_request(SvcName, Peer), case Msg of [_ | #{'Result-Code' := RC}] -> {error, RC}; %% try to handle gracefully @@ -303,7 +305,6 @@ handle_cca({error, Code} = Result, Session, Events, _Opts, State) when is_integer(Code) -> {Result, Session, [{stop, {?API, peer_reject}} | Events], State#state{state = stopped}}; handle_cca({error, Reason} = Result, Session, Events, _Opts, State) -> - ?LOG(error, "CCA Result: ~p", [Result]), {Result, Session, [{stop, {?API, Reason}} | Events], State#state{state = stopped}}. %% handle_cca/7 @@ -625,10 +626,8 @@ to_session(Procedure, SessEvs, Avps) -> to_session(_, 'Usage-Monitoring-Information', Value, SessEv) -> lists:foldl(fun umi_to_session/2, SessEv, Value); to_session(_, 'Charging-Rule-Install', V, {Session, Events}) -> - [?LOG(info, "CRI: ~p", [R]) || R <- V], {Session, [{pcc, install, V} | Events]}; to_session(_, 'Charging-Rule-Remove', V, {Session, Events}) -> - [?LOG(info, "CRI: ~p", [R]) || R <- V], {Session, [{pcc, remove, V} | Events]}; to_session(_, _, _, SessEv) -> SessEv. diff --git a/src/ergw_aaa_nasreq.erl b/src/ergw_aaa_nasreq.erl index 6e8edac..71d2925 100644 --- a/src/ergw_aaa_nasreq.erl +++ b/src/ergw_aaa_nasreq.erl @@ -105,7 +105,7 @@ initialize_service(_ServiceId, #{function := Function, accounting := AcctModel}) {dictionary, ?DIAMETER_DICT_NASREQ}, {module, ?MODULE}] | Appl]}, - ?LOG(debug, "Registering NASREQ service: ~p", [{Function, SvcOpts}]), + ?LOG(info, "Registering NASREQ service: ~p", [{Function, SvcOpts}]), ergw_aaa_diameter_srv:register_service(Function, SvcOpts), {ok, []}. @@ -150,7 +150,6 @@ invoke(_Service, interim, Session, Events, Opts, #state{state = started} = State invoke(_Service, Procedure, Session, Events, Opts, #state{state = started, authorized = Authorized} = State0) when Procedure =:= stop; Procedure =:= terminate -> - ?LOG(debug, "Session ~s: ~p", [Procedure, Session]), State1 = inc_record_number(State0#state{state = stopped}), RecType = ?'DIAMETER_SGI_ACCOUNTING-RECORD-TYPE_STOP_RECORD', App = acct_app_alias(Opts), @@ -209,14 +208,14 @@ handle_response('STR', Msg, Session, Events, Opts, State) -> %%=================================================================== %% peer_up/3 -peer_up(_SvcName, _Peer, State) -> - ?LOG(debug, "peer_up: ~p~n", [_Peer]), +peer_up(_SvcName, {_, #diameter_caps{origin_host = {OH, _}}}, State) -> + ?LOG(info, "Diameter peer FSM for ~p changed to state UP", [OH]), State. %% peer_down/3 -peer_down(SvcName, Peer, State) -> +peer_down(SvcName, {_, #diameter_caps{origin_host = {OH, _}}} = Peer, State) -> ergw_aaa_diameter_srv:peer_down(?MODULE, SvcName, Peer), - ?LOG(debug, "peer_down: ~p~n", [Peer]), + ?LOG(info, "Diameter peer FSM for ~p changed to state DOWN", [OH]), State. %% pick_peer/5 @@ -275,9 +274,11 @@ prepare_retransmit(_Pkt, _SvcName, _Peer, _CallOpts) -> %% handle_answer/5 handle_answer(#diameter_packet{msg = Msg, errors = Errors}, - _Request, SvcName, Peer, _CallOpts) + _Request, SvcName, {_, #diameter_caps{origin_host = {OH, _}}} = Peer, _CallOpts) when length(Errors) /= 0 -> - ?LOG(error, "~p: decode of answer ~p from ~p failed, errors ~p", [SvcName, Msg, Peer, Errors]), + %% the exact content of Errors is a bit unclear, dumping them is best we can do + ?LOG(error, "~0tp: decode of Diameter answer ~0tp from ~0tp failed, errors ~0tp", + [SvcName, Msg, OH, Errors]), ok = ergw_aaa_diameter_srv:finish_request(SvcName, Peer), case Msg of [_ | #{'Result-Code' := RC}] -> {error, RC}; %% try to handle gracefully @@ -299,8 +300,10 @@ handle_error(Reason, _Request, SvcName, Peer, CallOpts) -> handle_request(#diameter_packet{msg = [Command | Avps]}, _SvcName, Peer) when Command =:= 'ASR'; Command =:= 'RAR' -> handle_common_request(Command, Avps, Peer); -handle_request(_Packet, _SvcName, _Peer) -> - erlang:error({unexpected, ?MODULE, ?LINE}). +handle_request(Packet, SvcName, {_, #diameter_caps{origin_host = {OH, _}}}) -> + ?LOG(error, "~0tp: unsupported Diameter request from peer ~p, raw request ~0tp", + [SvcName, OH, Packet]), + {answer_message, 3001}. %% DIAMETER_COMMAND_UNSUPPORTED %%%=================================================================== %%% Options Validation @@ -619,7 +622,7 @@ handle_common_request(Command, #{'Session-Id' := SessionId} = Avps, {_PeerRef, C 'Session-Id' => SessionId}, ReplyCode = diameter_reply_code(Command), ReplyAvps = diameter_reply_avps(Result, ReplyAvps2), - ?LOG(error, "~p reply Avps: ~p", [Command, ReplyAvps]), + ?LOG(debug, "~p reply Avps: ~p", [Command, ReplyAvps]), {reply, [ReplyCode | ReplyAvps]}. filter_reply_avps('RAR', Avps) -> diff --git a/src/ergw_aaa_radius.erl b/src/ergw_aaa_radius.erl index 253beb3..0f5dbfe 100644 --- a/src/ergw_aaa_radius.erl +++ b/src/ergw_aaa_radius.erl @@ -213,7 +213,8 @@ validate_host(Opt, Host) {ok, #hostent{h_addr_list = [IP | _]}} -> IP; _ -> - ?LOG(error, "can't resolve remote RADIUS server name '~s'", [Host]), + ?LOG(emergency, "unable to resolve remote RADIUS server name '~s' to IPv4 address", + [Host]), erlang:error(badarg, [Opt, Host]) end; validate_host(_Opt, {_,_,_,_} = IP) -> @@ -810,16 +811,16 @@ to_session_opts({#attribute{name = "X_" ++ Name} = Attr, Value}, SOpts) -> to_session_opts({#attribute{name = Name} = Attr, Value}, SOpts) -> to_session_opts(Attr, catch (list_to_existing_atom(Name)), Value, SOpts); to_session_opts({Attr, Value}, SOpts) -> - ?LOG(debug, "unhandled undecoded reply AVP: ~0p: ~0p", [Attr, Value]), + ?LOG(warning, "unsupported, undecoded AVP in reply: ~0tp: ~0tp", [Attr, Value]), SOpts. %% Service-Type = Framed-User to_session_opts(_Attr, 'Service-Type', 2, SOpts) -> SOpts#{'Service-Type' => 'Framed-User'}; -to_session_opts(_Attr, 'Service-Type', Value, _SOpts) -> - ?LOG(debug, "unexpected Value in Service-Type: ~p", [Value]), - throw(?AAA_ERR(?FATAL)); +to_session_opts(_Attr, 'Service-Type', Value, SOpts) -> + ?LOG(warning, "unsupported value for RADIUS Service-Type in reply: ~p", [Value]), + SOpts; %% Framed-Protocol = PPP to_session_opts(_Attr, 'Framed-Protocol', 1, SOpts) -> @@ -827,9 +828,9 @@ to_session_opts(_Attr, 'Framed-Protocol', 1, SOpts) -> %% Framed-Protocol = GPRS-PDP-Context to_session_opts(_Attr, 'Framed-Protocol', 7, SOpts) -> SOpts#{'Framed-Protocol' => 'GPRS-PDP-Context'}; -to_session_opts(_Attr, 'Framed-Protocol', Value, _SOpts) -> - ?LOG(debug, "unexpected Value in Framed-Protocol: ~p", [Value]), - throw(?AAA_ERR(?FATAL)); +to_session_opts(_Attr, 'Framed-Protocol', Value, SOpts) -> + ?LOG(warning, "unsupported value for RADIUS Framed-Protocol in reply: ~p", [Value]), + SOpts; %% Alc-Primary-Dns to_session_opts(_Attr, 'Alc-Primary-DNS', DNS, SOpts) -> diff --git a/src/ergw_aaa_radius_handler.erl b/src/ergw_aaa_radius_handler.erl index 27f9a28..37952bc 100644 --- a/src/ergw_aaa_radius_handler.erl +++ b/src/ergw_aaa_radius_handler.erl @@ -37,9 +37,9 @@ radius_request(#radius_request{cmd = discreq, attrs = Attrs} = Req, _NasProp, _A end, {reply, Req#radius_request{cmd = Cmd}}; -radius_request(#radius_request{} = Request, _NasProp, _Args) -> - ?LOG(warning, "Unhandled radius request: ~p", [Request]), - {reply, Request}. +radius_request(#radius_request{}, _NasProp, _Args) -> + %% unsupported requests, eradius_server will logs the `noreply` as an error, no need to duplicate that + noreply. to_session_id(HexSessionId) -> H = fun(N) when N < 58 -> N - 48; diff --git a/src/ergw_aaa_rf.erl b/src/ergw_aaa_rf.erl index b430b5b..870a2a8 100644 --- a/src/ergw_aaa_rf.erl +++ b/src/ergw_aaa_rf.erl @@ -190,14 +190,14 @@ handle_response(_Promise, _Msg, Session, Events, _Opts, State) -> %%=================================================================== %% peer_up/3 -peer_up(_SvcName, _Peer, State) -> - ?LOG(debug, "peer_up: ~p~n", [_Peer]), +peer_up(_SvcName, {_, #diameter_caps{origin_host = {OH, _}}}, State) -> + ?LOG(info, "Diameter peer FSM for ~p changed to state UP", [OH]), State. %% peer_down/3 -peer_down(SvcName, Peer, State) -> +peer_down(SvcName, {_, #diameter_caps{origin_host = {OH, _}}} = Peer, State) -> ergw_aaa_diameter_srv:peer_down(?MODULE, SvcName, Peer), - ?LOG(debug, "peer_down: ~p~n", [Peer]), + ?LOG(info, "Diameter peer FSM for ~p changed to state DOWN", [OH]), State. %% pick_peer/5 @@ -231,9 +231,11 @@ prepare_retransmit(_Pkt, _SvcName, _Peer, _CallOpts) -> %% handle_answer/5 handle_answer(#diameter_packet{msg = Msg, errors = Errors}, - _Request, SvcName, Peer, _CallOpts) + _Request, SvcName, {_, #diameter_caps{origin_host = {OH, _}}} = Peer, _CallOpts) when length(Errors) /= 0 -> - ?LOG(error, "~p: decode of answer from ~p failed, errors ~p", [SvcName, Peer, Errors]), + %% the exact content of Errors is a bit unclear, dumping them is best we can do + ?LOG(error, "~0tp: decode of Diameter answer ~0tp from ~0tp failed, errors ~0tp", + [SvcName, Msg, OH, Errors]), ok = ergw_aaa_diameter_srv:finish_request(SvcName, Peer), case Msg of [_ | #{'Result-Code' := RC}] -> {error, RC}; %% try to handle gracefully diff --git a/src/ergw_aaa_ro.erl b/src/ergw_aaa_ro.erl index 0634417..4f3258c 100644 --- a/src/ergw_aaa_ro.erl +++ b/src/ergw_aaa_ro.erl @@ -190,14 +190,14 @@ handle_response(_Promise, _Msg, Session, Events, _Opts, State) -> %%=================================================================== %% peer_up/3 -peer_up(_SvcName, _Peer, State) -> - ?LOG(debug, "peer_up: ~p~n", [_Peer]), +peer_up(_SvcName, {_, #diameter_caps{origin_host = {OH, _}}}, State) -> + ?LOG(info, "Diameter peer FSM for ~p changed to state UP", [OH]), State. %% peer_down/3 -peer_down(SvcName, Peer, State) -> +peer_down(SvcName, {_, #diameter_caps{origin_host = {OH, _}}} = Peer, State) -> ergw_aaa_diameter_srv:peer_down(?MODULE, SvcName, Peer), - ?LOG(debug, "peer_down: ~p~n", [Peer]), + ?LOG(info, "Diameter peer FSM for ~p changed to state DOWN", [OH]), State. %% pick_peer/5 @@ -232,9 +232,11 @@ prepare_retransmit(_Pkt, _SvcName, _Peer, _CallOpts) -> %% handle_answer/5 handle_answer(#diameter_packet{msg = Msg, errors = Errors}, - _Request, SvcName, Peer, CallOpts) + _Request, SvcName, {_, #diameter_caps{origin_host = {OH, _}}} = Peer, CallOpts) when length(Errors) /= 0 -> - ?LOG(error, "~p: decode of answer from ~p failed, errors ~p", [SvcName, Peer, Errors]), + %% the exact content of Errors is a bit unclear, dumping them is best we can do + ?LOG(error, "~0tp: decode of Diameter answer ~0tp from ~0tp failed, errors ~0tp", + [SvcName, Msg, OH, Errors]), ok = ergw_aaa_diameter_srv:finish_request(SvcName, Peer), Code = case Msg of @@ -276,9 +278,9 @@ maybe_retry(Reason, SvcName, Peer, CallOpts) -> handle_request(#diameter_packet{msg = [Command | Avps]}, _SvcName, Peer) when Command =:= 'ASR'; Command =:= 'RAR' -> handle_common_request(Command, Avps, Peer); -handle_request(_Packet, _SvcName, {_PeerRef, _Caps} = _Peer) -> - ?LOG(error, "~p:handle_request(~p, ~p, ~p)", - [?MODULE, _Packet, _SvcName, _Caps]), +handle_request(Packet, SvcName, {_, #diameter_caps{origin_host = {OH, _}}}) -> + ?LOG(error, "~0tp: unsupported Diameter request from peer ~p, raw request ~0tp", + [SvcName, OH, Packet]), {answer_message, 3001}. %% DIAMETER_COMMAND_UNSUPPORTED %%%=================================================================== @@ -359,7 +361,6 @@ handle_cca({error, Code} = Result, Session, Events, _Opts, State) when is_integer(Code) -> {Result, Session, [{stop, {?API, peer_reject}} | Events], State#state{state = stopped}}; handle_cca({error, Reason} = Result, Session, Events, _Opts, State) -> - ?LOG(error, "CCA Result: ~p", [Result]), {Result, Session, [{stop, {?API, Reason}} | Events], State#state{state = stopped}}. handle_common_request(Command, #{'Session-Id' := SessionId} = Avps, {_PeerRef, Caps}) -> @@ -768,11 +769,9 @@ request_credits(Session, MSCC) -> Credits = maps:get(credits, Session, #{}), maps:fold( fun(RatingGroup, empty, Request) -> - ?LOG(warning, "Ro Charging Key: ~p", [RatingGroup]), RSU = [{'Requested-Service-Unit', #{}}], merge_mscc(RatingGroup, RSU, Request); - (RatingGroup, _, Request) -> - ?LOG(error, "unknown Ro Rating Group: ~p", [RatingGroup]), + (_, _, Request) -> Request end, MSCC, Credits). diff --git a/src/ergw_aaa_session.erl b/src/ergw_aaa_session.erl index 35f4eea..015200b 100644 --- a/src/ergw_aaa_session.erl +++ b/src/ergw_aaa_session.erl @@ -219,17 +219,6 @@ handle_event({call, From}, {set, Values}, _State, Data) -> handle_event({call, From}, {unset, Options}, _State, Data = #data{session = Session}) -> {keep_state, Data#data{session = maps:without(Options, Session)}, [{reply, From, ok}]}; -handle_event(info, {'EXIT', Owner, normal = Reason}, - _State, #data{owner = Owner} = Data) -> - ?LOG(debug, "Received EXIT signal for ~p with reason ~p", [Owner, Reason]), - terminate_action(Data), - {stop, normal}; -handle_event(info, {'EXIT', Owner, Reason}, - _State, #data{owner = Owner} = Data) -> - ?LOG(error, "Received EXIT signal for ~p with reason ~p", [Owner, Reason]), - terminate_action(Data), - {stop, normal}; - handle_event(info, {'EXIT', _From, _Reason}, _State, _Data) -> %% ignore EXIT from eradius client keep_state_and_data; @@ -294,17 +283,21 @@ handle_event({call, From}, {invoke, SessionOpts, Procedure, Opts}, {keep_state, Data, [{reply, From, Reply}]} end; -handle_event(cast, terminate, _State, Data) -> - ?LOG(info, "Handling terminate request: ~p", [Data]), +handle_event(cast, terminate, _State, #data{owner_monitor = MonRef} = Data) -> + ?LOG(debug, "handling terminate request: ~p", [Data]), + demonitor(MonRef, [flush]), terminate_action(Data), {stop, normal}; -handle_event(info, {'DOWN', _Ref, process, Owner, Info}, +handle_event(info, {'DOWN', _Ref, process, Owner, normal}, _State, #data{owner = Owner} = Data) -> - case Info of - normal -> ok; - _ -> ?LOG(error, "Received DOWN information for ~p with info ~p", [Data#data.owner, Info]) - end, + ?LOG(debug, "AAA session owner exited normally, terminating"), + terminate_action(Data), + {stop, normal}; +handle_event(info, {'DOWN', _Ref, process, Owner, Info}, + _State, #data{owner = Owner, session = Session} = Data) -> + ?LOG(debug, "AAA session owner exited with ~p, terminating. Session state: ~0tp", + [Info, Session]), terminate_action(Data), {stop, normal}; @@ -318,12 +311,13 @@ handle_event(info, {'$reply', Promise, Handler, Msg, Opts} = _Info, update_session(SessOut, EvsOut, Data), {keep_state, Data}; -handle_event(Type, Event, _State, _Data) -> - ?LOG(warning, "unhandled event ~p:~p", [Type, Event]), +handle_event(info, Info, State, _) -> + ?LOG(alert, "unexpected info message in state ~p, something important might have been missed: ~p", + [State, Info]), keep_state_and_data. terminate(Reason, Data) -> - ?LOG(error, "ctld Session terminating with state ~p with reason ~p", [Data, Reason]), + ?LOG(debug, "terminating with state ~p with reason ~p", [Data, Reason]), ok. code_change(_OldVsn, Data, _Extra) -> diff --git a/src/ergw_aaa_static.erl b/src/ergw_aaa_static.erl index 2520383..b6c7f0f 100644 --- a/src/ergw_aaa_static.erl +++ b/src/ergw_aaa_static.erl @@ -107,7 +107,8 @@ handle_response({API, _}, #{'Result-Code' := Code}, Session, Events, State) -> handle_response(Procedure, #{'Result-Code' := Code}, Session, Events, State) -> {{fail, Code}, Session, [{stop, {Procedure, peer_reject}} | Events], State}; handle_response(_Procedure, Response, Session, Events, State) -> - ?LOG(error, "Response: ~p", [Response]), + ?LOG(alert, "unexpected Diameter response, something important might have been missed: ~p", + [Response]), {Response, Session, Events, State}. get_state_atom(_) -> diff --git a/test/diameter_Gy_SUITE.erl b/test/diameter_Gy_SUITE.erl index be7a861..2a599d0 100644 --- a/test/diameter_Gy_SUITE.erl +++ b/test/diameter_Gy_SUITE.erl @@ -65,7 +65,7 @@ -define(CONFIG, #{rate_limits => - #{default => #{outstanding_requests => 1, rate => 10}}, + #{default => #{outstanding_requests => 10, rate => 10}}, functions => ?DIAMETER_FUNCTION, handlers => #{ergw_aaa_static => ?STATIC_CONFIG, @@ -142,6 +142,9 @@ all() -> terminate]. init_per_suite(Config0) -> + %% the overhead of logging interfers with the rate limit tests + logger:set_primary_config(level, none), + Config = [{handler_under_test, ?HUT} | Config0], application:load(ergw_aaa), diff --git a/test/diameter_Rf_SUITE.erl b/test/diameter_Rf_SUITE.erl index 609af6b..7985551 100644 --- a/test/diameter_Rf_SUITE.erl +++ b/test/diameter_Rf_SUITE.erl @@ -47,7 +47,7 @@ -define(CONFIG, #{rate_limits => - #{default => #{outstanding_requests => 3, rate => 20}}, + #{default => #{outstanding_requests => 20, rate => 20}}, functions => ?DIAMETER_FUNCTION, handlers => #{ergw_aaa_static => ?STATIC_CONFIG, @@ -94,6 +94,9 @@ all() -> ]. init_per_suite(Config0) -> + %% the overhead of logging interfers with the rate limit tests + logger:set_primary_config(level, none), + Config = [{handler_under_test, ?HUT} | Config0], application:load(ergw_aaa), diff --git a/test/diameter_test_server.erl b/test/diameter_test_server.erl index 38fcff7..c37fa7e 100644 --- a/test/diameter_test_server.erl +++ b/test/diameter_test_server.erl @@ -249,7 +249,6 @@ handle_request(#diameter_packet{msg = ['ACR' | Msg]}, _SvcName, {_, Caps}, _Extr #{'Session-Id' := Id, 'Accounting-Record-Type' := Type, 'Accounting-Record-Number' := Number} = Msg, - ct:pal("Received msg: ~p", [Msg]), ACA = #{'Session-Id' => Id, 'Result-Code' => 2001, 'Origin-Host' => OH,