[SR-Users] Problems with avp_db_load

Kevin Bushong kbushong at carnegietechnologies.com
Thu Mar 30 16:35:05 CEST 2017


I hope this helps.

Thanks, Kevin


Mar 30 09:47:26 Limitless-Calling-Server /usr/local/sbin/kamailio[7855]: ERROR: <script>: SCRIPT: Thu Mar 30 09:47:26 2017 15703771055 Registration request inbound for useragent type of pjsua2 Android 2.5.5-svn
Mar 30 09:47:26 Limitless-Calling-Server /usr/local/sbin/kamailio[7855]: ERROR: <script>: SCRIPT: Thu Mar 30 09:47:26 2017 15703771055 registered to usrloc db from 172.16.128.135 from useragent type of pjsua2 Android 2.5.5-svn
Mar 30 09:47:26 Limitless-Calling-Server /usr/local/sbin/kamailio[7855]: ERROR: <script>: SCRIPT: Thu Mar 30 09:47:26 2017 15703771055 Going to PUSHJOIN route 172.16.128.135 from useragent type of pjsua2 Android 2.5.5-svn
Mar 30 09:47:26 Limitless-Calling-Server /usr/local/sbin/kamailio[7855]: INFO: <script>: Got to PUSHJOIN ROUTE
Mar 30 09:47:26 Limitless-Calling-Server /usr/local/sbin/kamailio[7855]: INFO: <script>: tU variable is: 15703771055
Mar 30 09:47:26 Limitless-Calling-Server /usr/local/sbin/kamailio[7855]: INFO: <script>: Value of <null> = <null>
Mar 30 09:47:26 Limitless-Calling-Server /usr/local/sbin/kamailio[7855]: INFO: <script>: hjoin Var is: 0
Mar 30 09:47:42 Limitless-Calling-Server SpectrumMax[10399]: [FWD/UPDATE] Updating FWD for 15703771055
Mar 30 09:47:42 Limitless-Calling-Server SpectrumMax[10399]: [FWD/UPDATE] Update 15703771055 Unconditional to 12104471202
Mar 30 09:47:42 Limitless-Calling-Server SpectrumMax[10399]: [FWD/UPDATE] FWD settings for MDN already exist, deleting 15703771055 settings from the system
Mar 30 09:47:42 Limitless-Calling-Server SpectrumMax[10399]: [FWD/UPDATE] Completed updating fwd settings for 15703771055
Mar 30 09:47:42 Limitless-Calling-Server SpectrumMax[10399]: [FWD/UPDATE] Update 15703771055 Unconditional to
Mar 30 09:47:42 Limitless-Calling-Server SpectrumMax[10399]: [FWD/UPDATE] Completed updating fwd settings for 15703771055
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: Thu Mar 30 09:48:05 2017 - 15703771993 = (15703771993)
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: Thu Mar 30 09:48:05 2017 - Source IP = (172.16.128.135)
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: Thu Mar 30 09:48:05 2017 - MSRN IP = 172.16.128.140
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: Trunk for user is: 172.16.2.166:5060
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: Trunk Prefix for user is: +
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: Old ru = sip:15703771993 at limitless.sip.carnegietechnologies.com;transport=TCP
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: New ru = sip:+15703771993 at 172.16.2.166:5060
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: fU = 15703771055
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: DigitCheck rU = +1
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: rU = +15703771993
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: DigitCheck tU = 15
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: tU = 15703771993
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: fU = 15703771055
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7858]: ERROR: <script>: SCRIPT: +15703771993 made it to MANAGE_BRANCH  branch_route
Mar 30 09:48:05 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f]: Received command 'offer' from 127.0.0.1:55383
Mar 30 09:48:05 Limitless-Calling-Server rtpengine[902]: NOTICE: [f1852cf5-fad4-402a-a5f2-96594e77ab3f]: Creating new call
Mar 30 09:48:05 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f]: offer time = 0.000447 sec
Mar 30 09:48:05 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f]: Replying to 'offer' from 127.0.0.1:55383
Mar 30 09:48:05 Limitless-Calling-Server /usr/local/sbin/kamailio[7839]: ERROR: <script>: SCRIPT: <null> made it to MANAGE_REPLY  branch_route
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7840]: ERROR: <script>: SCRIPT: <null> made it to MANAGE_REPLY  branch_route
Mar 30 09:48:06 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f]: Received command 'answer' from 127.0.0.1:44470
Mar 30 09:48:06 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f]: answer time = 0.000118 sec
Mar 30 09:48:06 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f]: Replying to 'answer' from 127.0.0.1:44470
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: SCRIPT: To URI: 15703771993
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: SCRIPT: To Username: +15703771993
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: Thu Mar 30 09:48:06 2017 - 15703771993 = (15703771993)
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: Thu Mar 30 09:48:06 2017 - Source IP = (172.16.128.140)
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: Thu Mar 30 09:48:06 2017 - MSRN IP = 172.16.128.140
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: INFO: <script>: Sending push. From (15703771055) to (15703771993)
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: INFO: <script>: Push sent. From (15703771055) to (15703771993) result: 0
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: Thu Mar 30 09:48:06 2017 Call to 15703771993 made it into route[LOCATION] block
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: Thu Mar 30 09:48:06 2017 Call to 15703771993 made it into WITH_CFWD in route[LOCATION] block
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: script should load from DB usr_preferences next
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: DB load should be complete
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: SCRIPT: Thu Mar 30 09:48:06 2017 Call Forwarding Unconditional set to <null>
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: SCRIPT: Thu Mar 30 09:48:06 2017 Call Forwarding NoAnswer set to <null>
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: SCRIPT: Thu Mar 30 09:48:06 2017 Call Forwarding Busy set to <null>
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: INFO: avpops [avpops_impl.c:1473]: ops_print_avp(): p=0x7f440edada48, flags=0x0113
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: INFO: avpops [avpops_impl.c:1477]: ops_print_avp(): #011#011#011name=<direction>
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: INFO: avpops [avpops_impl.c:1485]: ops_print_avp(): #011#011#011val_str=<INCOMING / 8>
Mar 30 09:48:06 Limitless-Calling-Server /usr/local/sbin/kamailio[7830]: ERROR: <script>: SCRIPT: 15703771993 made it to MANAGE_BRANCH  branch_route
Mar 30 09:48:06 Limitless-Calling-Server rtpengine[902]: INFO: [57fea221-8ff2-1235-a08c-0cc47ab00eb4]: Received command 'offer' from 127.0.0.1:54526
Mar 30 09:48:06 Limitless-Calling-Server rtpengine[902]: NOTICE: [57fea221-8ff2-1235-a08c-0cc47ab00eb4]: Creating new call
Mar 30 09:48:06 Limitless-Calling-Server rtpengine[902]: INFO: [57fea221-8ff2-1235-a08c-0cc47ab00eb4]: offer time = 0.000172 sec
Mar 30 09:48:06 Limitless-Calling-Server rtpengine[902]: INFO: [57fea221-8ff2-1235-a08c-0cc47ab00eb4]: Replying to 'offer' from 127.0.0.1:54526
Mar 30 09:48:10 Limitless-Calling-Server /usr/local/sbin/kamailio[7855]: ERROR: <script>: SCRIPT: <null> made it to MANAGE_REPLY  branch_route
Mar 30 09:48:10 Limitless-Calling-Server /usr/local/sbin/kamailio[7855]: ERROR: <script>: SCRIPT: <null> made it to MANAGE_REPLY  branch_route
Mar 30 09:48:10 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f port 23108]: Confirmed peer address as 172.16.6.124:4542
Mar 30 09:48:10 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f port 23128]: Confirmed peer address as 172.16.128.135:4000
Mar 30 09:48:10 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f port 23128]: Kernelizing media stream: 172.16.128.135:4000
Mar 30 09:48:10 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f port 23108]: Kernelizing media stream: 172.16.6.124:4542
Mar 30 09:48:10 Limitless-Calling-Server /usr/local/sbin/kamailio[7838]: ERROR: <script>: SCRIPT: <null> made it to MANAGE_REPLY  branch_route
Mar 30 09:48:11 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f port 23129]: Confirmed peer address as 172.16.128.135:4001
Mar 30 09:48:11 Limitless-Calling-Server snmpd[856]: Connection from UDP: [172.16.128.30]:33122->[172.16.128.10]:161
Mar 30 09:48:11 Limitless-Calling-Server snmpd[856]: Connection from UDP: [172.16.128.30]:33122->[172.16.128.10]:161
Mar 30 09:48:17 Limitless-Calling-Server /usr/local/sbin/kamailio[7856]: ALERT: <script>: ALERT: Cancel WITH route relay reached
Mar 30 09:48:17 Limitless-Calling-Server /usr/local/sbin/kamailio[7841]: ERROR: <script>: SCRIPT: <null> made it to MANAGE_REPLY  branch_route
Mar 30 09:48:17 Limitless-Calling-Server /usr/local/sbin/kamailio[7841]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: call missed: timestamp=1490881697;method=INVITE;from_tag=85682aa1-23ed-4c9c-a15c-0234eeafb9a5;to_tag=00001387282420;call_id=f1852cf5-fad4-402a-a5f2-96594e77ab3f;code=487;reason=Request Terminated;src_user=15703771055;src_domain=limitless.sip.carnegietechnologies.com;src_ip=172.16.128.135;dst_ouser=15703771993;dst_user=+15703771993;dst_domain=172.16.2.166;leg_src_cfwd=;leg_dst_cfwd=
Mar 30 09:48:17 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f]: Received command 'delete' from 127.0.0.1:39687
Mar 30 09:48:17 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f]: Scheduling deletion of call branch '85682aa1-23ed-4c9c-a15c-0234eeafb9a5' (via-branch '') in 30 seconds
Mar 30 09:48:17 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f]: delete time = 0.000182 sec
Mar 30 09:48:17 Limitless-Calling-Server rtpengine[902]: INFO: [f1852cf5-fad4-402a-a5f2-96594e77ab3f]: Replying to 'delete' from 127.0.0.1:39687
Mar 30 09:48:17 Limitless-Calling-Server /usr/local/sbin/kamailio[7841]: ERROR: <script>: SCRIPT: +15703771993 made it to MANAGE_FAILURE branch_route
Mar 30 09:48:17 Limitless-Calling-Server /usr/local/sbin/kamailio[7841]: NOTICE: acc [acc_cdr.c:352]: log_write_cdr(): start_time=1490881685.822; end_time=1490881685.822; duration=0
Mar 30 09:48:17 Limitless-Calling-Server /usr/local/sbin/kamailio[7832]: ALERT: <script>: ALERT: Cancel WITH route relay reached
Mar 30 09:48:17 Limitless-Calling-Server /usr/local/sbin/kamailio[7857]: ERROR: <script>: SCRIPT: <null> made it to MANAGE_REPLY  branch_route
Mar 30 09:48:17 Limitless-Calling-Server /usr/local/sbin/kamailio[7857]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: call missed: timestamp=1490881697;method=INVITE;from_tag=2ytKc5r8g9BHS;to_tag=44b94e17-e3bb-4d82-84b7-c3a46d9fe385;call_id=57fea221-8ff2-1235-a08c-0cc47ab00eb4;code=487;reason=Request Terminated;src_user=15703771055;src_domain=172.16.128.140;src_ip=172.16.128.140;dst_ouser=+15703771993;dst_user=15703771993;dst_domain=127.0.0.1;leg_src_cfwd=;leg_dst_cfwd=
Mar 30 09:48:17 Limitless-Calling-Server rtpengine[902]: INFO: [57fea221-8ff2-1235-a08c-0cc47ab00eb4]: Received command 'delete' from 127.0.0.1:45696
Mar 30 09:48:17 Limitless-Calling-Server rtpengine[902]: INFO: [57fea221-8ff2-1235-a08c-0cc47ab00eb4]: Scheduling deletion of call branch '2ytKc5r8g9BHS' (via-branch '') in 30 seconds
Mar 30 09:48:17 Limitless-Calling-Server rtpengine[902]: INFO: [57fea221-8ff2-1235-a08c-0cc47ab00eb4]: delete time = 0.000074 sec
Mar 30 09:48:17 Limitless-Calling-Server rtpengine[902]: INFO: [57fea221-8ff2-1235-a08c-0cc47ab00eb4]: Replying to 'delete' from 127.0.0.1:45696
Mar 30 09:48:17 Limitless-Calling-Server /usr/local/sbin/kamailio[7857]: ERROR: <script>: SCRIPT: 15703771993 made it to MANAGE_FAILURE branch_route
Mar 30 09:48:17 Limitless-Calling-Server /usr/local/sbin/kamailio[7857]: NOTICE: acc [acc_cdr.c:352]: log_write_cdr(): start_time=1490881686.274; end_time=1490881686.274; duration=0

From: sr-users [mailto:sr-users-bounces at lists.sip-router.org] On Behalf Of Daniel-Constantin Mierla
Sent: Thursday, March 30, 2017 2:23 AM
To: Kamailio (SER) - Users Mailing List <sr-users at lists.sip-router.org>
Subject: Re: [SR-Users] Problems with avp_db_load


Hello,

can you run with debug=3 in kamailio.cfg and send all the debug messages printed in syslog for this situation?

Cheers,
Daniel

On 29.03.17 20:48, Kevin Bushong wrote:
I am using the avpops module to read from a mysql database to look for CFWD information for the call.  When a call is placed, it appears the command avp_db_load attempts to read the file but all values come back as NULL.  There are no messages in the log and of course the call does not process correctly.


We are using a config that is exactly the same on a 4.3.4 version of kamailio using cento 6.7, with a local version of mysql  Ver 14.14 Distrib 5.1.73, that works perfectly.  When moving the code to kamailio 4.4.4 on Debian 8, Jessie, mysql  Ver 14.14 Distrib 5.5.53 the avp_db_load returns no information.

Here is the snippet of the code we are using.  Since I am not used to troubleshooting kamailio, please let me know what other information you need.

Thanks,

Kevin


Code snippet:

#!ifdef WITH_CFWD
        xlog ("$TF Call to $rU made it into WITH_CFWD in route[LOCATION] block\n");
        # Call forwarding is enabled, so lets do a lookup to pull all AVP's for possible call forwarding types/destinations
        # Below line should load all AVP's into memory from DB for the username portion of the TO: field from table usr_preferences
        xlog("script should load from DB usr_preferences next");
        avp_db_load("$tU","s/usr_preferences");
        # This line i simple want to print to log when the avp load is complete and what the values are (for debug purposes only and should typically be commented out)
        xlog("DB load should be complete");
        xlog("SCRIPT: $TF Call Forwarding Unconditional set to $avp(Unconditional)\n");
        xlog("SCRIPT: $TF Call Forwarding NoAnswer set to $avp(NoAnswer)\n");
        xlog("SCRIPT: $TF Call Forwarding Busy set to $avp(Busy)\n");
        avp_print();
        # Check to see if the AVP's are set and if so put them in log for logging purposes
        if(is_avp_set("$avp(Unconditional)"))
        xlog("SCRIPT: $TF Call Forwarding Unconditional set to $avp(Unconditional)\n");
        if(is_avp_set("$avp(NoAnswer)"))
        xlog("SCRIPT: $TF Call Forwarding NoAnswer set to $avp(NoAnswer)\n");
        if(is_avp_set("$avp(Busy)"))
        xlog("SCRIPT: $TF Call Forwarding Busy set to $avp(Busy)\n");
        t_set_fr(16000, 15000); # set fr invite timeout to 16s and no response at all to 15s to meet the specs for call fowarding no answer ringtime


        # If Call fowarding Unconditional is set, we need to change the dialed number and sent it off to the original users trunk from subscriber table

        # Check to see if unconditional is set
        if(is_avp_set("$avp(Unconditional)"))
        # Shove this call into route [PSTN_CFWD] Block
        route("PSTN_CFWD");


Here is the syslog for the same snippet:
09:29 2017 Call to 15703771055 made it into WITH_CFWD in route[LOCATION] block
Mar 29 14:09:29 Limitless-Calling-Server /usr/local/sbin/kamailio[7831]: ERROR: <script>: script should load from DB usr_preferences next
Mar 29 14:09:29 Limitless-Calling-Server /usr/local/sbin/kamailio[7831]: ERROR: <script>: DB load should be complete
Mar 29 14:09:29 Limitless-Calling-Server /usr/local/sbin/kamailio[7831]: ERROR: <script>: SCRIPT: Wed Mar 29 14:09:29 2017 Call Forwarding Unconditional set to <null>
Mar 29 14:09:29 Limitless-Calling-Server /usr/local/sbin/kamailio[7831]: ERROR: <script>: SCRIPT: Wed Mar 29 14:09:29 2017 Call Forwarding NoAnswer set to <null>
Mar 29 14:09:29 Limitless-Calling-Server /usr/local/sbin/kamailio[7831]: ERROR: <script>: SCRIPT: Wed Mar 29 14:09:29 2017 Call Forwarding Busy set to <null>
Mar 29 14:09:29 Limitless-Calling-Server /usr/local/sbin/kamailio[7831]: INFO: avpops [avpops_impl.c:1473]: ops_print_avp(): p=0x7f440ed86f90, flags=0x0113
Mar 29 14:09:29 Limitless-Calling-Server /usr/local/sbin/kamailio[7831]: INFO: avpops [avpops_impl.c:1477]: ops_print_avp(): #011#011#011name=<direction>
Mar 29 14:09:29 Limitless-Calling-Server /usr/local/sbin/kamailio[7831]: INFO: avpops [avpops_impl.c:1485]: ops_print_avp(): #011#011#011val_str=<INCOMING / 8>






_______________________________________________

SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list

sr-users at lists.sip-router.org<mailto:sr-users at lists.sip-router.org>

http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users



--

Daniel-Constantin Mierla

www.twitter.com/miconda<http://www.twitter.com/miconda> -- www.linkedin.com/in/miconda<http://www.linkedin.com/in/miconda>

Kamailio Advanced Training - May 22-24 (USA) - www.asipto.com<http://www.asipto.com>

Kamailio World Conference - May 8-10, 2017 - www.kamailioworld.com<http://www.kamailioworld.com>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20170330/15e57c5a/attachment.html>


More information about the sr-users mailing list