[SR-Users] Multiple radius responses on a missed call
Efelin Novak
efelin.novak at gmail.com
Fri Feb 8 11:07:52 CET 2013
I'm little bit confused about a usage of radius acc_radius module.
Parameters from acc_radius module can also be found in acc module
after recompiling it with ENABLE_RADIUS_ACC=true.
Which one should I use? Which one is more up to date? What is the difference?
Cheers,
Efelin
2013/2/8 Efelin Novak <efelin.novak at gmail.com>:
> 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