[SR-Users] Multiple radius responses on a missed call
Efelin Novak
efelin.novak at gmail.com
Fri Feb 8 10:21:55 CET 2013
Thanks Daniel,
I'll check it and post results here.
Efelin
2013/2/8 Daniel-Constantin Mierla <miconda at gmail.com>:
> 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 at dr.vm]
>> 0(5890) DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body
>> [<sip:5556003900000 at 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 at 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 at 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 at dr.vm
>> 0(5890) DEBUG: exec [exec_hf.c:267]:
>> SIP_HF_CONTACT=<sip:0221028400 at 192.168.21.106>
>> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_TO=<sip:5556003900000 at dr.vm>
>> 0(5890) DEBUG: exec [exec_hf.c:267]: SIP_HF_FROM="Janko"
>> <sip:0221028400 at 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 at ast-car.vm sip:0221028400 at dr.vm
>> 38e422e10af08b2e34d58e5b765e81d3 at 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 at dr.vm
>> [FAIL_TWO] Rerouted gw returned 486 0(5890) INFO: <script>: XLOG:
>> 38e422e10af08b2e34d58e5b765e81d3 at 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 at dr.vm>;tag=as5c1d222e
>> To: <sip:5556003900000 at dr.vm>;tag=as493d6134
>> Call-ID: 38e422e10af08b2e34d58e5b765e81d3 at 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 at dr.vm
>> [dialog:failed] Deleting 38e422e10af08b2e34d58e5b765e81d3 at 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='38e422e10af08b2e34d58e5b765e81d3 at dr.vm' 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 at 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 at 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 at 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 at 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 at lists.sip-router.org
> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
More information about the sr-users
mailing list