SIP inbound getting "CHANUNAVAIL"

MY question: I just installed the latest IncrediblePBX for the RaspberryPi 13-13.7 with Asterisk 13.22.0, with all of the updates. I have not made any manual changes to GVsip1. Google Voice is working, and a couple of extensions as well. I can’t get the Vitelity inbound route to work. Vitelity Outbound works, the DID is correct, I called Vitelity on that. I have left CID to “Any”. I even created a route from Any DID and Any CID, and still no answer. At one point it was working, but then GVsip1 was not, now GVsip1 is working and now Vitelity inbound is not. The extensions are working.

I don’t have a fixed external IP, and my internal IP is 192.168.1.206.
Is this possibly the problem? The only external inputs is Google Voice, and Vitelity Inbound.
I have had bad luck with dynamic dns providers

My DID is correct.
But Vitelity sends me an email that “chanunavail” error. In the log I see:
So Vitelity is getting thru. From the report information, you can see that
Both Vitelity inbound and outbound are registered, but unmonitored.

Name/username Host Dyn Forcerport Comedia ACL Port Status Description
163/163 192.168.1.201 D No No A 5061 OK (19 ms)
165/165 192.168.1.164 D Yes Yes A 5060 OK (115 ms)
701/701 192.168.1.164 D Yes Yes A 5060 OK (148 ms)
702/702 192.168.1.101 D No No A 34787 OK (19 ms)
vitel-inbound/xxxxxxxxxxxx 64.2.142.116 Yes Yes 5060 Unmonitored
vitel-outbound/xxxxxxxxxxx 64.2.142.216 Yes Yes 5060 Unmonitored
6 sip peers [Monitored: 4 online, 0 offline Unmonitored: 2 online, 0 offline]

Is it the vitality inbound registration that asterisk thinks fails?

asterisk -rddddddddd

I am new so I only get two links, and there is no definition of a link. So I will post this,

What am I missing?
Where else should I look?
Thanks for your help.

Connected to Asterisk 13.22.0 currently running on pi-new (pid = 6142)
Core debug is still 9.
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:9013 __sip_alloc: Allocating new SIP dialog for 00342e95081cb8b15bb4aab929eee814@192.168.1.206 - REGISTER (No RTP)
[2018-10-27 15:06:32] DEBUG[6248]: acl.c:992 ast_ouraddrfor: For destination ‘64.2.142.116’, our source address is ‘192.168.1.206’.
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:3908 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.1.206:5060
[2018-10-27 15:06:32] DEBUG[6248]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘inbound18.vitelity.net’ into…
[2018-10-27 15:06:32] DEBUG[6248]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘inbound18.vitelity.net’ and port ‘’.
[2018-10-27 15:06:32] DEBUG[6248]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘inbound18.vitelity.net’ into…
[2018-10-27 15:06:32] DEBUG[6248]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘inbound18.vitelity.net’ and port ‘’.
[2018-10-27 15:06:32] DEBUG[6248]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘inbound18.vitelity.net’ into…
[2018-10-27 15:06:32] DEBUG[6248]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘inbound18.vitelity.net’ and port ‘’.
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:3394 initialize_initreq: Initializing initreq for method REGISTER - callid 00342e95081cb8b15bb4aab929eee814@192.168.1.206
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:16233 transmit_register: REGISTER attempt 1 to xxxxxxxx@inbound18.vitelity.net
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:3751 __sip_xmit: Trying to put ‘REGISTER si’ onto UDP socket destined for 64.2.142.116:5060
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:15962 __start_register_timeout: Scheduled a registration timeout for inbound18.vitelity.net id #6
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:9426 __find_call: = Looking for Call ID: 00342e95081cb8b15bb4aab929eee814@192.168.1.206 (Checking To) --From tag as37409737 --To-tag
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:9426 __find_call: = Looking for Call ID: 00342e95081cb8b15bb4aab929eee814@192.168.1.206 (Checking To) --From tag as37409737 --To-tag as34283a28
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:4535 __sip_ack: Stopping retransmission on ‘00342e95081cb8b15bb4aab929eee814@192.168.1.206’ of Request 106: Match Found
[2018-10-27 15:06:32] DEBUG[6248]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘inbound18.vitelity.net’ into…
[2018-10-27 15:06:32] DEBUG[6248]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘inbound18.vitelity.net’ and port ‘’.
[2018-10-27 15:06:32] DEBUG[6248]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘inbound18.vitelity.net’ into…
[2018-10-27 15:06:32] DEBUG[6248]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘inbound18.vitelity.net’ and port ‘’.
[2018-10-27 15:06:32] DEBUG[6248]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘inbound18.vitelity.net’ into…
[2018-10-27 15:06:32] DEBUG[6248]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘inbound18.vitelity.net’ and port ‘’.
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:3392 initialize_initreq: Initializing already initialized SIP dialog 00342e95081cb8b15bb4aab929eee814@192.168.1.206 (presumably reinvite)
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:16233 transmit_register: REGISTER attempt 2 to xxxxxxxx@inbound18.vitelity.net
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:3751 __sip_xmit: Trying to put ‘REGISTER si’ onto UDP socket destined for 64.2.142.116:5060
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:9426 __find_call: = Looking for Call ID: 00342e95081cb8b15bb4aab929eee814@192.168.1.206 (Checking To) --From tag as37409737 --To-tag
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:9426 __find_call: = Looking for Call ID: 00342e95081cb8b15bb4aab929eee814@192.168.1.206 (Checking To) --From tag as37409737 --To-tag as34283a28
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:4535 __sip_ack: Stopping retransmission on ‘00342e95081cb8b15bb4aab929eee814@192.168.1.206’ of Request 107: Match Found
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:24548 handle_response_register: Registration successful
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:24550 handle_response_register: Cancelling timeout 6
[2018-10-27 15:06:32] DEBUG[6248]: chan_sip.c:6587 sip_pvt_dtor: Destroying SIP dialog 00342e95081cb8b15bb4aab929eee814@192.168.1.206
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:9426 __find_call: = Looking for Call ID: S8r3JZVaSDmz9eir4Y4Cgw… (Checking From) --From tag d7e4ef58 --To-tag
[2018-10-27 15:06:50] DEBUG[6248]: acl.c:992 ast_ouraddrfor: For destination ‘192.168.1.101’, our source address is ‘192.168.1.206’.
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:3908 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.1.206:5060
[2018-10-27 15:06:50] DEBUG[6248]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘192.168.1.101:34787’ into…
[2018-10-27 15:06:50] DEBUG[6248]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘192.168.1.101’ and port ‘34787’.
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:9013 __sip_alloc: Allocating new SIP dialog for S8r3JZVaSDmz9eir4Y4Cgw… - REGISTER (No RTP)
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:28848 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER
[2018-10-27 15:06:50] DEBUG[6248]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘192.168.1.101:34787’ into…
[2018-10-27 15:06:50] DEBUG[6248]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘192.168.1.101’ and port ‘34787’.
[2018-10-27 15:06:50] DEBUG[6248]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘192.168.1.206:5060’ into…
[2018-10-27 15:06:50] DEBUG[6248]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘192.168.1.206’ and port ‘’.
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:3751 __sip_xmit: Trying to put ‘SIP/2.0 401’ onto UDP socket destined for 192.168.1.101:34787
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:9426 __find_call: = Looking for Call ID: S8r3JZVaSDmz9eir4Y4Cgw… (Checking From) --From tag d7e4ef58 --To-tag
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:28848 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER
[2018-10-27 15:06:50] DEBUG[6248]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘192.168.1.101:34787’ into…
[2018-10-27 15:06:50] DEBUG[6248]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘192.168.1.101’ and port ‘34787’.
[2018-10-27 15:06:50] DEBUG[6248]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘192.168.1.206:5060’ into…
[2018-10-27 15:06:50] DEBUG[6248]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘192.168.1.206’ and port ‘’.
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:16928 parse_register_contact: Store REGISTER’s Contact header for call routing.
[2018-10-27 15:06:50] DEBUG[6248]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘192.168.1.101:34787’ into…
[2018-10-27 15:06:50] DEBUG[6248]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘192.168.1.101’ and port ‘34787’.
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:17114 build_path: build_path: do not use Path headers
[2018-10-27 15:06:50] DEBUG[6168]: threadpool.c:517 grow: Increasing threadpool stasis-core’s size by 1
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:9013 __sip_alloc: Allocating new SIP dialog for 3f1e788229ca858008ed5e5d788196c2@192.168.1.206:5060 - OPTIONS (No RTP)
[2018-10-27 15:06:50] DEBUG[6248]: acl.c:992 ast_ouraddrfor: For destination ‘192.168.1.101’, our source address is ‘192.168.1.206’.
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:3908 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.1.206:5060
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:8798 change_callid_pvt: SIP call-id changed from ‘3f1e788229ca858008ed5e5d788196c2@192.168.1.206:5060’ to ‘501587ef40a75e46076ebc0d3d70594f@192.168.1.206:5060’
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:3394 initialize_initreq: Initializing initreq for method OPTIONS - callid 501587ef40a75e46076ebc0d3d70594f@192.168.1.206:5060
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:3751 __sip_xmit: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.1.101:34787
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:3751 __sip_xmit: Trying to put ‘SIP/2.0 200’ onto UDP socket destined for 192.168.1.101:34787
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:9013 __sip_alloc: Allocating new SIP dialog for 7c013a2a5484647e6a07fb003afc2dce@192.168.1.206:5060 - NOTIFY (No RTP)
[2018-10-27 15:06:50] DEBUG[6248]: acl.c:992 ast_ouraddrfor: For destination ‘192.168.1.101’, our source address is ‘192.168.1.206’.
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:3908 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.1.206:5060
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:8798 change_callid_pvt: SIP call-id changed from ‘7c013a2a5484647e6a07fb003afc2dce@192.168.1.206:5060’ to ‘10e99b2f5cef564f2991b3974f83719b@192.168.1.206:5060’
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:3394 initialize_initreq: Initializing initreq for method NOTIFY - callid 10e99b2f5cef564f2991b3974f83719b@192.168.1.206:5060
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:3751 __sip_xmit: Trying to put ‘NOTIFY sip:’ onto UDP socket destined for 192.168.1.101:34787
[2018-10-27 15:06:50] DEBUG[6181]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for SIP - 702
[2018-10-27 15:06:50] DEBUG[6181]: chan_sip.c:30386 sip_devicestate: Checking device state for peer 702
[2018-10-27 15:06:50] DEBUG[6181]: devicestate.c:474 do_state_change: Changing state for SIP/702 - state 1 (Not in use)
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:9426 __find_call: = Looking for Call ID: 501587ef40a75e46076ebc0d3d70594f@192.168.1.206:5060 (Checking To) --From tag as574df0e0 --To-tag e3c7b74f
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:4535 __sip_ack: Stopping retransmission on ‘501587ef40a75e46076ebc0d3d70594f@192.168.1.206:5060’ of Request 102: Match Found
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:6587 sip_pvt_dtor: Destroying SIP dialog 501587ef40a75e46076ebc0d3d70594f@192.168.1.206:5060
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:9426 __find_call: = Looking for Call ID: 10e99b2f5cef564f2991b3974f83719b@192.168.1.206:5060 (Checking To) --From tag as7b7e95df --To-tag fe23d606
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:4535 __sip_ack: Stopping retransmission on ‘10e99b2f5cef564f2991b3974f83719b@192.168.1.206:5060’ of Request 102: Match Found
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:24233 handle_response_notify: Got 200 accepted on NOTIFY 10e99b2f5cef564f2991b3974f83719b@192.168.1.206:5060
[2018-10-27 15:06:50] DEBUG[6248]: chan_sip.c:6587 sip_pvt_dtor: Destroying SIP dialog 10e99b2f5cef564f2991b3974f83719b@192.168.1.206:5060
[2018-10-27 15:06:51] DEBUG[6222]: res_pjsip_registrar.c:1186 check_expiration_thread: Woke up at 1540670811 Interval: 30
[2018-10-27 15:06:51] DEBUG[6222]: res_pjsip_registrar.c:1193 check_expiration_thread: Expiring 0 contacts
[2018-10-27 15:06:51] DEBUG[6249]: res_pjsip_registrar_expire.c:78 check_expiration_thread: Woke up at 1540670811 Interval: 30
[2018-10-27 15:06:51] DEBUG[6249]: res_pjsip_registrar_expire.c:85 check_expiration_thread: Expiring 0 contacts
[2018-10-27 15:06:52] DEBUG[6185]: dnsmgr.c:286 refresh_list: Refreshing DNS lookups.
[2018-10-27 15:06:52] DEBUG[6185]: dnsmgr.c:212 dnsmgr_refresh: refreshing ‘inbound18.vitelity.net
[2018-10-27 15:06:52] DEBUG[6185]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘inbound18.vitelity.net’ into…
[2018-10-27 15:06:52] DEBUG[6185]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘inbound18.vitelity.net’ and port ‘’.
[2018-10-27 15:06:52] DEBUG[6185]: dnsmgr.c:212 dnsmgr_refresh: refreshing ‘outbound.vitelity.net
[2018-10-27 15:06:52] DEBUG[6185]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘outbound.vitelity.net’ into…
[2018-10-27 15:06:52] DEBUG[6185]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘outbound.vitelity.net’ and port ‘’.
[2018-10-27 15:06:52] DEBUG[6185]: acl.c:830 resolve_first: Multiple addresses. Using the first only
[2018-10-27 15:06:52] DEBUG[6185]: dnsmgr.c:212 dnsmgr_refresh: refreshing ‘inbound18.vitelity.net
[2018-10-27 15:06:53] DEBUG[6185]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting ‘inbound18.vitelity.net’ into…
[2018-10-27 15:06:53] DEBUG[6185]: netsock2.c:226 ast_sockaddr_split_hostport: …host ‘inbound18.vitelity.net’ and port ‘’.

I am not experienced any more in Asterisk or Linux. It has been 10 years since the last time I created a Asterisk system, so I am very much out of practice. I thank you in advance for any help, or direction if I am in the wrong forum for this type of question.

Your first post used a lot of terms that are not standard Asterisk terms.

Your second post doesn’t include the actual SIP packet contents, which is what we normally look at first.

I have never heard of an ITSP issuing a REGISTER towards a customer…

David, Thank you for your reply. I am not an Asterisk expert. It has been a decade since I installed it last. Let me know what terms might I explain more. The Asterisk output was from debug mode. I don’t know how to get the contents of the Sip Packets. Here is what I did:

asterisk -rdddddddddd
Parsing /etc/asterisk/asterisk.conf
Seeding global EID ‘b8:27:eb:a9:7e:8e’ from ‘eth0’ using ‘siocgifhwaddr’
Asterisk 13.22.0, Copyright © 1999 - 2014, Digium, Inc. and others.
Created by Mark Spencer markster@digium.com
Asterisk comes with ABSOLUTELY NO WARRANTY; type ‘core show warranty’ for details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type ‘core show license’ for details.

Connected to Asterisk 13.22.0 currently running on pi-new (pid = 6142)
Core debug was 9 and is now 10.

If you can tell me how to get the Sip contents I will do my best to post it here.

If you mean the Sip Settings, here is the Vitelity Inbound Configuration:
username=xxxxxxxxx
type=friend
t38pt_udptl=no
t38pt_tcp=no
t38pt_rtp=no
secret=zzzzzzzzz
insecure=port,invite
nat=yes
host=inbound18.vitelity.net
disallow=all
context=from-trunk
canreinvite=no
allow=ulaw

Again, Thank you for your help.

Please provide SIP traces (sip set debug on, Verbose output).

OK, I am going to work on tcpdump in the right format. But first the Vitelity Inbound quick busy was partially resolved. Vitelity was not sending the inbound information to Asterisk. Somewhere along the way the SIP routing on the Vitelity side was lost. For those who might have the same problem, here is the solution from Vitelity Support. Make sure you have an endpoint in the Subaccount:

To update the routing method for your numbers, please follow the

  1. Log into the user portal (portal.vitelity.net)
  2. Go to the “My products and services” menu on the left side of the
    screen
  3. Click on “My Numbers”
  4. Choose “All”
  5. Locate the DID you would like to change the routing for , click on
    the “Action Menu”
  6. Choose "Routing method "
  7. Keep protocol as “SIP via UDP”
  8. Choose device type (server, ata device etc)
  9. Put a check mark next to the sub accounts/ IP endpoints you
    would like the DID to be routing to
  10. Confirm settings, and press “Submit”

I can’t figure out how to get the tcpdump in a printable format so that I can post it here. The first 1xx chars are in binary, so not translated to printable. Here is what I did for tcpdump:

apt-get install tcpdump
tcpdump --version
tcpdump version 4.9.0
libpcap version 1.6.2
OpenSSL 1.0.1t 3 May 2016

tcpdump -A -w /var/log/asterisk/tcplog -i eth0 -T pgm
-w write to a file
-i eth0 (Ethernet Interface)
-T pgm (type of data)

I tried -A, -b, -d options separately, and still I have binary in the first 1xx characters. I read every option in the man tcpdump and still could not figure this out. Any help would be appreciated. Thanks

Now, I have to search for a new topic. The first time I connect with Vitelity, is rings many times and I can answer and connect. The next time after a successful connection, it rings once, and then I get an extension is busy response. Any suggestions while I work on getting the logs?

If you want to present protocol traces for packets that actually reached Asterisk, you want to use the in built protocol logging options, e.g. sip set debug on. People here are most familiar with debugging from them.

If you are capturing SIP that Asterisk is not seeing, you can read the tcpdump file into wireshark.

tcpdump doesn’t have the deep knowledge of protocols to be able to print out SIP cleanly, although tcpdump -r /var/log/asterisk/tcplog would analyze it to the extent that it can do so.

Thanks for the help. I hope the Vitelity reply helps someone else.