Hi Daniel and others, I'm having a problem with acc module if I'm using the event_route/ branch-failure: say, the call comes from the app server and goes to the registered user. We arm the the failure route and per-branch failure route for the 302 redirect from the UA. We explicitly reset the accounting flags because we don't want to account the calls from the app server. The transaction is created implicitly by the t_relay().
Now if the UA responds with the 302 response and we are going to process that, we want to create an acc record for the new target from 302 message because this call may incur additional costs. I'm setting the accounting flags and calling t_flush_flags() but that doesn't work (no accounting record). Any idea if I'm doing something wrong or maybe there's a bug when changing the flags and then calling t_flush_flags from the event_route?
Here are the module parameters:
modparam("acc", "early_media", 0) modparam("acc", "report_ack", 0) modparam("acc", "report_cancels", 1) modparam("acc", "detect_direction", 1) modparam("acc", "db_flag", 1) modparam("acc", "db_missed_flag", 2) modparam("acc", "failed_transaction_flag", 3) modparam("acc", "db_url", PAIR_URL) modparam("acc", "db_extra", "src_user=$fU;src_domain=$fd;dst_ouser=$tU;dst_user=$rU;dst_domain=$rd") modparam("acc", "multi_leg_info", "src_leg=$avp(i:901);dst_leg=$avp(i:902)") modparam("acc", "time_mode", 2) modparam("acc", "time_attr", "time_hires") modparam("acc", "cdr_log_enable", 0)
FTR, we tried 4.1.6 and 4.1.8.
And here is the event route (with flags defined like this: flags FLAG_ACC_DB:1, FLAG_ACC_MISSED:2, FLAG_ACC_FAILED:3, ...):
event_route[tm:branch-failure:redirect] { route(ROUTE_STOP_RTPPROXY_BRANCH); if($T_rpl($rs) == 301 || $T_rpl($rs) == 302) { # initialise variables when entering failure route route(ROUTE_INITVARS);
# these need to be avps because we need it in reply/failure-route $(avp(s:from_faxserver)[*]) = 0; $(avp(s:to_faxserver)[*]) = 0; $(avp(s:cf_from_pstn)[*]) = 0; $(avp(s:from_pstn)[*]) = 0; $(avp(s:proxylu_from_pstn)[*]) = 0; $(avp(s:lcr_flags)[*]) = 0; $(avp(s:em_call)[*]) = 0; $(avp(s:from_pbx)[*]) = 0; $(avp(s:p_to_device)[*]) = 0; $(avp(s:p_to_group)[*]) = 0; $(avp(s:is_primary)[*]) = 0;
# now let's process a 30x $(avp(s:acc_state)[*]) = "cfb"; $(avp(s:orig_acc_caller_user)[*]) = $avp(s:acc_caller_user); $(avp(s:orig_acc_caller_domain)[*]) = $avp(s:acc_caller_domain); $(avp(s:acc_caller_user)[*]) = $avp(s:acc_callee_user); $(avp(s:acc_caller_domain)[*]) = $avp(s:acc_callee_domain); $(avp(s:caller_uuid)[*]) = $avp(s:callee_uuid); $(avp(s:callee_uuid)[*]) = $null; # the $var(no_acc) is 0 at this point but the flags may have been reset # if this is a call from PBX user - we do want accounting for the 302 redirect if(isflagset(FLAG_ACC_DB)) { xlog("L_NOTICE", "++++++ ACC flag is set - [% logreq -%]\n"); } else { xlog("L_NOTICE", "------ ACC flag is NOT set - [% logreq -%]\n"); } setflag(FLAG_ACC_FAILED); setflag(FLAG_ACC_DB); t_flush_flags();
# get last URI from destination-set and set it as R-URI $var(contact) = $T_rpl($ct); $var(contact) = $(var(contact){nameaddr.uri}); if($var(contact) == 0 || $var(contact) == $null) {
xlog("L_ERROR", "Failed to fetch contact '$ct' from 301/302 - [% logreq -%]\n"); acc_db_request("480", "acc"); $var(announce_handle) = "callee_tmp_unavailable"; $var(announce_set) = $xavp(callee_real_prefs[0]=>sound_set); $(avp(s:announce_code)[*]) = 480; $(avp(s:announce_reason)[*]) = "Temporarily Unavailable"; route(ROUTE_EARLY_REJECT); } $ru = $var(contact); xlog("L_NOTICE", "Redirect from UAC intercepted - [% logreq -%]\n"); $(avp(s:forwarder_cli_userprov)[*]) = $T_rpl($tU); $(avp(s:forwarder_domain_userprov)[*]) = $T_rpl($td); $var(forward) = 1; $var(redirected_forward) = 1; route(ROUTE_LOAD_CALLER_PREF); route(ROUTE_FIND_CALLEE); } }
Thanks.
Andrew
Hello,
I haven't used this event route and the flags, if they don't persist afterwards, then maybe it needs a patch to be fixed. Hugh implemented it, iirc, not sure if he was looking at this aspect.
Cheers, Daniel
On 26/05/15 16:14, Andrew Pogrebennyk wrote:
Hi Daniel and others, I'm having a problem with acc module if I'm using the event_route/ branch-failure: say, the call comes from the app server and goes to the registered user. We arm the the failure route and per-branch failure route for the 302 redirect from the UA. We explicitly reset the accounting flags because we don't want to account the calls from the app server. The transaction is created implicitly by the t_relay().
Now if the UA responds with the 302 response and we are going to process that, we want to create an acc record for the new target from 302 message because this call may incur additional costs. I'm setting the accounting flags and calling t_flush_flags() but that doesn't work (no accounting record). Any idea if I'm doing something wrong or maybe there's a bug when changing the flags and then calling t_flush_flags from the event_route?
Here are the module parameters:
modparam("acc", "early_media", 0) modparam("acc", "report_ack", 0) modparam("acc", "report_cancels", 1) modparam("acc", "detect_direction", 1) modparam("acc", "db_flag", 1) modparam("acc", "db_missed_flag", 2) modparam("acc", "failed_transaction_flag", 3) modparam("acc", "db_url", PAIR_URL) modparam("acc", "db_extra", "src_user=$fU;src_domain=$fd;dst_ouser=$tU;dst_user=$rU;dst_domain=$rd") modparam("acc", "multi_leg_info", "src_leg=$avp(i:901);dst_leg=$avp(i:902)") modparam("acc", "time_mode", 2) modparam("acc", "time_attr", "time_hires") modparam("acc", "cdr_log_enable", 0)
FTR, we tried 4.1.6 and 4.1.8.
And here is the event route (with flags defined like this: flags FLAG_ACC_DB:1, FLAG_ACC_MISSED:2, FLAG_ACC_FAILED:3, ...):
event_route[tm:branch-failure:redirect] { route(ROUTE_STOP_RTPPROXY_BRANCH); if($T_rpl($rs) == 301 || $T_rpl($rs) == 302) { # initialise variables when entering failure route route(ROUTE_INITVARS);
# these need to be avps because we need it in reply/failure-route $(avp(s:from_faxserver)[*]) = 0; $(avp(s:to_faxserver)[*]) = 0; $(avp(s:cf_from_pstn)[*]) = 0; $(avp(s:from_pstn)[*]) = 0; $(avp(s:proxylu_from_pstn)[*]) = 0; $(avp(s:lcr_flags)[*]) = 0; $(avp(s:em_call)[*]) = 0; $(avp(s:from_pbx)[*]) = 0; $(avp(s:p_to_device)[*]) = 0; $(avp(s:p_to_group)[*]) = 0; $(avp(s:is_primary)[*]) = 0; # now let's process a 30x $(avp(s:acc_state)[*]) = "cfb"; $(avp(s:orig_acc_caller_user)[*]) = $avp(s:acc_caller_user); $(avp(s:orig_acc_caller_domain)[*]) = $avp(s:acc_caller_domain); $(avp(s:acc_caller_user)[*]) = $avp(s:acc_callee_user); $(avp(s:acc_caller_domain)[*]) = $avp(s:acc_callee_domain); $(avp(s:caller_uuid)[*]) = $avp(s:callee_uuid); $(avp(s:callee_uuid)[*]) = $null; # the $var(no_acc) is 0 at this point but the flags may have
been reset # if this is a call from PBX user - we do want accounting for the 302 redirect if(isflagset(FLAG_ACC_DB)) { xlog("L_NOTICE", "++++++ ACC flag is set - [% logreq -%]\n"); } else { xlog("L_NOTICE", "------ ACC flag is NOT set - [% logreq -%]\n"); } setflag(FLAG_ACC_FAILED); setflag(FLAG_ACC_DB); t_flush_flags();
# get last URI from destination-set and set it as R-URI $var(contact) = $T_rpl($ct); $var(contact) = $(var(contact){nameaddr.uri}); if($var(contact) == 0 || $var(contact) == $null) { xlog("L_ERROR", "Failed to fetch contact '$ct' from 301/302
- [% logreq -%]\n"); acc_db_request("480", "acc"); $var(announce_handle) = "callee_tmp_unavailable"; $var(announce_set) = $xavp(callee_real_prefs[0]=>sound_set); $(avp(s:announce_code)[*]) = 480; $(avp(s:announce_reason)[*]) = "Temporarily Unavailable"; route(ROUTE_EARLY_REJECT); } $ru = $var(contact); xlog("L_NOTICE", "Redirect from UAC intercepted - [% logreq -%]\n"); $(avp(s:forwarder_cli_userprov)[*]) = $T_rpl($tU); $(avp(s:forwarder_domain_userprov)[*]) = $T_rpl($td); $var(forward) = 1; $var(redirected_forward) = 1; route(ROUTE_LOAD_CALLER_PREF); route(ROUTE_FIND_CALLEE); }
}
Thanks.
Andrew
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
Hi Daniel, thanks for the answer, that's what I was thinking - maybe the flags do not persist or are destroyed after the per-branch failure route.
However, the t_flush_flags description says this function can be used in any route, so in should be fixed in the long term.. Let me check if I can come up with some workaround in config script for the time being.
Regards, Andrew
On 05/27/2015 08:19 AM, Daniel-Constantin Mierla wrote:
Hello,
I haven't used this event route and the flags, if they don't persist afterwards, then maybe it needs a patch to be fixed. Hugh implemented it, iirc, not sure if he was looking at this aspect.
Cheers, Daniel
Daniel, I'm reviving this old thread..
On 05/27/2015 01:40 PM, Andrew Pogrebennyk wrote:
thanks for the answer, that's what I was thinking - maybe the flags do not persist or are destroyed after the per-branch failure route.
However, the t_flush_flags description says this function can be used in any route, so in should be fixed in the long term.. Let me check if I can come up with some workaround in config script for the time being.
I didn't manage to come up with any workaround so far.
The problem appears if the initial call leg coming from, let's say, the application server didn't have the accounting flags set. Long story put short, if the UA responds with the 302 response and we are going to process that, we want to create an acc record for the new target from 302 message because this call may incur additional costs.
I'm setting the accounting flags and even calling t_flush_flags() but that doesn't work (no accounting record for INVITE with Call-ID: rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1).
if($var(redirected_forward) == 1) { setflag(FLAG_ACC_FAILED); setflag(FLAG_ACC_DB); t_flush_flags(); }
From attached log: root@sp2:~# grep -i acc kamailio.log Jun 17 11:49:38 sp2 proxy[12702]: INFO: <script>: Set callee dialogs: user, account to 'e59611e6-01de-424c-a04f-e977409c54f6/64' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: INFO: <script>: Set callee dialogs: totaluser, totalaccount to 'e59611e6-01de-424c-a04f-e977409c54f6/64' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: INFO: <script>: Set caller dialogs: totaluser, totaluserout, totalaccount, totalaccountout to '0214786f-eb1c-4865-95ba-65d8c1c0bf32/48' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: INFO: <script>: Set caller dialogs: user, userout, account, accountout to '0214786f-eb1c-4865-95ba-65d8c1c0bf32/48' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: NOTICE: <script>: Setting acc source-leg for uuid '0214786f-eb1c-4865-95ba-65d8c1c0bf32': '0214786f-eb1c-4865-95ba-65d8c1c0bf32|phone2|xxx.demo.mylocal.com|43221000202|||48|||0|call|77.244.249.126|1434534578.107169|||||||||||' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: NOTICE: <script>: ++++++ 2. ACC flag is set - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: NOTICE: <script>: Setting acc destination-leg for uuid 'e59611e6-01de-424c-a04f-e977409c54f6': '0||comx|64|0004399111111|e59611e6-01de-424c-a04f-e977409c54f6|test1|demo.mylocal.com|4399111111|xxx.demo.mylocal.com|0|||||||||||' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12695]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 2, reply code 100 Jun 17 11:49:38 sp2 proxy[12698]: INFO: <script>: Skip accounting for call from PBX to device - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jun 17 11:49:38 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 2, reply code 180 Jun 17 11:49:38 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 512, reply code 180 Jun 17 11:49:40 sp2 proxy[12695]: NOTICE: <script>: ------ 1. ACC flag is NOT set - R=sip:test1@10.15.20.112:5060 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: INFO: <script>: Set callee dialogs: user, account to '72d04db7-6fd2-47c3-95a7-5685a5297715/64' - R=sip:test2@demo.mylocal.com;alias=77.244.249.126~6774~1 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: INFO: <script>: Set callee dialogs: totaluser, totalaccount to '72d04db7-6fd2-47c3-95a7-5685a5297715/64' - R=sip:test2@demo.mylocal.com;alias=77.244.249.126~6774~1 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: INFO: <script>: Set caller dialogs: totaluser, totaluserout, totalaccount, totalaccountout to 'e59611e6-01de-424c-a04f-e977409c54f6/64' - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: INFO: <script>: Set caller dialogs: user, userout, account, accountout to 'e59611e6-01de-424c-a04f-e977409c54f6/64' - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: NOTICE: <script>: Setting acc source-leg for uuid 'e59611e6-01de-424c-a04f-e977409c54f6': 'e59611e6-01de-424c-a04f-e977409c54f6|test1|xxx.demo.mylocal.com|phone2||comx|64|||<null>|cfb|77.244.249.126|1434534580.186507|||||||||||' - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: NOTICE: <script>: ++++++ 2. ACC flag is set - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: NOTICE: <script>: Setting acc destination-leg for uuid '72d04db7-6fd2-47c3-95a7-5685a5297715': '0||comx|64|4399111112|72d04db7-6fd2-47c3-95a7-5685a5297715|test2|demo.mylocal.com|4399111112|demo.mylocal.com|0|||||||||||' - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:43 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 2, reply code 200 Jun 17 11:49:43 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 512, reply code 200 Jun 17 11:49:52 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8d2998) event type 2, reply code 200 Jun 17 11:49:52 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8d2998) event type 512, reply code 200 Jun 17 11:49:52 sp2 proxy[12696]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8ce000) event type 2, reply code 200 Jun 17 11:49:52 sp2 proxy[12696]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8ce000) event type 512, reply code 200
Note there are two different calls: Call-ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV is ingress one, which goes through sems application server and comes back as Call-ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1
We're accounting the ingress one but not the one with Call-ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 (due to highlighted line above: Skip accounting for call from PBX to device...), but if the device responds with 302 we want to account the INVITE and the BYE - this is what I'm trying to achieve.
I see that callback is invoked for the 200 OK to INVITE so in theory it should work, shouldn't it? But in fact I'm getting the BYE with Call-ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 but not the INVITE accounted.
mysql> select * from acc where id>11416\G *************************** 1. row *************************** id: 11420 method: INVITE from_tag: .gX8uom0bP5ROJMaEt1lxZbQpmknoGxP to_tag: 7F09755D-558142B20001BCFA-555E8700 callid: rOemTINsCbQspe1Vlje9nAK15SNy0DdV sip_code: 200 sip_reason: OK time: 2015-06-17 11:49:43 time_hires: 1434534583.250 src_leg: 0214786f-eb1c-4865-95ba-65d8c1c0bf32|phone2|xxx.demo.mylocal.com|43221000202|||48|||0|call|77.244.249.126|1434534578.107210||||||||||| dst_leg: 0||comx|64|0004399111111|e59611e6-01de-424c-a04f-e977409c54f6|test1|demo.mylocal.com|4399111111|xxx.demo.mylocal.com|0||||||||||| dst_user: test1 dst_ouser: test1 dst_domain: demo.mylocal.com src_user: phone2 src_domain: xxx.demo.mylocal.com *************************** 2. row *************************** id: 11422 method: BYE from_tag: 60106B3B-558142B20001C04C-54DE0700 to_tag: 7B3C0FA6-558142B40002EE78-EB1F1700 callid: rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 sip_code: 200 sip_reason: OK time: 2015-06-17 11:49:52 time_hires: 1434534592.380 src_leg: dst_leg: dst_user: 25704386 dst_ouser: test1 dst_domain: 127.0.0.1 src_user: phone2 src_domain: xxx.demo.mylocal.com *************************** 3. row *************************** id: 11424 method: BYE from_tag: .gX8uom0bP5ROJMaEt1lxZbQpmknoGxP to_tag: 7F09755D-558142B20001BCFA-555E8700 callid: rOemTINsCbQspe1Vlje9nAK15SNy0DdV sip_code: 200 sip_reason: OK time: 2015-06-17 11:49:52 time_hires: 1434534592.380 src_leg: dst_leg: dst_user: dst_ouser: 0004399111111 dst_domain: 127.0.0.1 src_user: phone2 src_domain: xxx.demo.mylocal.com 3 rows in set (0.00 sec)
root@sp2:~# kamailio -V version: kamailio 4.1.8 (x86_64/linux) flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 14:44:30 May 21 2015 with gcc 4.7.2
Here are the module parameters:
modparam("acc", "early_media", 0) modparam("acc", "report_ack", 0) modparam("acc", "report_cancels", 1) modparam("acc", "detect_direction", 1) modparam("acc", "db_flag", 1) modparam("acc", "db_missed_flag", 2) modparam("acc", "failed_transaction_flag", 3) modparam("acc", "db_url", PAIR_URL) modparam("acc", "db_extra", "src_user=$fU;src_domain=$fd;dst_ouser=$tU;dst_user=$rU;dst_domain=$rd") modparam("acc", "multi_leg_info", "src_leg=$avp(i:901);dst_leg=$avp(i:902)") modparam("acc", "time_mode", 2) modparam("acc", "time_attr", "time_hires") modparam("acc", "cdr_log_enable", 0)
And the relevant config code parts (with flags defined like this: flags FLAG_ACC_DB:1, FLAG_ACC_MISSED:2, FLAG_ACC_FAILED:3, ...):
event_route[tm:branch-failure:redirect] { [% debug_dump('start', 'redirect') %] route(ROUTE_STOP_RTPPROXY_BRANCH); if($T_rpl($rs) == 301 || $T_rpl($rs) == 302) { # initialise variables when entering failure route route(ROUTE_INITVARS);
# these need to be avps because we need it in reply/failure-route $(avp(s:from_faxserver)[*]) = 0; $(avp(s:to_faxserver)[*]) = 0; $(avp(s:cf_from_pstn)[*]) = 0; $(avp(s:from_pstn)[*]) = 0; $(avp(s:proxylu_from_pstn)[*]) = 0; $(avp(s:lcr_flags)[*]) = 0;
$(avp(s:em_call)[*]) = 0; $(avp(s:from_pbx)[*]) = 0; $(avp(s:p_to_device)[*]) = 0; $(avp(s:p_to_group)[*]) = 0; $(avp(s:is_primary)[*]) = 0;
# now let's process a 30x $(avp(s:acc_state)[*]) = "cfb"; $(avp(s:orig_acc_caller_user)[*]) = $avp(s:acc_caller_user); $(avp(s:orig_acc_caller_domain)[*]) = $avp(s:acc_caller_domain); $(avp(s:acc_caller_user)[*]) = $avp(s:acc_callee_user); $(avp(s:acc_caller_domain)[*]) = $avp(s:acc_callee_domain); $(avp(s:caller_uuid)[*]) = $avp(s:callee_uuid); $(avp(s:callee_uuid)[*]) = $null; $var(no_acc) = 0;
if(isflagset(FLAG_ACC_DB)) { xlog("L_NOTICE", "++++++ 1. ACC flag is set - [% logreq -%]\n"); } else { xlog("L_NOTICE", "------ 1. ACC flag is NOT set - [% logreq -%]\n"); }
# get last URI from destination-set and set it as R-URI $var(contact) = $T_rpl($ct); $var(contact) = $(var(contact){nameaddr.uri}); if($var(contact) == 0 || $var(contact) == $null) {
xlog("L_ERROR", "Failed to fetch contact '$ct' from 301/302 - [% logreq -%]\n"); acc_db_request("480", "acc"); $var(announce_handle) = "callee_tmp_unavailable"; $var(announce_set) = $xavp(callee_real_prefs[0]=>sound_set); $(avp(s:announce_code)[*]) = 480; $(avp(s:announce_reason)[*]) = "Temporarily Unavailable"; route(ROUTE_EARLY_REJECT); } $ru = $var(contact);
# not needed in per-branch failure route? #append_branch(); #t_on_branch("BRANCH_ROUTE_SBC");
xlog("L_NOTICE", "Redirect from UAC intercepted - [% logreq -%]\n"); $(avp(s:forwarder_cli_userprov)[*]) = $T_rpl($tU); $(avp(s:forwarder_domain_userprov)[*]) = $T_rpl($td); $var(forward) = 1; $var(redirected_forward) = 1; route(ROUTE_LOAD_CALLER_PREF); route(ROUTE_FIND_CALLEE); } [% debug_dump('end', 'redirect') %] }
######################################################################## # Request route 'usr-preferences-caller' ######################################################################## route[ROUTE_LOAD_CALLER_PREF] { [% debug_dump('start', 'ROUTE_LOAD_CALLER_PREF') %] route(ROUTE_CLEAR_CALLER_PREF);
# if we're coming from 302 redirect route we want acc now #even if previously the flags may have been NOT set
if($var(redirected_forward) == 1) { setflag(FLAG_ACC_FAILED); setflag(FLAG_ACC_DB); t_flush_flags(); }
xlog("L_INFO", "Load caller preferences for uuid '$avp(s:caller_uuid)' and domain '$var(pref_domain)' - [% logreq -%]\n"); if (!lua_run("ngcp_caller_usr_load", "$avp(s:caller_uuid)", "$var(pref_domain)")) { route(ROUTE_ADD_CALLINFO_REPLY); sl_send_reply("500", "Internal Error"); [% debug_dump('exit', 'ROUTE_LOAD_CALLER_PREF') %] exit; } ... }
######################################################################## # Request route 'acc-callee' ######################################################################## route[ROUTE_ACC_CALLEE] { [% debug_dump('start', 'ROUTE_ACC_CALLEE') %] if($var(proxylu_src) == 1 || $var(proxylu_dst_callee == 1)) { $(avp(s:callee_acc_proxylu)[*]) = 1; } else { $(avp(s:callee_acc_proxylu)[*]) = 0; } if(isflagset(FLAG_ACC_DB)) { xlog("L_NOTICE", "++++++ 2. ACC flag is set - [% logreq -%]\n"); } else { xlog("L_NOTICE", "------ 2. ACC flag is NOT set - [% logreq -%]\n"); }
$var(gpp) = $xavp(callee_real_prefs[0]=>gpp0); ... xlog("L_NOTICE", "Setting acc destination-leg for uuid '$avp(s:callee_uuid)': '$avp(s:callee_acc_proxylu)|$var(callee_ext_subscriber_id)|$var(callee_ext_contract_id)|$var(callee_account_id)|$avp(s:acc_callee_dialed)|$avp(s:callee_uuid)|$avp(s:acc_callee_user)|$avp(s:acc_callee_domain)|$avp(s:acc_callee_user_in)|$avp(s:acc_callee_domain_in)|$avp(s:lcr_flags)|$var(gpp)|' - [% logreq -%]\n"); $avp(i:902) = $_s($avp(s:callee_acc_proxylu)|$var(callee_ext_subscriber_id)|$var(callee_ext_contract_id)|$var(callee_account_id)|$avp(s:acc_callee_dialed)|$avp(s:callee_uuid)|$avp(s:acc_callee_user)|$avp(s:acc_callee_domain)|$avp(s:acc_callee_user_in)|$avp(s:acc_callee_domain_in)|$avp(s:lcr_flags)|) + $var(gpp) + "|"; [% debug_dump('end', 'ROUTE_ACC_CALLEE') %] }
Attaching debug with debug=4 for tm and acc. Hope that I've provided enough information to check this.
Regards, Andrew
Hi, ideas anyone?
BR, Andrew
On 06/17/2015 12:12 PM, Andrew Pogrebennyk wrote:
Daniel, I'm reviving this old thread..
On 05/27/2015 01:40 PM, Andrew Pogrebennyk wrote:
thanks for the answer, that's what I was thinking - maybe the flags do not persist or are destroyed after the per-branch failure route.
However, the t_flush_flags description says this function can be used in any route, so in should be fixed in the long term.. Let me check if I can come up with some workaround in config script for the time being.
I didn't manage to come up with any workaround so far.
The problem appears if the initial call leg coming from, let's say, the application server didn't have the accounting flags set. Long story put short, if the UA responds with the 302 response and we are going to process that, we want to create an acc record for the new target from 302 message because this call may incur additional costs.
I'm setting the accounting flags and even calling t_flush_flags() but that doesn't work (no accounting record for INVITE with Call-ID: rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1).
if($var(redirected_forward) == 1) { setflag(FLAG_ACC_FAILED); setflag(FLAG_ACC_DB); t_flush_flags(); }
From attached log:
root@sp2:~# grep -i acc kamailio.log Jun 17 11:49:38 sp2 proxy[12702]: INFO: <script>: Set callee dialogs: user, account to 'e59611e6-01de-424c-a04f-e977409c54f6/64' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: INFO: <script>: Set callee dialogs: totaluser, totalaccount to 'e59611e6-01de-424c-a04f-e977409c54f6/64' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: INFO: <script>: Set caller dialogs: totaluser, totaluserout, totalaccount, totalaccountout to '0214786f-eb1c-4865-95ba-65d8c1c0bf32/48' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: INFO: <script>: Set caller dialogs: user, userout, account, accountout to '0214786f-eb1c-4865-95ba-65d8c1c0bf32/48' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: NOTICE: <script>: Setting acc source-leg for uuid '0214786f-eb1c-4865-95ba-65d8c1c0bf32': '0214786f-eb1c-4865-95ba-65d8c1c0bf32|phone2|xxx.demo.mylocal.com|43221000202|||48|||0|call|77.244.249.126|1434534578.107169|||||||||||' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: NOTICE: <script>: ++++++ 2. ACC flag is set - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: NOTICE: <script>: Setting acc destination-leg for uuid 'e59611e6-01de-424c-a04f-e977409c54f6': '0||comx|64|0004399111111|e59611e6-01de-424c-a04f-e977409c54f6|test1|demo.mylocal.com|4399111111|xxx.demo.mylocal.com|0|||||||||||' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12695]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 2, reply code 100 Jun 17 11:49:38 sp2 proxy[12698]: INFO: <script>: Skip accounting for call from PBX to device - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jun 17 11:49:38 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 2, reply code 180 Jun 17 11:49:38 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 512, reply code 180 Jun 17 11:49:40 sp2 proxy[12695]: NOTICE: <script>: ------ 1. ACC flag is NOT set - R=sip:test1@10.15.20.112:5060 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: INFO: <script>: Set callee dialogs: user, account to '72d04db7-6fd2-47c3-95a7-5685a5297715/64' - R=sip:test2@demo.mylocal.com;alias=77.244.249.126~6774~1 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: INFO: <script>: Set callee dialogs: totaluser, totalaccount to '72d04db7-6fd2-47c3-95a7-5685a5297715/64' - R=sip:test2@demo.mylocal.com;alias=77.244.249.126~6774~1 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: INFO: <script>: Set caller dialogs: totaluser, totaluserout, totalaccount, totalaccountout to 'e59611e6-01de-424c-a04f-e977409c54f6/64' - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: INFO: <script>: Set caller dialogs: user, userout, account, accountout to 'e59611e6-01de-424c-a04f-e977409c54f6/64' - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: NOTICE: <script>: Setting acc source-leg for uuid 'e59611e6-01de-424c-a04f-e977409c54f6': 'e59611e6-01de-424c-a04f-e977409c54f6|test1|xxx.demo.mylocal.com|phone2||comx|64|||<null>|cfb|77.244.249.126|1434534580.186507|||||||||||' - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: NOTICE: <script>: ++++++ 2. ACC flag is set - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: NOTICE: <script>: Setting acc destination-leg for uuid '72d04db7-6fd2-47c3-95a7-5685a5297715': '0||comx|64|4399111112|72d04db7-6fd2-47c3-95a7-5685a5297715|test2|demo.mylocal.com|4399111112|demo.mylocal.com|0|||||||||||' - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:43 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 2, reply code 200 Jun 17 11:49:43 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 512, reply code 200 Jun 17 11:49:52 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8d2998) event type 2, reply code 200 Jun 17 11:49:52 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8d2998) event type 512, reply code 200 Jun 17 11:49:52 sp2 proxy[12696]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8ce000) event type 2, reply code 200 Jun 17 11:49:52 sp2 proxy[12696]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8ce000) event type 512, reply code 200
Note there are two different calls: Call-ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV is ingress one, which goes through sems application server and comes back as Call-ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1
We're accounting the ingress one but not the one with Call-ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 (due to highlighted line above: Skip accounting for call from PBX to device...), but if the device responds with 302 we want to account the INVITE and the BYE - this is what I'm trying to achieve.
I see that callback is invoked for the 200 OK to INVITE so in theory it should work, shouldn't it? But in fact I'm getting the BYE with Call-ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 but not the INVITE accounted.
mysql> select * from acc where id>11416\G *************************** 1. row *************************** id: 11420 method: INVITE from_tag: .gX8uom0bP5ROJMaEt1lxZbQpmknoGxP to_tag: 7F09755D-558142B20001BCFA-555E8700 callid: rOemTINsCbQspe1Vlje9nAK15SNy0DdV sip_code: 200 sip_reason: OK time: 2015-06-17 11:49:43 time_hires: 1434534583.250 src_leg: 0214786f-eb1c-4865-95ba-65d8c1c0bf32|phone2|xxx.demo.mylocal.com|43221000202|||48|||0|call|77.244.249.126|1434534578.107210||||||||||| dst_leg: 0||comx|64|0004399111111|e59611e6-01de-424c-a04f-e977409c54f6|test1|demo.mylocal.com|4399111111|xxx.demo.mylocal.com|0||||||||||| dst_user: test1 dst_ouser: test1 dst_domain: demo.mylocal.com src_user: phone2 src_domain: xxx.demo.mylocal.com *************************** 2. row *************************** id: 11422 method: BYE from_tag: 60106B3B-558142B20001C04C-54DE0700 to_tag: 7B3C0FA6-558142B40002EE78-EB1F1700 callid: rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 sip_code: 200 sip_reason: OK time: 2015-06-17 11:49:52 time_hires: 1434534592.380 src_leg: dst_leg: dst_user: 25704386 dst_ouser: test1 dst_domain: 127.0.0.1 src_user: phone2 src_domain: xxx.demo.mylocal.com *************************** 3. row *************************** id: 11424 method: BYE from_tag: .gX8uom0bP5ROJMaEt1lxZbQpmknoGxP to_tag: 7F09755D-558142B20001BCFA-555E8700 callid: rOemTINsCbQspe1Vlje9nAK15SNy0DdV sip_code: 200 sip_reason: OK time: 2015-06-17 11:49:52 time_hires: 1434534592.380 src_leg: dst_leg: dst_user: dst_ouser: 0004399111111 dst_domain: 127.0.0.1 src_user: phone2 src_domain: xxx.demo.mylocal.com 3 rows in set (0.00 sec)
root@sp2:~# kamailio -V version: kamailio 4.1.8 (x86_64/linux) flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 14:44:30 May 21 2015 with gcc 4.7.2
Here are the module parameters:
modparam("acc", "early_media", 0) modparam("acc", "report_ack", 0) modparam("acc", "report_cancels", 1) modparam("acc", "detect_direction", 1) modparam("acc", "db_flag", 1) modparam("acc", "db_missed_flag", 2) modparam("acc", "failed_transaction_flag", 3) modparam("acc", "db_url", PAIR_URL) modparam("acc", "db_extra", "src_user=$fU;src_domain=$fd;dst_ouser=$tU;dst_user=$rU;dst_domain=$rd") modparam("acc", "multi_leg_info", "src_leg=$avp(i:901);dst_leg=$avp(i:902)") modparam("acc", "time_mode", 2) modparam("acc", "time_attr", "time_hires") modparam("acc", "cdr_log_enable", 0)
And the relevant config code parts (with flags defined like this: flags FLAG_ACC_DB:1, FLAG_ACC_MISSED:2, FLAG_ACC_FAILED:3, ...):
event_route[tm:branch-failure:redirect] { [% debug_dump('start', 'redirect') %] route(ROUTE_STOP_RTPPROXY_BRANCH); if($T_rpl($rs) == 301 || $T_rpl($rs) == 302) { # initialise variables when entering failure route route(ROUTE_INITVARS);
# these need to be avps because we need it in reply/failure-route $(avp(s:from_faxserver)[*]) = 0; $(avp(s:to_faxserver)[*]) = 0; $(avp(s:cf_from_pstn)[*]) = 0; $(avp(s:from_pstn)[*]) = 0; $(avp(s:proxylu_from_pstn)[*]) = 0; $(avp(s:lcr_flags)[*]) = 0; $(avp(s:em_call)[*]) = 0; $(avp(s:from_pbx)[*]) = 0; $(avp(s:p_to_device)[*]) = 0; $(avp(s:p_to_group)[*]) = 0; $(avp(s:is_primary)[*]) = 0; # now let's process a 30x $(avp(s:acc_state)[*]) = "cfb"; $(avp(s:orig_acc_caller_user)[*]) = $avp(s:acc_caller_user); $(avp(s:orig_acc_caller_domain)[*]) = $avp(s:acc_caller_domain); $(avp(s:acc_caller_user)[*]) = $avp(s:acc_callee_user); $(avp(s:acc_caller_domain)[*]) = $avp(s:acc_callee_domain); $(avp(s:caller_uuid)[*]) = $avp(s:callee_uuid); $(avp(s:callee_uuid)[*]) = $null; $var(no_acc) = 0; if(isflagset(FLAG_ACC_DB)) { xlog("L_NOTICE", "++++++ 1. ACC flag is set - [% logreq -%]\n"); } else { xlog("L_NOTICE", "------ 1. ACC flag is NOT set - [% logreq
-%]\n"); }
# get last URI from destination-set and set it as R-URI $var(contact) = $T_rpl($ct); $var(contact) = $(var(contact){nameaddr.uri}); if($var(contact) == 0 || $var(contact) == $null) { xlog("L_ERROR", "Failed to fetch contact '$ct' from 301/302
[% logreq -%]\n"); acc_db_request("480", "acc"); $var(announce_handle) = "callee_tmp_unavailable"; $var(announce_set) = $xavp(callee_real_prefs[0]=>sound_set); $(avp(s:announce_code)[*]) = 480; $(avp(s:announce_reason)[*]) = "Temporarily Unavailable"; route(ROUTE_EARLY_REJECT); } $ru = $var(contact);
# not needed in per-branch failure route? #append_branch(); #t_on_branch("BRANCH_ROUTE_SBC"); xlog("L_NOTICE", "Redirect from UAC intercepted - [% logreq -%]\n"); $(avp(s:forwarder_cli_userprov)[*]) = $T_rpl($tU); $(avp(s:forwarder_domain_userprov)[*]) = $T_rpl($td); $var(forward) = 1; $var(redirected_forward) = 1; route(ROUTE_LOAD_CALLER_PREF); route(ROUTE_FIND_CALLEE);
} [% debug_dump('end', 'redirect') %]
}
######################################################################## # Request route 'usr-preferences-caller' ######################################################################## route[ROUTE_LOAD_CALLER_PREF] { [% debug_dump('start', 'ROUTE_LOAD_CALLER_PREF') %] route(ROUTE_CLEAR_CALLER_PREF);
# if we're coming from 302 redirect route we want acc now #even if previously the flags may have been NOT set if($var(redirected_forward) == 1) { setflag(FLAG_ACC_FAILED); setflag(FLAG_ACC_DB); t_flush_flags(); } xlog("L_INFO", "Load caller preferences for uuid
'$avp(s:caller_uuid)' and domain '$var(pref_domain)' - [% logreq -%]\n"); if (!lua_run("ngcp_caller_usr_load", "$avp(s:caller_uuid)", "$var(pref_domain)")) { route(ROUTE_ADD_CALLINFO_REPLY); sl_send_reply("500", "Internal Error"); [% debug_dump('exit', 'ROUTE_LOAD_CALLER_PREF') %] exit; } ... }
######################################################################## # Request route 'acc-callee' ######################################################################## route[ROUTE_ACC_CALLEE] { [% debug_dump('start', 'ROUTE_ACC_CALLEE') %] if($var(proxylu_src) == 1 || $var(proxylu_dst_callee == 1)) { $(avp(s:callee_acc_proxylu)[*]) = 1; } else { $(avp(s:callee_acc_proxylu)[*]) = 0; } if(isflagset(FLAG_ACC_DB)) { xlog("L_NOTICE", "++++++ 2. ACC flag is set - [% logreq -%]\n"); } else { xlog("L_NOTICE", "------ 2. ACC flag is NOT set - [% logreq -%]\n"); }
$var(gpp) = $xavp(callee_real_prefs[0]=>gpp0);
... xlog("L_NOTICE", "Setting acc destination-leg for uuid '$avp(s:callee_uuid)': '$avp(s:callee_acc_proxylu)|$var(callee_ext_subscriber_id)|$var(callee_ext_contract_id)|$var(callee_account_id)|$avp(s:acc_callee_dialed)|$avp(s:callee_uuid)|$avp(s:acc_callee_user)|$avp(s:acc_callee_domain)|$avp(s:acc_callee_user_in)|$avp(s:acc_callee_domain_in)|$avp(s:lcr_flags)|$var(gpp)|'
- [% logreq -%]\n"); $avp(i:902) =
$_s($avp(s:callee_acc_proxylu)|$var(callee_ext_subscriber_id)|$var(callee_ext_contract_id)|$var(callee_account_id)|$avp(s:acc_callee_dialed)|$avp(s:callee_uuid)|$avp(s:acc_callee_user)|$avp(s:acc_callee_domain)|$avp(s:acc_callee_user_in)|$avp(s:acc_callee_domain_in)|$avp(s:lcr_flags)|)
- $var(gpp) + "|"; [% debug_dump('end', 'ROUTE_ACC_CALLEE') %]
}
Attaching debug with debug=4 for tm and acc. Hope that I've provided enough information to check this.
Regards, Andrew
Hello,
grepping quickly the sources, it appears that the flags are propagated back in transaction, see:
modules/tm/t_reply.c:1060
I think the issue resides in the acc design, that prepares the request for accounting when the transaction is created, only if one of the accounting flags is set. It might be required to add a parameter to acc module for 'prepare always for accounting'.
Cheers, Daniel
On 20/07/15 12:56, Andrew Pogrebennyk wrote:
Hi, ideas anyone?
BR, Andrew
On 06/17/2015 12:12 PM, Andrew Pogrebennyk wrote:
Daniel, I'm reviving this old thread..
On 05/27/2015 01:40 PM, Andrew Pogrebennyk wrote:
thanks for the answer, that's what I was thinking - maybe the flags do not persist or are destroyed after the per-branch failure route.
However, the t_flush_flags description says this function can be used in any route, so in should be fixed in the long term.. Let me check if I can come up with some workaround in config script for the time being.
I didn't manage to come up with any workaround so far.
The problem appears if the initial call leg coming from, let's say, the application server didn't have the accounting flags set. Long story put short, if the UA responds with the 302 response and we are going to process that, we want to create an acc record for the new target from 302 message because this call may incur additional costs.
I'm setting the accounting flags and even calling t_flush_flags() but that doesn't work (no accounting record for INVITE with Call-ID: rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1).
if($var(redirected_forward) == 1) { setflag(FLAG_ACC_FAILED); setflag(FLAG_ACC_DB); t_flush_flags(); }
From attached log:
root@sp2:~# grep -i acc kamailio.log Jun 17 11:49:38 sp2 proxy[12702]: INFO: <script>: Set callee dialogs: user, account to 'e59611e6-01de-424c-a04f-e977409c54f6/64' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: INFO: <script>: Set callee dialogs: totaluser, totalaccount to 'e59611e6-01de-424c-a04f-e977409c54f6/64' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: INFO: <script>: Set caller dialogs: totaluser, totaluserout, totalaccount, totalaccountout to '0214786f-eb1c-4865-95ba-65d8c1c0bf32/48' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: INFO: <script>: Set caller dialogs: user, userout, account, accountout to '0214786f-eb1c-4865-95ba-65d8c1c0bf32/48' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: NOTICE: <script>: Setting acc source-leg for uuid '0214786f-eb1c-4865-95ba-65d8c1c0bf32': '0214786f-eb1c-4865-95ba-65d8c1c0bf32|phone2|xxx.demo.mylocal.com|43221000202|||48|||0|call|77.244.249.126|1434534578.107169|||||||||||' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: NOTICE: <script>: ++++++ 2. ACC flag is set - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12702]: NOTICE: <script>: Setting acc destination-leg for uuid 'e59611e6-01de-424c-a04f-e977409c54f6': '0||comx|64|0004399111111|e59611e6-01de-424c-a04f-e977409c54f6|test1|demo.mylocal.com|4399111111|xxx.demo.mylocal.com|0|||||||||||' - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV Jun 17 11:49:38 sp2 proxy[12695]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 2, reply code 100 Jun 17 11:49:38 sp2 proxy[12698]: INFO: <script>: Skip accounting for call from PBX to device - R=sip:test1@demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jun 17 11:49:38 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 2, reply code 180 Jun 17 11:49:38 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 512, reply code 180 Jun 17 11:49:40 sp2 proxy[12695]: NOTICE: <script>: ------ 1. ACC flag is NOT set - R=sip:test1@10.15.20.112:5060 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: INFO: <script>: Set callee dialogs: user, account to '72d04db7-6fd2-47c3-95a7-5685a5297715/64' - R=sip:test2@demo.mylocal.com;alias=77.244.249.126~6774~1 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: INFO: <script>: Set callee dialogs: totaluser, totalaccount to '72d04db7-6fd2-47c3-95a7-5685a5297715/64' - R=sip:test2@demo.mylocal.com;alias=77.244.249.126~6774~1 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: INFO: <script>: Set caller dialogs: totaluser, totaluserout, totalaccount, totalaccountout to 'e59611e6-01de-424c-a04f-e977409c54f6/64' - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: INFO: <script>: Set caller dialogs: user, userout, account, accountout to 'e59611e6-01de-424c-a04f-e977409c54f6/64' - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: NOTICE: <script>: Setting acc source-leg for uuid 'e59611e6-01de-424c-a04f-e977409c54f6': 'e59611e6-01de-424c-a04f-e977409c54f6|test1|xxx.demo.mylocal.com|phone2||comx|64|||<null>|cfb|77.244.249.126|1434534580.186507|||||||||||' - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: NOTICE: <script>: ++++++ 2. ACC flag is set - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:40 sp2 proxy[12695]: NOTICE: <script>: Setting acc destination-leg for uuid '72d04db7-6fd2-47c3-95a7-5685a5297715': '0||comx|64|4399111112|72d04db7-6fd2-47c3-95a7-5685a5297715|test2|demo.mylocal.com|4399111112|demo.mylocal.com|0|||||||||||' - R=sip:25704386@10.10.8.52:46637 ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 Jun 17 11:49:43 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 2, reply code 200 Jun 17 11:49:43 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8da308) event type 512, reply code 200 Jun 17 11:49:52 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8d2998) event type 2, reply code 200 Jun 17 11:49:52 sp2 proxy[12699]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8d2998) event type 512, reply code 200 Jun 17 11:49:52 sp2 proxy[12696]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8ce000) event type 2, reply code 200 Jun 17 11:49:52 sp2 proxy[12696]: DEBUG: acc [acc_logic.c:615]: tmcb_func(): acc callback called for t(0x7f421c8ce000) event type 512, reply code 200
Note there are two different calls: Call-ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV is ingress one, which goes through sems application server and comes back as Call-ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1
We're accounting the ingress one but not the one with Call-ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 (due to highlighted line above: Skip accounting for call from PBX to device...), but if the device responds with 302 we want to account the INVITE and the BYE - this is what I'm trying to achieve.
I see that callback is invoked for the 200 OK to INVITE so in theory it should work, shouldn't it? But in fact I'm getting the BYE with Call-ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 but not the INVITE accounted.
mysql> select * from acc where id>11416\G *************************** 1. row *************************** id: 11420 method: INVITE from_tag: .gX8uom0bP5ROJMaEt1lxZbQpmknoGxP to_tag: 7F09755D-558142B20001BCFA-555E8700 callid: rOemTINsCbQspe1Vlje9nAK15SNy0DdV sip_code: 200 sip_reason: OK time: 2015-06-17 11:49:43 time_hires: 1434534583.250 src_leg: 0214786f-eb1c-4865-95ba-65d8c1c0bf32|phone2|xxx.demo.mylocal.com|43221000202|||48|||0|call|77.244.249.126|1434534578.107210||||||||||| dst_leg: 0||comx|64|0004399111111|e59611e6-01de-424c-a04f-e977409c54f6|test1|demo.mylocal.com|4399111111|xxx.demo.mylocal.com|0||||||||||| dst_user: test1 dst_ouser: test1 dst_domain: demo.mylocal.com src_user: phone2 src_domain: xxx.demo.mylocal.com *************************** 2. row *************************** id: 11422 method: BYE from_tag: 60106B3B-558142B20001C04C-54DE0700 to_tag: 7B3C0FA6-558142B40002EE78-EB1F1700 callid: rOemTINsCbQspe1Vlje9nAK15SNy0DdV_pbx-1 sip_code: 200 sip_reason: OK time: 2015-06-17 11:49:52 time_hires: 1434534592.380 src_leg: dst_leg: dst_user: 25704386 dst_ouser: test1 dst_domain: 127.0.0.1 src_user: phone2 src_domain: xxx.demo.mylocal.com *************************** 3. row *************************** id: 11424 method: BYE from_tag: .gX8uom0bP5ROJMaEt1lxZbQpmknoGxP to_tag: 7F09755D-558142B20001BCFA-555E8700 callid: rOemTINsCbQspe1Vlje9nAK15SNy0DdV sip_code: 200 sip_reason: OK time: 2015-06-17 11:49:52 time_hires: 1434534592.380 src_leg: dst_leg: dst_user: dst_ouser: 0004399111111 dst_domain: 127.0.0.1 src_user: phone2 src_domain: xxx.demo.mylocal.com 3 rows in set (0.00 sec)
root@sp2:~# kamailio -V version: kamailio 4.1.8 (x86_64/linux) flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 14:44:30 May 21 2015 with gcc 4.7.2
Here are the module parameters:
modparam("acc", "early_media", 0) modparam("acc", "report_ack", 0) modparam("acc", "report_cancels", 1) modparam("acc", "detect_direction", 1) modparam("acc", "db_flag", 1) modparam("acc", "db_missed_flag", 2) modparam("acc", "failed_transaction_flag", 3) modparam("acc", "db_url", PAIR_URL) modparam("acc", "db_extra", "src_user=$fU;src_domain=$fd;dst_ouser=$tU;dst_user=$rU;dst_domain=$rd") modparam("acc", "multi_leg_info", "src_leg=$avp(i:901);dst_leg=$avp(i:902)") modparam("acc", "time_mode", 2) modparam("acc", "time_attr", "time_hires") modparam("acc", "cdr_log_enable", 0)
And the relevant config code parts (with flags defined like this: flags FLAG_ACC_DB:1, FLAG_ACC_MISSED:2, FLAG_ACC_FAILED:3, ...):
event_route[tm:branch-failure:redirect] { [% debug_dump('start', 'redirect') %] route(ROUTE_STOP_RTPPROXY_BRANCH); if($T_rpl($rs) == 301 || $T_rpl($rs) == 302) { # initialise variables when entering failure route route(ROUTE_INITVARS);
# these need to be avps because we need it in reply/failure-route $(avp(s:from_faxserver)[*]) = 0; $(avp(s:to_faxserver)[*]) = 0; $(avp(s:cf_from_pstn)[*]) = 0; $(avp(s:from_pstn)[*]) = 0; $(avp(s:proxylu_from_pstn)[*]) = 0; $(avp(s:lcr_flags)[*]) = 0; $(avp(s:em_call)[*]) = 0; $(avp(s:from_pbx)[*]) = 0; $(avp(s:p_to_device)[*]) = 0; $(avp(s:p_to_group)[*]) = 0; $(avp(s:is_primary)[*]) = 0; # now let's process a 30x $(avp(s:acc_state)[*]) = "cfb"; $(avp(s:orig_acc_caller_user)[*]) = $avp(s:acc_caller_user); $(avp(s:orig_acc_caller_domain)[*]) = $avp(s:acc_caller_domain); $(avp(s:acc_caller_user)[*]) = $avp(s:acc_callee_user); $(avp(s:acc_caller_domain)[*]) = $avp(s:acc_callee_domain); $(avp(s:caller_uuid)[*]) = $avp(s:callee_uuid); $(avp(s:callee_uuid)[*]) = $null; $var(no_acc) = 0; if(isflagset(FLAG_ACC_DB)) { xlog("L_NOTICE", "++++++ 1. ACC flag is set - [% logreq -%]\n"); } else { xlog("L_NOTICE", "------ 1. ACC flag is NOT set - [% logreq
-%]\n"); }
# get last URI from destination-set and set it as R-URI $var(contact) = $T_rpl($ct); $var(contact) = $(var(contact){nameaddr.uri}); if($var(contact) == 0 || $var(contact) == $null) { xlog("L_ERROR", "Failed to fetch contact '$ct' from 301/302
[% logreq -%]\n"); acc_db_request("480", "acc"); $var(announce_handle) = "callee_tmp_unavailable"; $var(announce_set) = $xavp(callee_real_prefs[0]=>sound_set); $(avp(s:announce_code)[*]) = 480; $(avp(s:announce_reason)[*]) = "Temporarily Unavailable"; route(ROUTE_EARLY_REJECT); } $ru = $var(contact);
# not needed in per-branch failure route? #append_branch(); #t_on_branch("BRANCH_ROUTE_SBC"); xlog("L_NOTICE", "Redirect from UAC intercepted - [% logreq -%]\n"); $(avp(s:forwarder_cli_userprov)[*]) = $T_rpl($tU); $(avp(s:forwarder_domain_userprov)[*]) = $T_rpl($td); $var(forward) = 1; $var(redirected_forward) = 1; route(ROUTE_LOAD_CALLER_PREF); route(ROUTE_FIND_CALLEE);
} [% debug_dump('end', 'redirect') %]
}
######################################################################## # Request route 'usr-preferences-caller' ######################################################################## route[ROUTE_LOAD_CALLER_PREF] { [% debug_dump('start', 'ROUTE_LOAD_CALLER_PREF') %] route(ROUTE_CLEAR_CALLER_PREF);
# if we're coming from 302 redirect route we want acc now #even if previously the flags may have been NOT set if($var(redirected_forward) == 1) { setflag(FLAG_ACC_FAILED); setflag(FLAG_ACC_DB); t_flush_flags(); } xlog("L_INFO", "Load caller preferences for uuid
'$avp(s:caller_uuid)' and domain '$var(pref_domain)' - [% logreq -%]\n"); if (!lua_run("ngcp_caller_usr_load", "$avp(s:caller_uuid)", "$var(pref_domain)")) { route(ROUTE_ADD_CALLINFO_REPLY); sl_send_reply("500", "Internal Error"); [% debug_dump('exit', 'ROUTE_LOAD_CALLER_PREF') %] exit; } ... }
######################################################################## # Request route 'acc-callee' ######################################################################## route[ROUTE_ACC_CALLEE] { [% debug_dump('start', 'ROUTE_ACC_CALLEE') %] if($var(proxylu_src) == 1 || $var(proxylu_dst_callee == 1)) { $(avp(s:callee_acc_proxylu)[*]) = 1; } else { $(avp(s:callee_acc_proxylu)[*]) = 0; } if(isflagset(FLAG_ACC_DB)) { xlog("L_NOTICE", "++++++ 2. ACC flag is set - [% logreq -%]\n"); } else { xlog("L_NOTICE", "------ 2. ACC flag is NOT set - [% logreq -%]\n"); }
$var(gpp) = $xavp(callee_real_prefs[0]=>gpp0);
... xlog("L_NOTICE", "Setting acc destination-leg for uuid '$avp(s:callee_uuid)': '$avp(s:callee_acc_proxylu)|$var(callee_ext_subscriber_id)|$var(callee_ext_contract_id)|$var(callee_account_id)|$avp(s:acc_callee_dialed)|$avp(s:callee_uuid)|$avp(s:acc_callee_user)|$avp(s:acc_callee_domain)|$avp(s:acc_callee_user_in)|$avp(s:acc_callee_domain_in)|$avp(s:lcr_flags)|$var(gpp)|'
- [% logreq -%]\n"); $avp(i:902) =
$_s($avp(s:callee_acc_proxylu)|$var(callee_ext_subscriber_id)|$var(callee_ext_contract_id)|$var(callee_account_id)|$avp(s:acc_callee_dialed)|$avp(s:callee_uuid)|$avp(s:acc_callee_user)|$avp(s:acc_callee_domain)|$avp(s:acc_callee_user_in)|$avp(s:acc_callee_domain_in)|$avp(s:lcr_flags)|)
- $var(gpp) + "|"; [% debug_dump('end', 'ROUTE_ACC_CALLEE') %]
}
Attaching debug with debug=4 for tm and acc. Hope that I've provided enough information to check this.
Regards, Andrew
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users