[New install] Issues with Kamailio, DB and outbound calling

[Loren Burlingame]

Hi guys, thanks for reading this and trying to help with my issue.

I have installed Kazoo via CentOS repository and have a functioning system, for the most part.

Early on, when I was trying to get a phone registered, I changed the IP and host name of the system from private to public. The old IP was a 192.168.x.x IP and the host name was a .lan address (only valid on internal DNS).

I then attempted to change all of the references to any internal IP or host name in various configuration files and database documents to the external equivalents.

I now am able to register a phone and all services appear to be up and running.

However, I am unable to make any outbound calls. Actually, I am unable to make any calls at all.

I have made some simple call flows that should be purely internal, but as soon as the phone dials the number, I get a 403 FORBIDDEN error on the phone itself and some non-helpful (to me at least) messages in the kamailio log file.

I am also seeing some messages show up in the 2600hz platform log file that, while not directly related to the call attempt, would seem to suggest a database issue.

Below are snippets from both the 2600hz platform and kamailio log files.

If anyone could point me in the right direction, I would greatly appreciate it.6

2600HZ PLATFORM DEBUG LOG

Dec 17 17:09:00 kaio 2600hz[7354]: |undefined|wh_amqp_channel:150 (<0.163.0>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key statistics) via <0.1110.0>
Dec 17 17:09:02 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact account/12/b7/dfc029ec3160123eff9ebd650021 on bigc...@kaio.ttt.lan
Dec 17 17:09:02 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 43447 is under min_data_size threshold 131072
Dec 17 17:09:02 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db account/12/b7/dfc029ec3160123eff9ebd650021 not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:03 kaio 2600hz[7354]: |wh_nodes|wh_amqp_channel:134 (<0.1127.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.1131.0>
Dec 17 17:09:05 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact anonymous_cdrs on bigc...@kaio.ttt.lan
Dec 17 17:09:05 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 5390 is under min_data_size threshold 131072
Dec 17 17:09:05 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db anonymous_cdrs not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:08 kaio 2600hz[7292]: |wh_nodes|wh_amqp_channel:134 (<0.193.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.173.0>
Dec 17 17:09:08 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact services on bigc...@kaio.ttt.lan
Dec 17 17:09:08 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 4549 is under min_data_size threshold 131072
Dec 17 17:09:08 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db services not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:09 kaio 2600hz[7354]: |wh_nodes|wh_amqp_channel:134 (<0.1127.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.1131.0>
Dec 17 17:09:10 kaio 2600hz[7354]: |undefined|wh_amqp_channel:150 (<0.163.0>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key statistics) via <0.1110.0>
Dec 17 17:09:11 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact accounts on bigc...@kaio.ttt.lan
Dec 17 17:09:11 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 9147 is under min_data_size threshold 131072
Dec 17 17:09:11 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db accounts not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:13 kaio 2600hz[7292]: |wh_nodes|wh_amqp_channel:134 (<0.193.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.173.0>
Dec 17 17:09:14 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact ratedeck on bigc...@kaio.ttt.lan
Dec 17 17:09:14 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 1052 is under min_data_size threshold 131072
Dec 17 17:09:14 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db ratedeck not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:17 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact faxes on bigc...@kaio.ttt.lan
Dec 17 17:09:17 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 679 is under min_data_size threshold 131072
Dec 17 17:09:17 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db faxes not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:20 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact system_media on bigc...@kaio.ttt.lan
Dec 17 17:09:20 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1417 (<0.190.0>) data size 13180876 is larger than minimum 131072
Dec 17 17:09:20 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1429 (<0.190.0>) ratio 1.0746061187435494 (14164250/13180876) is under min threshold 1.2
Dec 17 17:09:20 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db system_media not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:20 kaio 2600hz[7354]: |undefined|wh_amqp_channel:150 (<0.163.0>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key statistics) via <0.1110.0>
Dec 17 17:09:21 kaio 2600hz[7354]: |wh_nodes|wh_amqp_channel:134 (<0.1127.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.1131.0>
Dec 17 17:09:23 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact system_config on bigc...@kaio.ttt.lan
Dec 17 17:09:23 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 34135 is under min_data_size threshold 131072
Dec 17 17:09:23 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db system_config not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:26 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact account/59/77/206d93ccfcff0676cdbc301ee930 on bigc...@kaio.ttt.lan
Dec 17 17:09:26 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 53933 is under min_data_size threshold 131072
Dec 17 17:09:26 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db account/59/77/206d93ccfcff0676cdbc301ee930 not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:27 kaio 2600hz[7354]: |wh_nodes|wh_amqp_channel:134 (<0.1127.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.1131.0>
Dec 17 17:09:28 kaio 2600hz[7292]: |wh_nodes|wh_amqp_channel:134 (<0.193.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.173.0>
Dec 17 17:09:29 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact system_schemas on bigc...@kaio.ttt.lan
Dec 17 17:09:29 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 92706 is under min_data_size threshold 131072
Dec 17 17:09:29 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db system_schemas not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:30 kaio 2600hz[7354]: |undefined|wh_amqp_channel:150 (<0.163.0>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key statistics) via <0.1110.0>
Dec 17 17:09:32 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact global_provisioner on bigc...@kaio.ttt.lan
Dec 17 17:09:32 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 356 is under min_data_size threshold 131072
Dec 17 17:09:32 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db global_provisioner not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:32 kaio 2600hz[7354]: |wh_nodes|wh_amqp_channel:134 (<0.1127.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.1131.0>
Dec 17 17:09:35 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact offnet on bigc...@kaio.ttt.lan
Dec 17 17:09:35 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 335 is under min_data_size threshold 131072
Dec 17 17:09:35 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db offnet not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:38 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:621 (<0.190.0>) checking if should compact token_auth on bigc...@kaio.ttt.lan
Dec 17 17:09:38 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 283 is under min_data_size threshold 131072
Dec 17 17:09:38 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:628 (<0.190.0>) db token_auth not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:40 kaio 2600hz[7354]: |undefined|wh_amqp_channel:150 (<0.163.0>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key statistics) via <0.1110.0>
Dec 17 17:09:40 kaio 2600hz[7292]: |wh_nodes|wh_amqp_channel:134 (<0.193.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.173.0>
Dec 17 17:09:41 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:596 (<0.190.0>) checking if should compact sip_auth on bigc...@kaio.ttt.lan
Dec 17 17:09:41 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1420 (<0.190.0>) data size 3110 is under min_data_size threshold 131072
Dec 17 17:09:41 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:603 (<0.190.0>) db sip_auth not found on bigc...@kaio.ttt.lan OR heuristic not met
Dec 17 17:09:44 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:537 (<0.190.0>) no nodes to compact: {state,[],[],undefined,undefined,undefined,<<"bigc...@kaio.ttt.lan">>,undefined,{server,"kaio.ttt.lan",15984,[],[{max_sessions,512},{max_pipeline_size,10},{connect_timeout,300}]},{server,"kaio.ttt.lan",15986,[],[{max_sessions,512},{max_pipeline_size,10},{connect_timeout,300}]},{[],[]},undefined,undefined,ratio}
Dec 17 17:09:44 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:540 (<0.190.0>) returning to 'ready'
Dec 17 17:09:44 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:1343 (<0.190.0>) sending compact after timeout
Dec 17 17:09:44 kaio 2600hz[7292]: |couch_compactor_fsm|couch_compactor_fsm:312 (<0.190.0>) returning to 'ready'
Dec 17 17:09:44 kaio 2600hz[7354]: |wh_nodes|wh_amqp_channel:134 (<0.1127.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.1131.0>
Dec 17 17:09:50 kaio 2600hz[7354]: |undefined|wh_amqp_channel:150 (<0.163.0>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key statistics) via <0.1110.0>
Dec 17 17:09:51 kaio 2600hz[7354]: |wh_nodes|wh_amqp_channel:134 (<0.1127.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.1131.0>
Dec 17 17:09:55 kaio 2600hz[7292]: |wh_nodes|wh_amqp_channel:134 (<0.193.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.173.0>

KAMAILIO DEBUG LOG

Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request:
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/msg_parser.c:625]: parse_msg():  method:  <INVITE>
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/msg_parser.c:627]: parse_msg():  uri:     <sip:PHONE_...@kaio.tttphone.com>
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/msg_parser.c:629]: parse_msg():  version: <SIP/2.0>
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK12654214>; state=6
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=17
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [receive.c:151]: receive_msg(): After parse_msg...
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [receive.c:192]: receive_msg(): preparing to run routing scripts...
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/parse_to.c:799]: parse_to(): end of header reached, state=10
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [36]; uri=[sip:PHONE_...@kaio.tttphone.com]
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [<sip:PHONE_...@kaio.tttphone.com>#015#012]
Dec 17 17:09:04 kaio kamailio[30952]: INFO: <script>: 796397425...@BA.CA.DA.ED|start|recieved UDP request INVITE sip:PHONE_...@kaio.tttphone.com
Dec 17 17:09:04 kaio kamailio[30952]: INFO: <script>: 796397425...@BA.CA.DA.ED|log|source IP_ADDRESS_OF_CLIENT:35650
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/parse_to.c:176]: parse_to_param(): DEBUG: add_param: tag=1798003977
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/parse_to.c:799]: parse_to(): end of header reached, state=29
Dec 17 17:09:04 kaio kamailio[30952]: INFO: <script>: 796397425...@BA.CA.DA.ED|log|from sip:67...@kaio.tttphone.com
Dec 17 17:09:04 kaio kamailio[30952]: INFO: <script>: 796397425...@BA.CA.DA.ED|log|to sip:PHONE_...@kaio.tttphone.com
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <170> <INVITE>
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=400
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: maxfwd [maxfwd.c:161]: process_maxfwd_header(): value 70 decreased to 50
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1
Dec 17 17:09:04 kaio kamailio[30952]: INFO: <script>: 796397425...@BA.CA.DA.ED|log|originated from external sources
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: siputils [checks.c:103]: has_totag(): no totag
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: tm [t_lookup.c:1100]: t_check_msg(): DEBUG: t_check_msg: msg id=3151 global id=3150 T start=0xffffffffffffffff
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: tm [t_lookup.c:534]: t_lookup_request(): t_lookup_request: start searching: hash=6813, isACK=0
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: tm [t_lookup.c:492]: matching_3261(): DEBUG: RFC3261 transaction matching failed
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: tm [t_lookup.c:716]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: tm [t_lookup.c:1169]: t_check_msg(): DEBUG: t_check_msg: msg id=3151 global id=3151 T end=(nil)
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: rr [loose.c:85]: is_preloaded(): is_preloaded: Yes
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 17==14 && [kaio.tttphone.com] == [209.173.221.71]
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 17==14 && [kaio.tttphone.com] == [209.173.221.71]
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 7000 (advertise 0) matches port 5060
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 17==14 && [kaio.tttphone.com] == [209.173.221.71]
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 17==14 && [kaio.tttphone.com] == [209.173.221.71]
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 7000 (advertise 0) matches port 5060
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [forward.c:462]: check_self(): check_self: host != me
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: rr [loose.c:857]: after_loose(): Topmost URI is NOT myself
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: rr [loose.c:862]: after_loose(): URI to be processed: 'sip:kaio.tttphone.com:5060;lr'
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: rr [loose.c:871]: after_loose(): Next URI is a loose router
Dec 17 17:09:04 kaio kamailio[30952]: WARNING: <script>: 796397425...@BA.CA.DA.ED|end|denying initial request with route-set
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [msg_translator.c:206]: check_via_address(): check_via_address(IP_ADDRESS_OF_CLIENT, 10.20.30.43, 0)
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [xavp.c:447]: xavp_destroy_list(): destroying xavp list (nil)
Dec 17 17:09:04 kaio kamailio[30952]: DEBUG: <core> [receive.c:295]: receive_msg(): receive_msg: cleaning up
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request:
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/msg_parser.c:625]: parse_msg():  method:  <ACK>
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/msg_parser.c:627]: parse_msg():  uri:     <sip:PHONE_...@kaio.tttphone.com>
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/msg_parser.c:629]: parse_msg():  version: <SIP/2.0>
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK12654214>; state=6
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=17
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [receive.c:151]: receive_msg(): After parse_msg...
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [receive.c:192]: receive_msg(): preparing to run routing scripts...
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/parse_to.c:176]: parse_to_param(): DEBUG: add_param: tag=79263156c6763fc08625920481f69257.6d96
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/parse_to.c:799]: parse_to(): end of header reached, state=29
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [78]; uri=[sip:PHONE_...@kaio.tttphone.com]
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [<sip:PHONE_...@kaio.tttphone.com>]
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: sl [sl_funcs.c:415]: sl_filter_ACK(): SL local ACK found -> dropping it!
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [xavp.c:447]: xavp_destroy_list(): destroying xavp list (nil)
Dec 17 17:09:04 kaio kamailio[30956]: DEBUG: <core> [receive.c:295]: receive_msg(): receive_msg: cleaning up

[James Aimonetti]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Your BigCouch is still using the old hostname, which will cause you
many problems. Best to redo it entirely, tbh. I'd wipe all the data
out of /srv/ and restart BigCouch and whapps.

The best way to debug a call is to capture the Call-ID from the SIP
packet and grep the various logs (kamailio, FreeSWITCH,
2600hz-platform.log). This will give you an idea for how the call
flows between components, and, provided you're on debug logging,
should complain loudly and obviously when something doesn't work as
expected.

Also, please use a pastie service for your logs (instead of putting
them directly in the email); makes the email easier to parse.

James

- --
James Aimonetti
Lead Systems Architect
"I thought I fixed that"

2600Hz | http://2600hz.com
sip:ja...@2600hz.com
tel:415.886.7905
irc:mc_ @ freenode
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iF4EAREIAAYFAlKw4bEACgkQ54NxaUq7OmD6NwEAh0TmXnTXA+z8KzyW5lLNAIiN
kwzua2JOMdD3fx8ZmeEA/3zODI37mnppkKgkRNONIkmSS00B5BF6fqZ3qCJlW9Ea
=BCXq
-----END PGP SIGNATURE-----

[Karl Anderson]

However, the real issue is your SIP endpoint sent the initial request with a route set. This is not allowed by the default Kazoo config because it would allow public Kamailio servers to be used as an open relay. The log line that indicates this in in kamailio.log:

Dec 17 17:09:04 kaio kamailio[30952]: WARNING: <script>: 796397425...@BA.CA.DA.ED|end|denying initial request with route-set

Please note;
1) You would see this log line even if Kamailio was not in full debug
2) The ***|end|**** indicates that no further processing will occur (end of the attempt to handle the call)
3) Since the call is killed prior to getting to FreeSWITCH (and engaging the Kazoo routing engine) there will be no log lines in the 2600hz-platform.log


If you understand the ramifications of allowing initial SIP requests with pre-loaded route sets you can remove the following from /etc/kazoo/kamailio/default.cfg:
https://github.com/2600hz/kazoo_configs/blob/master/kamailio/default.cfg#L395-L399

After this you may have issues as James has indicated, however the immediate cause is the pre-loaded route set.

--
You received this message because you are subscribed to the Google Groups "2600hz-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to 2600hz-users...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

[Loren Burlingame]

Thanks for the reply.

What would be the best way to re-install Kazoo without wiping / re-installing the OS?

Since it is installed via CentOS repository, would I just do the standard yum remove and then install again? Are any old configs kept around?

**snipped**

[Karl Anderson]

I would recommend stopping everything. A instances of BigCouch especially.  Then move the database directory and recreate it… this will effectively allow bigcouch to build up the shards with the proper hostnames.  Notice, these commands are typed from memory and should be considered close approximations:

 

On all bigcouch servers:

/etc/init.d/bigcouch stop

 

Once all bigcouch instances have been stopped, repeat this command on db servers:

mv /srv /$(date +%s)-srv

mkdir /srv

chown bigcouch:bigcouch /srv

 

Once no bigcouch server has anything in the /srv directory, start bigcouch on all of them:

/etc/init.d/bigcouch start

 

You should then be able to restart all other services as a clean-slate.  Don’t for get to re-import your media files and create the initial account again.

 

From: 2600hz...@googlegroups.com [mailto:2600hz...@googlegroups.com] On Behalf Of Loren Burlingame
Sent: Wednesday, December 18, 2013 12:18 PM
To: 2600hz...@googlegroups.com
Subject: Re: [New install] Issues with Kamailio, DB and outbound calling

 

Thanks for the reply.

--

[Loren Burlingame]

Thank you very much for the procedure.

I have done this and have successfully created a fresh set of DB files.

I am now trying to create the initial account using:

/opt/kazoo/utils/sup/sup crossbar_maintenance create_account TTT "Tonka TelTec" tttadmin tonkatt

but I get the following:

Connection to service failed!
Failed to connect to service 'whistl...@kaio.tttphone.com' with cookie 'frees...@kaio.ttt.lan'
  Possible fixes:
    * Ensure the whistle service you are trying to connect to is running on the host
    * Ensure that you are using the same cookie as the whistle node, "./sup -c <cookie>"
    * Verify that the hostname being used is a whistle node

I followed the directions for creating a new account manually from here:

https://2600hz.atlassian.net/wiki/display/docs/Creating+Accounts+Manually

which was fine up until the very last step:

[root@kaio kazoo]#  /opt/kazoo/scripts/conn-to-apps.sh
Connection to service failed!
Erlang R15B03 (erts-5.9.3.1) [source] [64-bit] [smp:8:8] [async-threads:0] [hipe] [kernel-poll:false]

*** ERROR: Shell process terminated! (^G to start new job) ***

which, I am pretty sure is related to the initial failure.

So either, I do not have a key service running or the cookie deal is incorrect.

Here is the output from epmd -names:

[root@kaio ~]# epmd -names
epmd: up and running on port 4369 with data:
name freeswitch at port 56581
name rabbit at port 40073
name bigcouch at port 11500

[Karl Anderson]

The Erlang Port Manager indicates that whapps and ecallmgr are not running.  Try:

 

/etc/init.d/kz-whistle_apps start

/etc/init.d/kz-ecallmgr start

 

 

You should see:

 

[root@kaio ~]# epmd -names
epmd: up and running on port 4369 with data:
name freeswitch at port 56581
name rabbit at port 40073
name bigcouch at port 11500

name whistle_apps at port #####

name ecallmgr at port #####

[James Aimonetti]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

whistle_apps and ecallmgr are both not running (as evidenced by your
epmd output).

You should have /etc/init.d/kz-* scripts for whistle_apps and
ecallmgr, and you should also be able to use 'service' to start them:

service kz-whistle_apps start
service kz-ecallmgr start

Having those running will make the SUP commands much more effective ;)

>> especially. Then move the database directory and recreate it�

>> this will effectively allow bigcouch to build up the shards with
>> the proper hostnames. Notice, these commands are typed from
>> memory and should be considered close approximations:
>>
>>
>>
>> On all bigcouch servers:
>>
>> /etc/init.d/bigcouch stop
>>
>>
>>
>> Once all bigcouch instances have been stopped, repeat this
>> command on db servers:
>>
>> mv /srv /$(date +%s)-srv
>>
>> mkdir /srv
>>
>> chown bigcouch:bigcouch /srv
>>
>>
>>
>> Once no bigcouch server has anything in the /srv directory, start
>> bigcouch on all of them:
>>
>> /etc/init.d/bigcouch start
>>
>>
>>
>> You should then be able to restart all other services as a

>> clean-slate. Don�t for get to re-import your media files and

>> create the initial account again.
>>
>>
>>

>> *From:* 2600hz...@googlegroups.com <javascript:> [mailto:
>> 2600hz...@googlegroups.com <javascript:>] *On Behalf Of *Loren
>> Burlingame *Sent:* Wednesday, December 18, 2013 12:18 PM *To:*
>> 2600hz...@googlegroups.com <javascript:> *Subject:* Re: [New

>> 2600hz-users...@googlegroups.com <javascript:>. For more options,
>> visit https://groups.google.com/groups/opt_out.
>>
>

- --
James Aimonetti
Lead Systems Architect
"I thought I fixed that"

2600Hz | http://2600hz.com
sip:ja...@2600hz.com
tel:415.886.7905
irc:mc_ @ freenode
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iF4EAREIAAYFAlKzN8wACgkQ54NxaUq7OmBCOwD8CM7IZZvX6dafGENwdHpBJhPW
NrsOaky7m60SVemc3fsBAKnFxerikISTQdIKptMxWS2nRjxlwvY4Yev516pC7ZXW
=d2H0
-----END PGP SIGNATURE-----

[Loren Burlingame]

Yep, thanks to all!

I actually had started those services earlier but perhaps I did not have bigcouch started at the time... restarting the services got everything working again.

I know these are newbish problems and I appreciate everyone for being patient with me.

sip:...@2600hz.com

[Loren Burlingame]

So, I am back now at the point where I need to troubleshoot this route set issue.

I disabled the "loose_route" lines in the default.cfg file under /etc/kazoo/kamailio and it is now getting further.

Here is what I am seeing now: http://tttphone.com:9980/pastie/p.pl/get/yjPVbcl4

*snipped*

[Karl Anderson]

Dec 19 17:57:06 kaio kamailio[3928]: WARNING: <script>: US...@BA.CA.DA.ED|end|no servers avaliable in group 1 or 2

 

The error about having no servers available in either group is referencing the fact that kamailio does not have a FreeSWITCH server available.  This could be because:

1)     Kamailio is misconfigured

2)     FreeSWITCH is not running (or mod_sofia isn’t running which could indicate ecallmgr did not connect to FreeSWITCH)

3)     The network is not allowing Kamailio to reach FreeSWITCH

 

You can check by running the command to get the list of FreeSWITCH servers that kamailio knows about (and their status up/down):

kamctl fifo ds_list

 

If you don’t know which IP/port FreeSWITCH is using you can run (on the server where FreeSWITCH is):

fs_cli -x 'sofia status'

 

If the sofia status gives you an error, try adding the FreeSWITCH node to Kazoo via:

sup -n ecallmgr ecallmgr_maintenance add_fs_node freeswitch@{REPLACE_ME_WITH_THE_HOSTNAME}

 

To set the IP/port update the config (and restart Kamailio):

/etc/kazoo/kamailio/dbtext/dispatcher

 

 

 

From: Loren Burlingame [mailto:loren.bu...@gmail.com]

Sent: Thursday, December 19, 2013 4:08 PM
To: 2600hz...@googlegroups.com
Cc: Karl Anderson

[Loren Burlingame]

Huzza!

Thank you very much! This got me to where I needed to be.

I added the node to Kazoo using your sup command and I am now able to make a call!

On Thursday, December 19, 2013 7:11:26 PM UTC-6, Karl Anderson wrote:

Dec 19 17:57:06 kaio kamailio[3928]: WARNING: <script>: US...@BA.CA.DA.ED|end|no servers avaliable in group 1 or 2

 

The error about having no servers available in either group is referencing the fact that kamailio does not have a FreeSWITCH server available.  This could be because:

1)     Kamailio is misconfigured

2)     FreeSWITCH is not running (or mod_sofia isn’t running which could indicate ecallmgr did not connect to FreeSWITCH)

3)     The network is not allowing Kamailio to reach FreeSWITCH

 

You can check by running the command to get the list of FreeSWITCH servers that kamailio knows about (and their status up/down):

kamctl fifo ds_list

 

If you don’t know which IP/port FreeSWITCH is using you can run (on the server where FreeSWITCH is):

fs_cli -x 'sofia status'

 

If the sofia status gives you an error, try adding the FreeSWITCH node to Kazoo via:

sup -n ecallmgr ecallmgr_maintenance add_fs_node freeswitch@{REPLACE_ME_WITH_THE_HOSTNAME}

 

To set the IP/port update the config (and restart Kamailio):

/etc/kazoo/kamailio/dbtext/dispatcher

 

 

 

From: Loren Burlingame [mailto:loren.bu...@gmail.com]
Sent: Thursday, December 19, 2013 4:08 PM
To: 2600hz...@googlegroups.com
Cc: Karl Anderson
Subject: Re: [New install] Issues with Kamailio, DB and outbound calling

 

So, I am back now at the point where I need to troubleshoot this route set issue.

I disabled the "loose_route" lines in the default.cfg file under /etc/kazoo/kamailio and it is now getting further.

Here is what I am seeing now: http://tttphone.com:9980/pastie/p.pl/get/yjPVbcl4


On Tuesday, December 17, 2013 7:21:12 PM UTC-6, Karl Anderson wrote:

However, the real issue is your SIP endpoint sent the initial request with a route set.  This is not allowed by the default Kazoo config because it would allow public Kamailio servers to be used as an open relay.  The log line that indicates this in in kamailio.log:

Dec 17 17:09:04 kaio kamailio[30952]: WARNING: <script>: 79639742...@BA.CA.DA.ED|end|denying initial request with route-set

[Yumminova Telecom]

Please replace chown bigcouch:bigcouch 

to 

chown bigcouch:deamon

Op woensdag 18 december 2013 21:59:46 UTC+1 schreef Karl Anderson: