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>
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@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
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@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@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@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@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@lists.sip-router.orgmailto:sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
--
Daniel-Constantin Mierla
www.twitter.com/micondahttp://www.twitter.com/miconda -- www.linkedin.com/in/micondahttp://www.linkedin.com/in/miconda
Kamailio Advanced Training - May 22-24 (USA) - www.asipto.comhttp://www.asipto.com
Kamailio World Conference - May 8-10, 2017 - www.kamailioworld.comhttp://www.kamailioworld.com
Are you sure you ran it with debug=3? Because there must be a lot of "DEBUG: ...." log messages.
Cheers, Daniel
On 30.03.17 16:35, Kevin Bushong wrote:
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
[...]
Yes, I ran it as debug=3
#!ifdef WITH_DEBUG debug=3 log_stderror=yes #!else debug=2 log_stderror=no #!endif
Here is my modparams for the debugger module.
#!ifdef WITH_DEBUG # ----- debugger params ----- modparam("debugger", "cfgtrace", 1)
I expect debugs as well, but didn’t see any. Is there some configuration I’m missing?
Thanks,
Kevin
From: Daniel-Constantin Mierla [mailto:miconda@gmail.com] Sent: Thursday, March 30, 2017 1:37 PM To: Kevin Bushong kbushong@carnegietechnologies.com; Kamailio (SER) - Users Mailing List sr-users@lists.sip-router.org Subject: Re: [SR-Users] Problems with avp_db_load
Are you sure you ran it with debug=3? Because there must be a lot of "DEBUG: ...." log messages.
Cheers, Daniel
On 30.03.17 16:35, Kevin Bushong wrote: 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 [...]
--
Daniel-Constantin Mierla
www.twitter.com/micondahttp://www.twitter.com/miconda -- www.linkedin.com/in/micondahttp://www.linkedin.com/in/miconda
Kamailio Advanced Training - May 22-24 (USA) - www.asipto.comhttp://www.asipto.com
Kamailio World Conference - May 8-10, 2017 - www.kamailioworld.comhttp://www.kamailioworld.com
By default the second setting of debug is in effect, the one after #!else, respectively:
debug=2
Cheers, Daniel
On 30.03.17 19:40, Kevin Bushong wrote:
Yes, I ran it as debug=3
#!ifdef WITH_DEBUG
debug=3
log_stderror=yes
#!else
debug=2
log_stderror=no
#!endif
Here is my modparams for the debugger module.
#!ifdef WITH_DEBUG
# ----- debugger params -----
modparam("debugger", "cfgtrace", 1)
I expect debugs as well, but didn’t see any. Is there some configuration I’m missing?
Thanks,
Kevin
*From:*Daniel-Constantin Mierla [mailto:miconda@gmail.com] *Sent:* Thursday, March 30, 2017 1:37 PM *To:* Kevin Bushong kbushong@carnegietechnologies.com; Kamailio (SER) - Users Mailing List sr-users@lists.sip-router.org *Subject:* Re: [SR-Users] Problems with avp_db_load
Are you sure you ran it with debug=3? Because there must be a lot of "DEBUG: ...." log messages.
Cheers, Daniel
On 30.03.17 16:35, Kevin Bushong wrote:
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
[...]
-- 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
Oops. Well that explains it. Here is the portion of the debug I believe is relevant. I’ve also attached the full syslog in case you need it.
I suspect this is the line that is the problem, but I’m not sure how to fix it:
Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:775]: sip_trace_store_db(): database connection not initialized
Thanks
Kevin
(14606) ERROR: <script>: Fri Mar 31 08:51:29 2017 Call to 15703771993 made it into route[LOCATION] block Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) ERROR: <script>: Fri Mar 31 08:51:29 2017 Call to 15703771993 made it into WITH_CFWD in route[LOCATION] block Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) ERROR: <script>: script should load from DB usr_preferences next11(14615) DEBUG: <core> [parser/msg_parser.c:605]: parse_msg(): SIP Reply (status): Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:607]: parse_msg(): version: <SIP/2.0> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:609]: parse_msg(): status: <200> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:611]: parse_msg(): reason: <OK> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_addr_spec.c:171]: parse_to_param(): DEBUG: add_param: tag=10002030710893 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_addr_spec.c:871]: parse_addr_spec(): end of header reached, state=29 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:171]: get_hdr_field(): <To> [75]; uri=[sip:15703771993@limitless.sip.carnegietechnologies.com] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:172]: get_hdr_field(): to body [sip:15703771993@limitless.sip.carnegietechnologies.com] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK38da.2ef31f0c72c8f2c0b9dd76e2865a2dc3.0>; state=6 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 234, <received> = <172.16.128.140>; state=6 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 236, <i> = <91>; state=9 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:2685]: parse_via(): parse_via: next_via Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 234, <received> = <172.16.128.135>; state=6 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 235, <rport> = <55579>; state=6 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPj6505d775-c66a-4f3a-b76a-d87b1e84f6be>; state=6 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 237, <alias> = <n/a>; state=16 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:486]: parse_headers(): Via found, flags=2 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:488]: parse_headers(): this is the first via Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [receive.c:178]: receive_msg(): After parse_msg... Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=1 global id=0 T start=0xffffffffffffffff Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <24412> <PRACK> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_lookup.c:888]: t_reply_matching(): DEBUG: t_reply_matching: hash 44419 label 0 branch 0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_lookup.c:943]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x7f5a78216e40)! Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f5a78216e40, callback type 2, id 0 entered Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_addr_spec.c:171]: parse_to_param(): DEBUG: add_param: tag=b9d6ff68-2bb6-405b-bf20-dd4f0f68878f Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_addr_spec.c:871]: parse_addr_spec(): end of header reached, state=29 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:775]: sip_trace_store_db(): database connection not initialized Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:1896]: pipport2su(): the port string is 5060 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:1896]: pipport2su(): the port string is 5085 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [proxy.c:265]: mk_proxy(): doing DNS lookup... Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:1708]: trace_send_hep_duplicate(): setting up the socket_info Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [forward.c:174]: get_out_socket(): socket determined: 0x7f5a7db99ea0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f5a78216e40, callback type 2, id 0 entered Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: dialog [dlg_hash.c:690]: dlg_lookup(): ref dlg 0x7f5a782062b0 with 1 -> 2 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: dialog [dlg_hash.c:692]: dlg_lookup(): dialog id=4198 found on entry 2114 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: dialog [dlg_profile.c:530]: set_current_dialog(): setting current dialog [2114:4198] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: dialog [dlg_hash.c:922]: dlg_unref_helper(): unref op on 0x7f5a782062b0 with 1 from dlg_hash.c:940 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: dialog [dlg_hash.c:926]: dlg_unref_helper(): unref dlg 0x7f5a782062b0 with 1 -> 1 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_lookup.c:1080]: t_check_msg(): DEBUG: t_check_msg: msg id=1 global id=1 T end=0x7f5a78216e40 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_reply.c:2161]: reply_received(): DEBUG: reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_reply.c:1233]: t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=200 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_reply.c:1752]: relay_reply(): DEBUG: relay_reply: branch=0, save=0, relay=0 icode=0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:183]: get_hdr_field(): content_length=0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:89]: get_hdr_field(): found end of header Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [msg_translator.c:2261]: generate_res_buf_from_sip_res(): old size: 539, new size: 423 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [msg_translator.c:2279]: generate_res_buf_from_sip_res(): copied size: orig:319, new: 203, rest: 220 msg= Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: SIP/2.0 200 OK Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: From: sip:15703771055@limitless.sip.carnegietechnologies.com;tag=b9d6ff68-2bb6-405b-bf20-dd4f0f68878f Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: To: sip:15703771993@limitless.sip.carnegietechnologies.com;tag=10002030710893 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: Via: SIP/2.0/TCP 172.16.128.135:55579;received=172.16.128.135;rport=55579;branch=z9hG4bKPj6505d775-c66a-4f3a-b76a-d87b1e84f6be;alias Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: Call-ID: 2faac02a-f381-4b8e-8791-ea5941cb1970 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: CSeq: 24412 PRACK Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: Content-Length: 0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [tcp_main.c:2211]: tcpconn_send_put(): tcp connection found (0x7f5a781ee1c8), acquiring fd Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 30(14634) DEBUG: <core> [tcp_main.c:3484]: handle_ser_child(): read response= 7f5a781ee1c8, 2, fd -1 from 11 (14615) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [tcp_main.c:2221]: tcpconn_send_put(): c=0x7f5a781ee1c8, n=16 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [tcp_main.c:2251]: tcpconn_send_put(): after receive_fd: c= 0x7f5a781ee1c8 n=8 fd=11 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [tcp_main.c:2430]: tcpconn_do_send(): sending... Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [tcp_main.c:2464]: tcpconn_do_send(): after real write: c= 0x7f5a781ee1c8 n=423 fd=11 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [tcp_main.c:2465]: tcpconn_do_send(): buf= Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: SIP/2.0 200 OK Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: From: sip:15703771055@limitless.sip.carnegietechnologies.com;tag=b9d6ff68-2bb6-405b-bf20-dd4f0f68878f Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: To: sip:15703771993@limitless.sip.carnegietechnologies.com;tag=10002030710893 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: Via: SIP/2.0/TCP 172.16.128.135:55579;received=172.16.128.135;rport=55579;branch=z9hG4bKPj6505d775-c66a-4f3a-b76a-d87b1e84f6be;alias Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: Call-ID: 2faac02a-f381-4b8e-8791-ea5941cb1970 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: CSeq: 24412 PRACK Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: Content-Length: 0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 56 bytes for result set at 0x7f5a7dbb1fa0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f5a78216e40, callback type 8388608, id 0 entered Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:66]: db_mysql_get_columns(): 3 columns returned from the query Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:775]: sip_trace_store_db(): database connection not initialized Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:154]: db_allocate_columns(): allocate 24 bytes for result names at 0x7f5a7dbb2130 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:1896]: pipport2su(): the port string is 5085 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 12 bytes for result types at 0x7f5a7dbb01e0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:1896]: pipport2su(): the port string is 55579 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7f5a7db996d0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7f5a7db996d0)[0]=[value] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [proxy.c:265]: mk_proxy(): doing DNS lookup... Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:135]: db_mysql_get_columns(): use DB1_STRING result type Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[1] at 0x7f5a7dbb1920 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7f5a7dbb1920)[1]=[attribute] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:1708]: trace_send_hep_duplicate(): setting up the socket_info Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:135]: db_mysql_get_columns(): use DB1_STRING result type Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[2] at 0x7f5a7dbb17e8 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7f5a7dbb17e8)[2]=[type] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:99]: db_mysql_get_columns(): use DB1_INT result type Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:168]: db_mysql_convert_rows(): no rows returned from the query Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [forward.c:174]: get_out_socket(): socket determined: 0x7f5a7db99ea0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: avpops [avpops_db.c:265]: db_close_query(): close avp query Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 3 columns Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7f5a7db996d0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[1] at 0x7f5a7dbb1920 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[2] at 0x7f5a7dbb17e8 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:92]: db_free_columns(): freeing result names at 0x7f5a7dbb2130 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_reply.c:1593]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:97]: db_free_columns(): freeing result types at 0x7f5a7dbb01e0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0x7f5a7dbb1fa0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: avpops [avpops_impl.c:415]: ops_dbload_avps(): loaded avps = 0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) ERROR: <script>: DB load should be complete11(14615) DEBUG: dialog [dlg_var.c:86]: cb_dlg_locals_reset(): resetting the local dialog shortcuts on script callback: 2147483652 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [receive.c:322]: receive_msg(): cleaning up Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) ERROR: <script>: SCRIPT: Fri Mar 31 08:51:29 2017 Call Forwarding Unconditional set to <null> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) ERROR: <script>: SCRIPT: Fri Mar 31 08:51:29 2017 Call Forwarding NoAnswer set to <null> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) ERROR: <script>: SCRIPT: Fri Mar 31 08:51:29 2017 Call Forwarding Busy set to <null> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) INFO: avpops [avpops_impl.c:1473]: ops_print_avp(): p=0x7f5a78205bd0, flags=0x0113 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) INFO: avpops [avpops_impl.c:1477]: ops_print_avp(): #011#011#011name=<direction> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) INFO: avpops [avpops_impl.c:1485]: ops_print_avp(): #011#011#011val_str=<INCOMING / 8> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: registrar [lookup.c:240]: lookup_helper(): contact for [15703771993] found by address Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: tm [t_lookup.c:1312]: t_newtran(): DEBUG: t_newtran: msg id=1 , global msg id=1 , T on entrance=(nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: tm [t_lookup.c:466]: t_lookup_request(): t_lookup_request: start searching: hash=16801, isACK=0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: tm [t_lookup.c:424]: matching_3261(): DEBUG: RFC3261 transaction matching failed Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: tm [t_lookup.c:648]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: tm [t_hooks.c:358]: run_reqin_callbacks_internal(): DBG: trans=0x7f5a78233c70, callback type 1, id 0 entered Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_handlers.c:722]: dlg_onreq(): dialog creation on config flag Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_hash.c:756]: internal_get_dlg(): no dialog callid='9984c9ea-90b3-1235-a08c-0cc47ab00eb4' found Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_hash.c:821]: dlg_search(): dialog with callid='9984c9ea-90b3-1235-a08c-0cc47ab00eb4' not found Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_hash.c:452]: build_new_dlg(): new dialog on hash 354 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_handlers.c:255]: populate_leg_info(): route_set , contact sip:mod_sofia@172.16.128.140:5060;alias=172.16.128.140~5060~1, cseq 105146280 and bind_addr udp:127.0.0.1:5085 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_hash.c:875]: link_dlg(): linking dialog [354:4990] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_hash.c:884]: link_dlg(): ref dlg 0x7f5a782384c8 with 1 -> 1 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_cb.c:228]: run_create_callbacks(): dialog=0x7f5a782384c8 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: acc [acc_cdr.c:790]: cdr_on_create(): dialog '0x7f5a782384c8' created! 2(14606) DEBUG: dialog [dlg_var.c:250]: print_lists(): Internal var-list ((nil)): Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_var.c:260]: print_lists(): Dialog var-list (0x7f5a78238ae0):
From: Daniel-Constantin Mierla [mailto:miconda@gmail.com] Sent: Friday, March 31, 2017 7:41 AM To: Kevin Bushong kbushong@carnegietechnologies.com; Kamailio (SER) - Users Mailing List sr-users@lists.sip-router.org Subject: Re: [SR-Users] Problems with avp_db_load
By default the second setting of debug is in effect, the one after #!else, respectively:
debug=2 Cheers, Daniel On 30.03.17 19:40, Kevin Bushong wrote: Yes, I ran it as debug=3
#!ifdef WITH_DEBUG debug=3 log_stderror=yes #!else debug=2 log_stderror=no #!endif
Here is my modparams for the debugger module.
#!ifdef WITH_DEBUG # ----- debugger params ----- modparam("debugger", "cfgtrace", 1)
I expect debugs as well, but didn’t see any. Is there some configuration I’m missing?
Thanks,
Kevin
From: Daniel-Constantin Mierla [mailto:miconda@gmail.com] Sent: Thursday, March 30, 2017 1:37 PM To: Kevin Bushong kbushong@carnegietechnologies.commailto:kbushong@carnegietechnologies.com; Kamailio (SER) - Users Mailing List sr-users@lists.sip-router.orgmailto:sr-users@lists.sip-router.org Subject: Re: [SR-Users] Problems with avp_db_load
Are you sure you ran it with debug=3? Because there must be a lot of "DEBUG: ...." log messages.
Cheers, Daniel
On 30.03.17 16:35, Kevin Bushong wrote: 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 [...]
--
Daniel-Constantin Mierla
www.twitter.com/micondahttp://www.twitter.com/miconda -- www.linkedin.com/in/micondahttp://www.linkedin.com/in/miconda
Kamailio Advanced Training - May 22-24 (USA) - www.asipto.comhttp://www.asipto.com
Kamailio World Conference - May 8-10, 2017 - www.kamailioworld.comhttp://www.kamailioworld.com
--
Daniel-Constantin Mierla
www.twitter.com/micondahttp://www.twitter.com/miconda -- www.linkedin.com/in/micondahttp://www.linkedin.com/in/miconda
Kamailio Advanced Training - May 22-24 (USA) - www.asipto.comhttp://www.asipto.com
Kamailio World Conference - May 8-10, 2017 - www.kamailioworld.comhttp://www.kamailioworld.com
Look like my attachment flagged for moderator, so I’m sending this email again without the full syslog attached.
From: Kevin Bushong Sent: Friday, March 31, 2017 10:12 AM To: miconda@gmail.com; Kamailio (SER) - Users Mailing List sr-users@lists.sip-router.org Subject: RE: [SR-Users] Problems with avp_db_load
Oops. Well that explains it. Here is the portion of the debug I believe is relevant. I’ve also attached the full syslog in case you need it.
I suspect this is the line that is the problem, but I’m not sure how to fix it:
Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:775]: sip_trace_store_db(): database connection not initialized
Thanks
Kevin
(14606) ERROR: <script>: Fri Mar 31 08:51:29 2017 Call to 15703771993 made it into route[LOCATION] block Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) ERROR: <script>: Fri Mar 31 08:51:29 2017 Call to 15703771993 made it into WITH_CFWD in route[LOCATION] block Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) ERROR: <script>: script should load from DB usr_preferences next11(14615) DEBUG: <core> [parser/msg_parser.c:605]: parse_msg(): SIP Reply (status): Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:607]: parse_msg(): version: <SIP/2.0> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:609]: parse_msg(): status: <200> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:611]: parse_msg(): reason: <OK> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_addr_spec.c:171]: parse_to_param(): DEBUG: add_param: tag=10002030710893 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_addr_spec.c:871]: parse_addr_spec(): end of header reached, state=29 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:171]: get_hdr_field(): <To> [75]; uri=[sip:15703771993@limitless.sip.carnegietechnologies.com] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:172]: get_hdr_field(): to body [sip:15703771993@limitless.sip.carnegietechnologies.com] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK38da.2ef31f0c72c8f2c0b9dd76e2865a2dc3.0>; state=6 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 234, <received> = <172.16.128.140>; state=6 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 236, <i> = <91>; state=9 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:2685]: parse_via(): parse_via: next_via Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 234, <received> = <172.16.128.135>; state=6 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 235, <rport> = <55579>; state=6 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPj6505d775-c66a-4f3a-b76a-d87b1e84f6be>; state=6 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 237, <alias> = <n/a>; state=16 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:486]: parse_headers(): Via found, flags=2 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:488]: parse_headers(): this is the first via Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [receive.c:178]: receive_msg(): After parse_msg... Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=1 global id=0 T start=0xffffffffffffffff Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <24412> <PRACK> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_lookup.c:888]: t_reply_matching(): DEBUG: t_reply_matching: hash 44419 label 0 branch 0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_lookup.c:943]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x7f5a78216e40)! Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f5a78216e40, callback type 2, id 0 entered Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_addr_spec.c:171]: parse_to_param(): DEBUG: add_param: tag=b9d6ff68-2bb6-405b-bf20-dd4f0f68878f Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/parse_addr_spec.c:871]: parse_addr_spec(): end of header reached, state=29 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:775]: sip_trace_store_db(): database connection not initialized Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:1896]: pipport2su(): the port string is 5060 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:1896]: pipport2su(): the port string is 5085 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [proxy.c:265]: mk_proxy(): doing DNS lookup... Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:1708]: trace_send_hep_duplicate(): setting up the socket_info Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [forward.c:174]: get_out_socket(): socket determined: 0x7f5a7db99ea0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f5a78216e40, callback type 2, id 0 entered Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: dialog [dlg_hash.c:690]: dlg_lookup(): ref dlg 0x7f5a782062b0 with 1 -> 2 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: dialog [dlg_hash.c:692]: dlg_lookup(): dialog id=4198 found on entry 2114 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: dialog [dlg_profile.c:530]: set_current_dialog(): setting current dialog [2114:4198] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: dialog [dlg_hash.c:922]: dlg_unref_helper(): unref op on 0x7f5a782062b0 with 1 from dlg_hash.c:940 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: dialog [dlg_hash.c:926]: dlg_unref_helper(): unref dlg 0x7f5a782062b0 with 1 -> 1 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_lookup.c:1080]: t_check_msg(): DEBUG: t_check_msg: msg id=1 global id=1 T end=0x7f5a78216e40 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_reply.c:2161]: reply_received(): DEBUG: reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_reply.c:1233]: t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=200 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_reply.c:1752]: relay_reply(): DEBUG: relay_reply: branch=0, save=0, relay=0 icode=0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:183]: get_hdr_field(): content_length=0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [parser/msg_parser.c:89]: get_hdr_field(): found end of header Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [msg_translator.c:2261]: generate_res_buf_from_sip_res(): old size: 539, new size: 423 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [msg_translator.c:2279]: generate_res_buf_from_sip_res(): copied size: orig:319, new: 203, rest: 220 msg= Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: SIP/2.0 200 OK Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: From: sip:15703771055@limitless.sip.carnegietechnologies.com;tag=b9d6ff68-2bb6-405b-bf20-dd4f0f68878f Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: To: sip:15703771993@limitless.sip.carnegietechnologies.com;tag=10002030710893 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: Via: SIP/2.0/TCP 172.16.128.135:55579;received=172.16.128.135;rport=55579;branch=z9hG4bKPj6505d775-c66a-4f3a-b76a-d87b1e84f6be;alias Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: Call-ID: 2faac02a-f381-4b8e-8791-ea5941cb1970 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: CSeq: 24412 PRACK Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: Content-Length: 0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [tcp_main.c:2211]: tcpconn_send_put(): tcp connection found (0x7f5a781ee1c8), acquiring fd Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 30(14634) DEBUG: <core> [tcp_main.c:3484]: handle_ser_child(): read response= 7f5a781ee1c8, 2, fd -1 from 11 (14615) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [tcp_main.c:2221]: tcpconn_send_put(): c=0x7f5a781ee1c8, n=16 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [tcp_main.c:2251]: tcpconn_send_put(): after receive_fd: c= 0x7f5a781ee1c8 n=8 fd=11 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [tcp_main.c:2430]: tcpconn_do_send(): sending... Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [tcp_main.c:2464]: tcpconn_do_send(): after real write: c= 0x7f5a781ee1c8 n=423 fd=11 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [tcp_main.c:2465]: tcpconn_do_send(): buf= Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: SIP/2.0 200 OK Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: From: sip:15703771055@limitless.sip.carnegietechnologies.com;tag=b9d6ff68-2bb6-405b-bf20-dd4f0f68878f Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: To: sip:15703771993@limitless.sip.carnegietechnologies.com;tag=10002030710893 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: Via: SIP/2.0/TCP 172.16.128.135:55579;received=172.16.128.135;rport=55579;branch=z9hG4bKPj6505d775-c66a-4f3a-b76a-d87b1e84f6be;alias Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: Call-ID: 2faac02a-f381-4b8e-8791-ea5941cb1970 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: CSeq: 24412 PRACK Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: Content-Length: 0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 56 bytes for result set at 0x7f5a7dbb1fa0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f5a78216e40, callback type 8388608, id 0 entered Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:66]: db_mysql_get_columns(): 3 columns returned from the query Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:775]: sip_trace_store_db(): database connection not initialized Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:154]: db_allocate_columns(): allocate 24 bytes for result names at 0x7f5a7dbb2130 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:1896]: pipport2su(): the port string is 5085 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 12 bytes for result types at 0x7f5a7dbb01e0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:1896]: pipport2su(): the port string is 55579 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7f5a7db996d0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7f5a7db996d0)[0]=[value] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [proxy.c:265]: mk_proxy(): doing DNS lookup... Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:135]: db_mysql_get_columns(): use DB1_STRING result type Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[1] at 0x7f5a7dbb1920 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7f5a7dbb1920)[1]=[attribute] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:1708]: trace_send_hep_duplicate(): setting up the socket_info Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:135]: db_mysql_get_columns(): use DB1_STRING result type Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[2] at 0x7f5a7dbb17e8 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7f5a7dbb17e8)[2]=[type] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:99]: db_mysql_get_columns(): use DB1_INT result type Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: db_mysql [km_res.c:168]: db_mysql_convert_rows(): no rows returned from the query Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [forward.c:174]: get_out_socket(): socket determined: 0x7f5a7db99ea0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: avpops [avpops_db.c:265]: db_close_query(): close avp query Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 3 columns Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7f5a7db996d0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[1] at 0x7f5a7dbb1920 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[2] at 0x7f5a7dbb17e8 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:92]: db_free_columns(): freeing result names at 0x7f5a7dbb2130 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: tm [t_reply.c:1593]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:97]: db_free_columns(): freeing result types at 0x7f5a7dbb01e0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0x7f5a7dbb1fa0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: avpops [avpops_impl.c:415]: ops_dbload_avps(): loaded avps = 0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) ERROR: <script>: DB load should be complete11(14615) DEBUG: dialog [dlg_var.c:86]: cb_dlg_locals_reset(): resetting the local dialog shortcuts on script callback: 2147483652 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: <core> [receive.c:322]: receive_msg(): cleaning up Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) ERROR: <script>: SCRIPT: Fri Mar 31 08:51:29 2017 Call Forwarding Unconditional set to <null> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) ERROR: <script>: SCRIPT: Fri Mar 31 08:51:29 2017 Call Forwarding NoAnswer set to <null> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) ERROR: <script>: SCRIPT: Fri Mar 31 08:51:29 2017 Call Forwarding Busy set to <null> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) INFO: avpops [avpops_impl.c:1473]: ops_print_avp(): p=0x7f5a78205bd0, flags=0x0113 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) INFO: avpops [avpops_impl.c:1477]: ops_print_avp(): #011#011#011name=<direction> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) INFO: avpops [avpops_impl.c:1485]: ops_print_avp(): #011#011#011val_str=<INCOMING / 8> Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: registrar [lookup.c:240]: lookup_helper(): contact for [15703771993] found by address Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: tm [t_lookup.c:1312]: t_newtran(): DEBUG: t_newtran: msg id=1 , global msg id=1 , T on entrance=(nil) Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: tm [t_lookup.c:466]: t_lookup_request(): t_lookup_request: start searching: hash=16801, isACK=0 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: tm [t_lookup.c:424]: matching_3261(): DEBUG: RFC3261 transaction matching failed Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: tm [t_lookup.c:648]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: tm [t_hooks.c:358]: run_reqin_callbacks_internal(): DBG: trans=0x7f5a78233c70, callback type 1, id 0 entered Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_handlers.c:722]: dlg_onreq(): dialog creation on config flag Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_hash.c:756]: internal_get_dlg(): no dialog callid='9984c9ea-90b3-1235-a08c-0cc47ab00eb4' found Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_hash.c:821]: dlg_search(): dialog with callid='9984c9ea-90b3-1235-a08c-0cc47ab00eb4' not found Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_hash.c:452]: build_new_dlg(): new dialog on hash 354 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_handlers.c:255]: populate_leg_info(): route_set , contact sip:mod_sofia@172.16.128.140:5060;alias=172.16.128.140~5060~1, cseq 105146280 and bind_addr udp:127.0.0.1:5085 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_hash.c:875]: link_dlg(): linking dialog [354:4990] Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_hash.c:884]: link_dlg(): ref dlg 0x7f5a782384c8 with 1 -> 1 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_cb.c:228]: run_create_callbacks(): dialog=0x7f5a782384c8 Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: acc [acc_cdr.c:790]: cdr_on_create(): dialog '0x7f5a782384c8' created! 2(14606) DEBUG: dialog [dlg_var.c:250]: print_lists(): Internal var-list ((nil)): Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 2(14606) DEBUG: dialog [dlg_var.c:260]: print_lists(): Dialog var-list (0x7f5a78238ae0):
From: Daniel-Constantin Mierla [mailto:miconda@gmail.com] Sent: Friday, March 31, 2017 7:41 AM To: Kevin Bushong <kbushong@carnegietechnologies.commailto:kbushong@carnegietechnologies.com>; Kamailio (SER) - Users Mailing List <sr-users@lists.sip-router.orgmailto:sr-users@lists.sip-router.org> Subject: Re: [SR-Users] Problems with avp_db_load
By default the second setting of debug is in effect, the one after #!else, respectively:
debug=2 Cheers, Daniel On 30.03.17 19:40, Kevin Bushong wrote: Yes, I ran it as debug=3
#!ifdef WITH_DEBUG debug=3 log_stderror=yes #!else debug=2 log_stderror=no #!endif
Here is my modparams for the debugger module.
#!ifdef WITH_DEBUG # ----- debugger params ----- modparam("debugger", "cfgtrace", 1)
I expect debugs as well, but didn’t see any. Is there some configuration I’m missing?
Thanks,
Kevin
From: Daniel-Constantin Mierla [mailto:miconda@gmail.com] Sent: Thursday, March 30, 2017 1:37 PM To: Kevin Bushong kbushong@carnegietechnologies.commailto:kbushong@carnegietechnologies.com; Kamailio (SER) - Users Mailing List sr-users@lists.sip-router.orgmailto:sr-users@lists.sip-router.org Subject: Re: [SR-Users] Problems with avp_db_load
Are you sure you ran it with debug=3? Because there must be a lot of "DEBUG: ...." log messages.
Cheers, Daniel
On 30.03.17 16:35, Kevin Bushong wrote: 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 [...]
--
Daniel-Constantin Mierla
www.twitter.com/micondahttp://www.twitter.com/miconda -- www.linkedin.com/in/micondahttp://www.linkedin.com/in/miconda
Kamailio Advanced Training - May 22-24 (USA) - www.asipto.comhttp://www.asipto.com
Kamailio World Conference - May 8-10, 2017 - www.kamailioworld.comhttp://www.kamailioworld.com
--
Daniel-Constantin Mierla
www.twitter.com/micondahttp://www.twitter.com/miconda -- www.linkedin.com/in/micondahttp://www.linkedin.com/in/miconda
Kamailio Advanced Training - May 22-24 (USA) - www.asipto.comhttp://www.asipto.com
Kamailio World Conference - May 8-10, 2017 - www.kamailioworld.comhttp://www.kamailioworld.com
Are you sure you have the correct records in the database? I did a diff between 4.3 and 4.4 branches and there are no differences in avpops module code.
Maybe you can sniff the communication between kamailio and mysql server and see what is returned there. If mysql server is listening on loopback interface port 3306 without tls, then you can use tcpdump or ngrep to view what's the query and the response.
Daniel
On 31.03.17 16:12, Kevin Bushong wrote:
Oops. Well that explains it. Here is the portion of the debug I believe is relevant. I’ve also attached the full syslog in case you need it.
I suspect this is the line that is the problem, but I’m not sure how to fix it:
Mar 31 08:51:29 Limitless-Calling-Server kamailio[14586]: 11(14615) DEBUG: siptrace [siptrace.c:775]: sip_trace_store_db(): database connection not initialized
Thanks
Kevin
[...]