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

Daniel-Constantin Mierla miconda at gmail.com
Mon Jul 20 18:12:14 CEST 2015


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 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
>>
>>
> _______________________________________________
> 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://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Book: SIP Routing With Kamailio - http://www.asipto.com




More information about the sr-users mailing list