Re: [SR-Users] Multiple radius responses on a missed call

Thanks Daniel, I'll check it and post results here. Efelin 2013/2/8 Daniel-Constantin Mierla &lt;miconda(a)gmail.com&gt;om>: > Hello, > > there are different event logged for accounting: > - missed call event which is sent from the point of view of callee > - transaction answered which is sent from the point of view of caller > > In db (eg mysql) accounting, each event in stored in a different table. I > don't know how they are in radius. You probably get two missed call events > and one transaction answered. > > If you want only one, do not set the flag for missed calls. > > Cheers, > Daniel > > > On 2/7/13 9:23 PM, Efelin Novak wrote: >> >> Hi folks, >> >> I'd like to ask you how can I solve an issue when I'm receiving three >> RADIUS requests on one missed call. My scenario is as follows: >> >> A calls to B. B returns 503 error message, INIVITE is then sent to C >> and C sends 486. >> >> After first 503 I receive a first RADIUS request. This is correct. >> >> However after 486 I receive three RADIUS requests with different IDs. >> As you can see in a DEBUG one RADIUS is send after the SIP reply >> message is received and second and third RADIUS messages are sent >> after the SIP reply message is forwarded. >> >> I'd like to receive only two RADIUS messages. One after 503 and second >> after 486. >> >> >> FLT_ACC is defined as 1. My config is as follows: >> modparam("acc", "failed_transaction_flag", FLT_ACC) >> modparam("acc", "report_cancels", 1) >> modparam("acc", "report_ack", 0) >> modparam("acc", "detect_direction", 0) >> modparam("acc", "early_media", 0) >> modparam("acc", "log_level", 5) >> modparam("acc", "log_flag", 1) >> modparam("acc", "log_missed_flag", 1) >> modparam("acc_radius", "radius_config", >> "/etc/radiusclient-ng/radiusclient.conf") # This is the >> location of the configuration file of radius client >> modparam("acc_radius", "radius_flag", FLT_ACC) >> modparam("acc_radius", "radius_missed_flag", FLT_ACC) >> >> In a route I set setflag("FLT_ACC") only once per call. >> >> Here is the debug for debug level 7: >> 0(5890) DEBUG: <core> [parser/msg_parser.c:634]: SIP Reply (status): >> 0(5890) DEBUG: <core> [parser/msg_parser.c:636]: version: <SIP/2.0> >> 0(5890) DEBUG: <core> [parser/msg_parser.c:638]: status: <486> >> 0(5890) DEBUG: <core> [parser/msg_parser.c:640]: reason: <Busy here> >> 0(5890) DEBUG: <core> [parser/parse_via.c:1286]: Found param type >> 232, <branch> = <z9hG4bK8d9c.4438d232.1>; state=6 >> 0(5890) DEBUG: <core> [parser/parse_via.c:1286]: Found param type >> 234, <received> = <192.168.21.101>; state=16 >> 0(5890) DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, >> state=5 >> 0(5890) DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via >> found, flags=2 >> 0(5890) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this >> is the first via >> 0(5890) DEBUG: <core> [receive.c:149]: After parse_msg... >> 0(5890) DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=6 >> global id=5 T start=0xffffffff >> 0(5890) DEBUG: <core> [parser/parse_via.c:1286]: Found param type >> 232, <branch> = <z9hG4bK8d9c.e7b650e1.0>; state=16 >> 0(5890) DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, >> state=5 >> 0(5890) DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via >> found, flags=22 >> 0(5890) DEBUG: <core> [parser/msg_parser.c:524]: parse_headers: this >> is the second via >> 0(5890) DEBUG: <core> [parser/parse_via.c:1286]: Found param type >> 232, <branch> = <z9hG4bK463ae086>; state=6 >> 0(5890) DEBUG: <core> [parser/parse_via.c:1286]: Found param type >> 235, <rport> = <5060>; state=16 >> 0(5890) DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, >> state=5 >> 0(5890) DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via >> found, flags=22 >> 0(5890) DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: >> tag=as493d6134 >> 0(5890) DEBUG: <core> [parser/parse_to.c:802]: end of header reached, >> state=29 >> 0(5890) DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: >> get_hdr_field: <To> [42]; uri=[sip:5556003900000@dr.vm] >> 0(5890) DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body >> [<sip:5556003900000@dr.vm>] >> 0(5890) DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq >> <CSeq>: <102> <INVITE> >> 0(5890) DEBUG: tm [t_lookup.c:965]: DEBUG: t_reply_matching: hash >> 51672 label 590185284 branch 1 >> 0(5890) DEBUG: tm [t_lookup.c:1016]: DEBUG: t_reply_matching: reply >> matched (T=0x871afc98)! >> 0(5890) DEBUG: tm [t_hooks.c:288]: DBG: trans=0x871afc98, callback >> type 2, id 0 entered >> 0(5890) DEBUG: acc [acc_logic.c:537]: acc callback called for >> t(0x871afc98) event type 2, reply code 486 >> 0(5890) DEBUG: tm [t_hooks.c:288]: DBG: trans=0x871afc98, callback >> type 2, id 0 entered >> 0(5890) DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: >> tag=as5c1d222e >> 0(5890) DEBUG: <core> [parser/parse_to.c:802]: end of header reached, >> state=29 >> 0(5890) DEBUG: siptrace [siptrace.c:794]: storing info... >> 0(5890) DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=6 >> global id=6 T end=0x871afc98 >> 0(5890) DEBUG: tm [t_reply.c:2081]: DEBUG: reply_received: org. >> status uas=180, uac[1]=180 local=0 is_invite=1) >> 0(5890) DEBUG: tm [t_hooks.c:288]: DBG: trans=0x871afc98, callback >> type 4194304, id 0 entered >> 0(5890) DEBUG: siptrace [siptrace.c:794]: storing info... >> 0(5890) DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=6 >> global id=6 T start=0x871afc98 >> 0(5890) DEBUG: tm [t_lookup.c:1151]: DEBUG: t_check_msg: T already >> found! >> 0(5890) DEBUG: tmx [t_var.c:438]: reply code is <486> >> 0(5890) INFO: <script>: XLOG: 38e422e10af08b2e34d58e5b765e81d3(a)dr.vm >> [REPLY_TWO] Incoming reply code: 486 0(5890) DEBUG: tm >> [t_reply.c:1204]: ->>>>>>>>> T_code=180, new_code=486 >> 0(5890) DEBUG: tm [t_hooks.c:288]: DBG: trans=0x871afc98, callback >> type 128, id 0 entered >> 0(5890) DEBUG: acc [acc_logic.c:537]: acc callback called for >> t(0x871afc98) event type 128, reply code 486 >> 0(5890) acc [acc.c:275]: ACC: call missed: >> >> timestamp=1360265692;method=INVITE;from_tag=as5c1d222e;to_tag=as493d6134;call_id=38e422e10af08b2e34d58e5b765e81d3(a)dr.vm;code=486;reason=Busy >> here >> 0(5890) DEBUG: acc [acc.c:872]: missed event for engine: radius >> 0(5890) DEBUG: <core> [md5utils.c:67]: DEBUG: MD5 calculated: >> 6e1b9f35a8b3e65859e29aefc1c26fc3 >> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_CONTENT_LENGTH=262 >> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_CONTENT_TYPE=application/sdp >> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_SUPPORTED=replaces >> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_ALLOW=INVITE, ACK, >> CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO >> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_DATE=Thu, 07 Feb 2013 >> 19:35:53 GMT >> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_MAX_FORWARDS=68 >> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_USER_AGENT=Asterisk PBX >> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_CSEQ=102 INVITE >> 0(5890) DEBUG: exec [exec_hf.c:267]: >> SIP_HF_CALLID=38e422e10af08b2e34d58e5b765e81d3(a)dr.vm >> 0(5890) DEBUG: exec [exec_hf.c:267]: >> SIP_HF_CONTACT=<sip:0221028400@192.168.21.106> >> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_TO=<sip:5556003900000@dr.vm> >> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_FROM="Janko" >> <sip:0221028400@dr.vm>;tag=as5c1d222e >> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_VIA=SIP/2.0/UDP >> 192.168.21.100;branch=z9hG4bK8d9c.e7b650e1.0,SIP/2.0/UDP >> 192.168.21.106:5060;branch=z9hG4bK463ae086;rport=5060 >> 0(5890) DEBUG: exec [exec_mod.c:175]: executing >> [/opt/kamrouter/scripts/notify_reroute.sh 503 >> sip:3333003900000@ast-car.vm sip:0221028400@dr.vm >> 38e422e10af08b2e34d58e5b765e81d3(a)dr.vm] >> sh: /opt/kamrouter/scripts/notify_reroute.sh: not found >> 0(5890) INFO: <core> [main.c:797]: INFO: dont_fork turned on, living on >> 0(5890) DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=0 >> global id=0 T start=0x871afc98 >> 0(5890) DEBUG: tm [t_lookup.c:1151]: DEBUG: t_check_msg: T already >> found! >> 0(5890) DEBUG: tmx [t_var.c:438]: reply code is <486> >> 0(5890) INFO: <script>: XLOG: 38e422e10af08b2e34d58e5b765e81d3(a)dr.vm >> [FAIL_TWO] Rerouted gw returned 486 0(5890) INFO: <script>: XLOG: >> 38e422e10af08b2e34d58e5b765e81d3(a)dr.vm [aaa] VYMAZAVAM3 0(5890) DEBUG: >> tm [t_reply.c:1702]: DEBUG: relay_reply: branch=1, save=0, relay=1 >> 0(5890) DEBUG: <core> [msg_translator.c:1933]: old size: 572, new size: >> 485 >> 0(5890) DEBUG: <core> [msg_translator.c:1951]: >> build_res_from_sip_res: copied size: orig:110, new: 23, rest: 462 msg= >> SIP/2.0 486 Busy here >> Via: SIP/2.0/UDP 192.168.21.100;branch=z9hG4bK8d9c.e7b650e1.0 >> Via: SIP/2.0/UDP 192.168.21.106:5060;branch=z9hG4bK463ae086;rport=5060 >> From: "Janko" <sip:0221028400@dr.vm>;tag=as5c1d222e >> To: <sip:5556003900000@dr.vm>;tag=as493d6134 >> Call-ID: 38e422e10af08b2e34d58e5b765e81d3(a)dr.vm >> CSeq: 102 INVITE >> Server: Asterisk PBX 11.0.2 >> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, >> INFO, PUBLISH >> Supported: replaces, timer >> Content-Length: 0 >> >> >> 0(5890) DEBUG: tm [t_hooks.c:288]: DBG: trans=0x871afc98, callback >> type 1048576, id 0 entered >> 0(5890) DEBUG: dialog [dlg_hash.c:588]: ref dlg 0x871af3f0 with 1 -> 2 >> 0(5890) DEBUG: dialog [dlg_hash.c:590]: dialog id=3894 found on entry >> 2825 >> 0(5890) DEBUG: dialog [dlg_hash.c:940]: dialog 0x871af3f0 changed >> from state 2 to state 5, due event 4 (ref 2) >> 0(5890) DEBUG: dialog [dlg_hash.c:735]: ref dlg 0x871af3f0 with 1 -> 3 >> 0(5890) DEBUG: dialog [dlg_handlers.c:1469]: executing event_route 4 on >> state 5 >> 0(5890) INFO: <script>: XLOG: 38e422e10af08b2e34d58e5b765e81d3(a)dr.vm >> [dialog:failed] Deleting 38e422e10af08b2e34d58e5b765e81d3(a)dr.vm from >> dialogs and dstprefix_limit 0(5890) DEBUG: dialog [dlg_hash.c:753]: >> unref dlg 0x871af3f0 with 1 -> 2 >> 0(5890) DEBUG: dialog [dlg_handlers.c:543]: dialog 0x871af3f0 failed >> (negative reply) >> 0(5890) DEBUG: dialog [dlg_cb.c:256]: dialog=0x871af3f0, type=4 >> 0(5890) DEBUG: dialog [dlg_hash.c:643]: ref dlg 0x871af3f0 with 1 -> 3 >> 0(5890) DEBUG: dialog [dlg_hash.c:646]: dialog >> callid=&#39;38e422e10af08b2e34d58e5b765e81d3(a)dr.vm&#39; found >> on entry 2825, dir=1 >> 0(5890) DEBUG: dialog [dlg_var.c:203]: Internal var-list ((nil)): >> 0(5890) DEBUG: dialog [dlg_var.c:213]: Dialog var-list (0x871af6f8): >> 0(5890) DEBUG: dialog [dlg_var.c:218]: "ru"=sip:003900000@cr1.vm:5060 >> (flags 1) >> 0(5890) DEBUG: dialog [dlg_var.c:218]: d=0 (flags 1) >> 0(5890) DEBUG: dialog [dlg_var.c:218]: et=1360265682.889 (flags 1) >> 0(5890) DEBUG: dialog [dlg_var.c:218]: st=1360265682.889 (flags 1) >> 0(5890) DEBUG: dialog [dlg_hash.c:753]: unref dlg 0x871af3f0 with 1 -> 2 >> 0(5890) acc [acc_cdr.c:192]: st=1360265682.889; et=1360265682.889; d=0; >> c1= >> 0(5890) DEBUG: dialog [dlg_hash.c:753]: unref dlg 0x871af3f0 with 1 -> 1 >> 0(5890) DEBUG: dialog [dlg_handlers.c:937]: registering TMCB to wait >> for negative ACK >> 0(5890) DEBUG: dialog [dlg_hash.c:735]: ref dlg 0x871af3f0 with 1 -> 2 >> 0(5890) DEBUG: dialog [dlg_hash.c:753]: unref dlg 0x871af3f0 with 1 -> 1 >> 0(5890) DEBUG: tm [t_hooks.c:288]: DBG: trans=0x871afc98, callback >> type 512, id 0 entered >> 0(5890) DEBUG: acc [acc_logic.c:537]: acc callback called for >> t(0x871afc98) event type 512, reply code 486 >> 0(5890) acc [acc.c:275]: ACC: call missed: >> >> timestamp=1360265692;method=INVITE;from_tag=as5c1d222e;to_tag=as493d6134;call_id=38e422e10af08b2e34d58e5b765e81d3(a)dr.vm;code=486;reason=Busy >> here >> 0(5890) DEBUG: acc [acc.c:872]: missed event for engine: radius >> 0(5890) acc [acc.c:275]: ACC: transaction answered: >> >> timestamp=1360265692;method=INVITE;from_tag=as5c1d222e;to_tag=as493d6134;call_id=38e422e10af08b2e34d58e5b765e81d3(a)dr.vm;code=486;reason=Busy >> here >> 0(5890) DEBUG: acc [acc.c:867]: acc event for engine: radius >> 0(5890) DEBUG: tm [t_hooks.c:288]: DBG: trans=0x871afc98, callback >> type 8388608, id 0 entered >> >> Thanks for a help. >> >> Efelin >> >> _______________________________________________ >> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list >> sr-users(a)lists.sip-router.org >> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users > > > -- > Daniel-Constantin Mierla - http://www.asipto.com > http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda > Kamailio World Conference, April 16-17, 2013, Berlin > - http://conference.kamailio.com - > > > _______________________________________________ > SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list > sr-users(a)lists.sip-router.org > http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users