[SR-Users] usage of t_flush_flags() in event_route

Andrew Pogrebennyk apogrebennyk at sipwise.com
Mon Jul 20 12:56:16 CEST 2015


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 at 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 at 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 at 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 at 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 at 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 at demo.mylocal.com ID=rOemTINsCbQspe1Vlje9nAK15SNy0DdV
>> Jun 17 11:49:38 sp2 proxy[12702]: NOTICE: <script>: ++++++ 2. ACC flag is set - R=sip:test1 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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
> 
> 



More information about the sr-users mailing list