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

Andrew Pogrebennyk apogrebennyk at sipwise.com
Wed Jun 17 12:12:54 CEST 2015


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
-------------- next part --------------
A non-text attachment was scrubbed...
Name: kamailio.log.gz
Type: application/gzip
Size: 9946 bytes
Desc: not available
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20150617/fe958937/attachment.bin>


More information about the sr-users mailing list