404 from Viatalk w/asterisk manual config, works w/trixbox

Recently I decided to set up Asterisk on my main server (Gentoo x64) rather than continue with an independent server running trixbox (Asterisk 1.2.13). This means i currently have a working trixbox install and a non-working from-source install to compare to each other. During the troubleshooting below, both servers were not running asterisk at the same time (/etc/init.d/asterisk stop on one before starting the other)

First I tried 1.6 beta, now am using 1.4.17, as I thought some synax change or beta issue was the problem. It is apparently not. I built both from source, and uninstalled 1.6 before installing 1.4.17. There don’t appear to me any errors with the build or in the starup of Asterisk.
Here is the log from the last asterisk startup:

[Jan 20 23:30:52] NOTICE[8463] cdr.c: CDR simple logging enabled.
[Jan 20 23:30:52] NOTICE[8463] loader.c: 146 modules will be loaded.
[Jan 20 23:30:52] WARNING[8463] res_smdi.c: No SMDI interfaces are available to listen on, not starting SMDI listener.
[Jan 20 23:30:52] NOTICE[8463] pbx_ael.c: Starting AEL load process.
[Jan 20 23:30:52] NOTICE[8463] pbx_ael.c: AEL load process: calculated config file name '/etc/asterisk/extensions.ael'.
[Jan 20 23:30:52] NOTICE[8463] pbx_ael.c: AEL load process: parsed config file name '/etc/asterisk/extensions.ael'.
[Jan 20 23:30:52] NOTICE[8463] pbx_ael.c: AEL load process: checked config file name '/etc/asterisk/extensions.ael'.
[Jan 20 23:30:52] NOTICE[8463] pbx_ael.c: AEL load process: compiled config file name '/etc/asterisk/extensions.ael'.
[Jan 20 23:30:52] NOTICE[8463] pbx_ael.c: AEL load process: merged config file name '/etc/asterisk/extensions.ael'.
[Jan 20 23:30:52] NOTICE[8463] pbx_ael.c: AEL load process: verified config file name '/etc/asterisk/extensions.ael'.
[Jan 20 23:30:53] NOTICE[8477] chan_sip.c: Peer 'ViatalkSIP' is now Reachable. (75ms / 2000ms)

I am attempting to register with Viatalk via SIP, and have that channel passed to the context listed in the peer definition.

The context was built using the O’reilly simple context of Answer, Playback, Hangup.

Context Snippet from extensions.conf:

[from-sip-trunk] exten => s,1,Answer() exten => s,n,Playback(demo-congrats.gsm) exten => s,n,Hangup() ; end of [from-sip-trunk]

Asterisk is aware of the context:

BigBox*CLI> dialplan show from-sip-trunk
[ Context 'from-sip-trunk' created by 'pbx_config' ]
's' =>            1. Answer()                                   [pbx_config]
                    2. Playback(demo-congrats.gsm)                [pbx_config]
                    3. Hangup()                                   [pbx_config]

Peer snippet from sip.conf:

register=1541705xxxx:xxxxxxxxxx@sanfrancisco-1.vtnoc.net
[ViatalkSIP]
username=1541705xxxx
type=peer
secret=xxxxxxxxx
qualify=yes
insecure=port,invite
host=sanfrancisco-1.vtnoc.net
fromuser=1541705xxxx
fromdomain=sanfrancisco-1.vtnoc.net
dtmfmode=inband
dtmf=auto
disallow=all
context=from-sip-trunk
canreinvite=yes
authuser=1541705xxxx
allow=ulaw

Registration never seems to happen. Setting the debug flag shows every Options (102) packet sent receives a 404 from Viatalk (if i’m reading this correctly).

BigBox*CLI> sip set debug peer ViatalkSIP
SIP Debugging Enabled for IP: 216.246.105.146:5060
Reliably Transmitting (no NAT) to 216.246.105.146:5060:
OPTIONS sip:sanfrancisco-1.vtnoc.net SIP/2.0
Via: SIP/2.0/UDP 192.168.11.10:5060;branch=z9hG4bK1712b2a9;rport
From: "asterisk" <sip:asterisk@192.168.11.10>;tag=as208fc522
To: <sip:sanfrancisco-1.vtnoc.net>
Contact: <sip:asterisk@192.168.11.10>
Call-ID: 6d8eaf1552140c411d852c5c681181b3@192.168.11.10
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Mon, 21 Jan 2008 07:45:40 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


---
BigBox*CLI> 
<--- SIP read from 216.246.105.146:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 71.94.236.209:5060;branch=z9hG4bK1712b2a9;received=71.94.236.209;rport=5060
From: "asterisk" <sip:asterisk@192.168.11.10>;tag=as208fc522
To: <sip:sanfrancisco-1.vtnoc.net>;tag=as447af17e
Call-ID: 6d8eaf1552140c411d852c5c681181b3@192.168.11.10
CSeq: 102 OPTIONS
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Accept: application/sdp
Content-Length: 0
BigBox*CLI> 

<------------->
--- (11 headers 0 lines) ---
Really destroying SIP dialog '6d8eaf1552140c411d852c5c681181b3@192.168.11.10' Method: OPTIONS
Reliably Transmitting (no NAT) to 216.246.105.146:5060:
OPTIONS sip:sanfrancisco-1.vtnoc.net SIP/2.0
Via: SIP/2.0/UDP 192.168.11.10:5060;branch=z9hG4bK70a08aa1;rport
From: "asterisk" <sip:asterisk@192.168.11.10>;tag=as3c61deca
To: <sip:sanfrancisco-1.vtnoc.net>
Contact: <sip:asterisk@192.168.11.10>
Call-ID: 7025f648535b3aa2155c577d469476bb@192.168.11.10
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Mon, 21 Jan 2008 07:46:40 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


---
BigBox*CLI> 
<--- SIP read from 216.246.105.146:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 71.94.236.209:5060;branch=z9hG4bK70a08aa1;received=71.94.236.209;rport=5060
From: "asterisk" <sip:asterisk@192.168.11.10>;tag=as3c61deca
To: <sip:sanfrancisco-1.vtnoc.net>;tag=as5250793a
Call-ID: 7025f648535b3aa2155c577d469476bb@192.168.11.10
CSeq: 102 OPTIONS
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Accept: application/sdp
Content-Length: 0
BigBox*CLI> 

The trixbox install is still working, even though I see some 404’s and 401s from Viatalk.

asterisk1*CLI> sip show registry 
Host                            Username       Refresh State               
sanfrancisco-1.vtnoc.net:5060   1541705xxxx        105 Registered       

Here is a snippet from the working trixbox sip.conf:

register=1541705xxxx:xxxxxxxxxx@sanfrancisco-1.vtnoc.net
[ViatalkSIP]
username=1541705xxxx
type=peer
secret=xxxxxxxxxx
qualify=yes
insecure=very
host=sanfrancisco-1.vtnoc.net
fromuser=1541705xxxx
fromdomain=sanfrancisco-1.vtnoc.net
dtmfmode=inband
dtmf=auto
disallow=all
context=from-trunk
canreinvite=yes
authuser=1541705xxxx
allow=ulaw

and here is the debug output from the working server asterisk -r, showing 404s and 401s:

asterisk1*CLI> sip debug peer ViatalkSIP 
SIP Debugging Enabled for IP: 216.246.105.146:5060
Destroying call '5edf81661626fc6366f5e884037899a7@127.0.0.1'
12 headers, 0 lines
Reliably Transmitting (no NAT) to 216.246.105.146:5060:
OPTIONS sip:sanfrancisco-1.vtnoc.net SIP/2.0
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK5dff7406;rport
From: "Unknown" <sip:Unknown@192.168.11.11>;tag=as5b031151
To: <sip:sanfrancisco-1.vtnoc.net>
Contact: <sip:Unknown@192.168.11.11>
Call-ID: 5fd41fcc5caa6cfa4e6e403669784c5a@192.168.11.11
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Sun, 20 Jan 2008 23:43:04 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0


---
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK5dff7406;received=71.94.236.209;rport=1024
From: "Unknown" <sip:Unknown@192.168.11.11>;tag=as5b031151
To: <sip:sanfrancisco-1.vtnoc.net>;tag=as37c70ca4
Call-ID: 5fd41fcc5caa6cfa4e6e403669784c5a@192.168.11.11
CSeq: 102 OPTIONS
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Accept: application/sdp
Content-Length: 0


--- (11 headers 0 lines) ---
Destroying call '5fd41fcc5caa6cfa4e6e403669784c5a@192.168.11.11'
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
OPTIONS sip:s@192.168.11.11 SIP/2.0
Via: SIP/2.0/UDP 216.246.105.146:5060;branch=z9hG4bK5a543db8;rport
From: "asterisk" <sip:asterisk@216.246.105.146>;tag=as6efa984b
To: <sip:s@192.168.11.11>
Contact: <sip:asterisk@216.246.105.146>
Call-ID: 50e0794954db24943ead03174be27082@216.246.105.146
CSeq: 102 OPTIONS
User-Agent: Viatalk SIP
Max-Forwards: 70
Date: Sun, 20 Jan 2008 23:43:00 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


--- (13 headers 0 lines) ---
Looking for s in from-sip-external (domain 192.168.11.11)
Transmitting (no NAT) to 216.246.105.146:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 216.246.105.146:5060;branch=z9hG4bK5a543db8;received=216.246.105.146;rport=5060
From: "asterisk" <sip:asterisk@216.246.105.146>;tag=as6efa984b
To: <sip:s@192.168.11.11>;tag=as50ce0239
Call-ID: 50e0794954db24943ead03174be27082@216.246.105.146
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:192.168.11.11>
Accept: application/sdp
Content-Length: 0


---
Destroying call '50e0794954db24943ead03174be27082@216.246.105.146'
REGISTER 13 headers, 0 lines
Reliably Transmitting (no NAT) to 216.246.105.146:5060:
REGISTER sip:sanfrancisco-1.vtnoc.net SIP/2.0
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK7aee35e7;rport
From: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as526557dc
To: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>
Call-ID: 5edf81661626fc6366f5e884037899a7@127.0.0.1
CSeq: 104 REGISTER
User-Agent: Asterisk PBX
Max-Forwards: 70
Authorization: Digest username="1541705xxxx", realm="asterisk", algorithm=MD5, uri="sip:sanfrancisco-1.vtnoc.net", nonce="4c73f20b", response="1fcff740556e719624760a1f423a6035", opaque=""
Expires: 120
Contact: <sip:s@192.168.11.11>
Event: registration
Content-Length: 0


---
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK7aee35e7;received=71.94.236.209;rport=1024
From: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as526557dc
To: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>
Call-ID: 5edf81661626fc6366f5e884037899a7@127.0.0.1
CSeq: 104 REGISTER
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:1541705xxxx@216.246.105.146>
Content-Length: 0


--- (11 headers 0 lines) ---

<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK7aee35e7;received=71.94.236.209;rport=1024
From: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as526557dc
To: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as31e36174
Call-ID: 5edf81661626fc6366f5e884037899a7@127.0.0.1
CSeq: 104 REGISTER
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="075a96d5"
Content-Length: 0


--- (11 headers 0 lines) ---
Responding to challenge, registration to domain/host name sanfrancisco-1.vtnoc.net
REGISTER 13 headers, 0 lines
Reliably Transmitting (no NAT) to 216.246.105.146:5060:
REGISTER sip:sanfrancisco-1.vtnoc.net SIP/2.0
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK079aa3b4;rport
From: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as0f869aef
To: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>
Call-ID: 5edf81661626fc6366f5e884037899a7@127.0.0.1
CSeq: 105 REGISTER
User-Agent: Asterisk PBX
Max-Forwards: 70
Authorization: Digest username="1541705xxxx", realm="asterisk", algorithm=MD5, uri="sip:sanfrancisco-1.vtnoc.net", nonce="075a96d5", response="c350046d77eb492446b32be6d0ff6c39", opaque=""
Expires: 120
Contact: <sip:s@192.168.11.11>
Event: registration
Content-Length: 0


---
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK079aa3b4;received=71.94.236.209;rport=1024
From: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as0f869aef
To: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>
Call-ID: 5edf81661626fc6366f5e884037899a7@127.0.0.1
CSeq: 105 REGISTER
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:1541705xxxx@216.246.105.146>
Content-Length: 0


--- (11 headers 0 lines) ---

<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK079aa3b4;received=71.94.236.209;rport=1024
From: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as0f869aef
To: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as31e36174
Call-ID: 5edf81661626fc6366f5e884037899a7@127.0.0.1
CSeq: 105 REGISTER
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Expires: 120
Contact: <sip:s@192.168.11.11>;expires=120
Date: Sun, 20 Jan 2008 23:43:46 GMT
Content-Length: 0


--- (13 headers 0 lines) ---
Scheduling destruction of call '5edf81661626fc6366f5e884037899a7@127.0.0.1' in 32000 ms
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
NOTIFY sip:s@192.168.11.11 SIP/2.0
Via: SIP/2.0/UDP 216.246.105.146:5060;branch=z9hG4bK566b7f61;rport
From: "asterisk" <sip:asterisk@216.246.105.146>;tag=as7b332eec
To: <sip:s@192.168.11.11>
Contact: <sip:asterisk@216.246.105.146>
Call-ID: 11d038a049155cbe0367e2956f92302b@216.246.105.146
CSeq: 102 NOTIFY
User-Agent: Viatalk SIP
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 96

Messages-Waiting: yes
Message-Account: sip:asterisk@216.246.105.146
Voice-Message: 1/0 (0/0)

--- (12 headers 3 lines) ---
Transmitting (no NAT) to 216.246.105.146:5060:
SIP/2.0 603 Declined (no dialog)
Via: SIP/2.0/UDP 216.246.105.146:5060;branch=z9hG4bK566b7f61;received=216.246.105.146;rport=5060
From: "asterisk" <sip:asterisk@216.246.105.146>;tag=as7b332eec
To: <sip:s@192.168.11.11>;tag=as5eb1046b
Call-ID: 11d038a049155cbe0367e2956f92302b@216.246.105.146
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0


---
12 headers, 0 lines
Reliably Transmitting (no NAT) to 216.246.105.146:5060:
OPTIONS sip:sanfrancisco-1.vtnoc.net SIP/2.0
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK46fef114;rport
From: "Unknown" <sip:Unknown@192.168.11.11>;tag=as3d6c0ffb
To: <sip:sanfrancisco-1.vtnoc.net>
Contact: <sip:Unknown@192.168.11.11>
Call-ID: 708f420c64bc32d7321d4bb4453baf12@192.168.11.11
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Sun, 20 Jan 2008 23:44:04 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0


---
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK46fef114;received=71.94.236.209;rport=1024
From: "Unknown" <sip:Unknown@192.168.11.11>;tag=as3d6c0ffb
To: <sip:sanfrancisco-1.vtnoc.net>;tag=as64a455f4
Call-ID: 708f420c64bc32d7321d4bb4453baf12@192.168.11.11
CSeq: 102 OPTIONS
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Accept: application/sdp
Content-Length: 0


--- (11 headers 0 lines) ---
Destroying call '708f420c64bc32d7321d4bb4453baf12@192.168.11.11'
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
OPTIONS sip:s@192.168.11.11 SIP/2.0
Via: SIP/2.0/UDP 216.246.105.146:5060;branch=z9hG4bK1f389ccf;rport
From: "asterisk" <sip:asterisk@216.246.105.146>;tag=as1483ccf1
To: <sip:s@192.168.11.11>
Contact: <sip:asterisk@216.246.105.146>
Call-ID: 60713b3114d86b592c7cdcc312ade610@216.246.105.146
CSeq: 102 OPTIONS
User-Agent: Viatalk SIP
Max-Forwards: 70
Date: Sun, 20 Jan 2008 23:44:00 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


--- (13 headers 0 lines) ---
Looking for s in from-sip-external (domain 192.168.11.11)
Transmitting (no NAT) to 216.246.105.146:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 216.246.105.146:5060;branch=z9hG4bK1f389ccf;received=216.246.105.146;rport=5060
From: "asterisk" <sip:asterisk@216.246.105.146>;tag=as1483ccf1
To: <sip:s@192.168.11.11>;tag=as146a24c3
Call-ID: 60713b3114d86b592c7cdcc312ade610@216.246.105.146
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:192.168.11.11>
Accept: application/sdp
Content-Length: 0


---
Destroying call '60713b3114d86b592c7cdcc312ade610@216.246.105.146'
Destroying call '5edf81661626fc6366f5e884037899a7@127.0.0.1'
12 headers, 0 lines
Reliably Transmitting (no NAT) to 216.246.105.146:5060:
OPTIONS sip:sanfrancisco-1.vtnoc.net SIP/2.0
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK0adea207;rport
From: "Unknown" <sip:Unknown@192.168.11.11>;tag=as3e7d4ddd
To: <sip:sanfrancisco-1.vtnoc.net>
Contact: <sip:Unknown@192.168.11.11>
Call-ID: 54f3cb392ff6dc8a526d24cf2edbc1ed@192.168.11.11
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Sun, 20 Jan 2008 23:45:04 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0


---
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK0adea207;received=71.94.236.209;rport=1024
From: "Unknown" <sip:Unknown@192.168.11.11>;tag=as3e7d4ddd
To: <sip:sanfrancisco-1.vtnoc.net>;tag=as73a23222
Call-ID: 54f3cb392ff6dc8a526d24cf2edbc1ed@192.168.11.11
CSeq: 102 OPTIONS
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Accept: application/sdp
Content-Length: 0


--- (11 headers 0 lines) ---
Destroying call '54f3cb392ff6dc8a526d24cf2edbc1ed@192.168.11.11'
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
OPTIONS sip:s@192.168.11.11 SIP/2.0
Via: SIP/2.0/UDP 216.246.105.146:5060;branch=z9hG4bK12e3c53d;rport
From: "asterisk" <sip:asterisk@216.246.105.146>;tag=as209e0ae5
To: <sip:s@192.168.11.11>
Contact: <sip:asterisk@216.246.105.146>
Call-ID: 73ceff352d40ed9f23d24b8c0e26b4ca@216.246.105.146
CSeq: 102 OPTIONS
User-Agent: Viatalk SIP
Max-Forwards: 70
Date: Sun, 20 Jan 2008 23:45:00 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


--- (13 headers 0 lines) ---
Looking for s in from-sip-external (domain 192.168.11.11)
Transmitting (no NAT) to 216.246.105.146:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 216.246.105.146:5060;branch=z9hG4bK12e3c53d;received=216.246.105.146;rport=5060
From: "asterisk" <sip:asterisk@216.246.105.146>;tag=as209e0ae5
To: <sip:s@192.168.11.11>;tag=as6fb205f4
Call-ID: 73ceff352d40ed9f23d24b8c0e26b4ca@216.246.105.146
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:192.168.11.11>
Accept: application/sdp
Content-Length: 0

Additionally, I have packet captures of both if they are needed for diagnosing.

What am I missing here guys? I’ve been pouring over it for hours…
Thanks!
thenextdon13

So, did a little more digging. Saw that in the new config file, the registry string is defined in a different manner. In the following code snippet notice the use of the ‘=>’ rather than just ‘=’:

;----------------------------------------- OUTBOUND SIP REGISTRATIONS  ------------------------
; Asterisk can register as a SIP user agent to a SIP proxy (provider)
; Format for the register statement is:
;       register => user[:secret[]]@host[:port][/extension]
;
; If no extension is given, the 's' extension is used. The extension needs to
; be defined in extensions.conf to be able to accept calls from this SIP proxy
; (provider).
;
; host is either a host name defined in DNS or the name of a section defined
; below.
;
; Examples:
;
;register => 1234:password@mysipprovider.com    
;
;     This will pass incoming calls to the 's' extension

So, realizing that the register string I had been using does not match the syntax shown in the config file, I tried both of the following possiblities

register => 1541705xxxx:xxxxxxxxxx@sanfrancisco-1.vtnoc.net
and
register => 1541705xxxx:xxxxxxxxxx:1541705xxxx@sanfrancisco-1.vtnoc.net

Nether of these register strings appear to do anything different than before. I still send an ‘option’, which is followed by a 404.

Will post additional info as I try other things…

thenextdon13

OK, some additional troubleshooting notes:

To see what the working trixbox did under the circumstance of missing peer section and missing ‘register’ line, I commented them out one by one:

First, without the peer section but retaining the ‘register’ line, as following
sip_additional.conf:

; do not edit this file, this is an auto-generated file by freepbx
; all modifications must be done from the web gui
register=1541705xxxx:xxxxxxxxxx@sanfrancisco-1.vtnoc.net

;[ViatalkSIP]
;username=1541705xxxx
;type=peer
;secret=xxxxxxxxxx
;qualify=yes
;insecure=very
;host=sanfrancisco-1.vtnoc.net
;fromuser=1541705xxxx
;fromdomain=sanfrancisco-1.vtnoc.net
;dtmfmode=inband
;dtmf=auto
;disallow=all
;context=from-trunk
;canreinvite=yes
;authuser=1541705xxxx
;allow=ulaw

With the missing peer lines, the registry still occured fine:

asterisk1*CLI> sip show registry 
Host                            Username       Refresh State               
sanfrancisco-1.vtnoc.net:5060   1541705xxxx        105 Registered        

and, we can still see the SIP packets flowing (although i cannot set debug based on a peer, as there is no peer entry for the register statement):

asterisk1*CLI> sip debug 
SIP Debugging enabled
REGISTER 13 headers, 0 lines
Reliably Transmitting (no NAT) to 216.246.105.146:5060:
REGISTER sip:sanfrancisco-1.vtnoc.net SIP/2.0
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK4e66f5ce;rport
From: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as57f89627
To: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>
Call-ID: 3eabad7e0438202639695a3c464e7ab1@127.0.0.1
CSeq: 104 REGISTER
User-Agent: Asterisk PBX
Max-Forwards: 70
Authorization: Digest username="1541705xxxx", realm="asterisk", algorithm=MD5, uri="sip:sanfrancisco-1.vtnoc.net", nonce="69c9a20d", response="2a48e31cc86e6cebb5cdf46f620d0410", opaque=""
Expires: 120
Contact: <sip:s@192.168.11.11>
Event: registration
Content-Length: 0


---
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK4e66f5ce;received=71.94.236.209;rport=1024
From: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as57f89627
To: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>
Call-ID: 3eabad7e0438202639695a3c464e7ab1@127.0.0.1
CSeq: 104 REGISTER
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:1541705xxxx@216.246.105.146>
Content-Length: 0


--- (11 headers 0 lines) ---

<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK4e66f5ce;received=71.94.236.209;rport=1024
From: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as57f89627
To: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as277e31e0
Call-ID: 3eabad7e0438202639695a3c464e7ab1@127.0.0.1
CSeq: 104 REGISTER
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="32e6d315"
Content-Length: 0


--- (11 headers 0 lines) ---
Responding to challenge, registration to domain/host name sanfrancisco-1.vtnoc.net
REGISTER 13 headers, 0 lines
Reliably Transmitting (no NAT) to 216.246.105.146:5060:
REGISTER sip:sanfrancisco-1.vtnoc.net SIP/2.0
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK574b3ec4;rport
From: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as489b358e
To: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>
Call-ID: 3eabad7e0438202639695a3c464e7ab1@127.0.0.1
CSeq: 105 REGISTER
User-Agent: Asterisk PBX
Max-Forwards: 70
Authorization: Digest username="1541705xxxx", realm="asterisk", algorithm=MD5, uri="sip:sanfrancisco-1.vtnoc.net", nonce="32e6d315", response="5f0be649049bcc34fbf28f6a36ef43a8", opaque=""
Expires: 120
Contact: <sip:s@192.168.11.11>
Event: registration
Content-Length: 0


---
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK574b3ec4;received=71.94.236.209;rport=1024
From: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as489b358e
To: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>
Call-ID: 3eabad7e0438202639695a3c464e7ab1@127.0.0.1
CSeq: 105 REGISTER
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:1541705xxxx@216.246.105.146>
Content-Length: 0


--- (11 headers 0 lines) ---

<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK574b3ec4;received=71.94.236.209;rport=1024
From: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as489b358e
To: <sip:1541705xxxx@sanfrancisco-1.vtnoc.net>;tag=as277e31e0
Call-ID: 3eabad7e0438202639695a3c464e7ab1@127.0.0.1
CSeq: 105 REGISTER
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Expires: 120
Contact: <sip:s@192.168.11.11>;expires=120
Date: Tue, 22 Jan 2008 01:22:50 GMT
Content-Length: 0

So, with this revelation (that the registry was still occuring just fine without having any of the peer lines in the file), I tried uncommenting the peer lines and commenting out the registry line…
sip_additional.conf:

; do not edit this file, this is an auto-generated file by freepbx
; all modifications must be done from the web gui
;register=1541705xxxx:xxxxxxxxxx@sanfrancisco-1.vtnoc.net

[ViatalkSIP]
username=1541705xxxx
type=peer
secret=xxxxxxxxxx
qualify=yes
insecure=very
host=sanfrancisco-1.vtnoc.net
fromuser=1541705xxxx
fromdomain=sanfrancisco-1.vtnoc.net
dtmfmode=inband
dtmf=auto
disallow=all
context=from-trunk
canreinvite=yes
authuser=1541705xxxx
allow=ulaw

The outcome of this is exactly what i am seeing on the Gentoo box w/only asterisk (no trixbox)-> only 202 option sends and 404 not-found receives, no other actions:

asterisk1*CLI> sip debug peer ViatalkSIP 
SIP Debugging Enabled for IP: 216.246.105.146:5060
12 headers, 0 lines
Reliably Transmitting (no NAT) to 216.246.105.146:5060:
OPTIONS sip:sanfrancisco-1.vtnoc.net SIP/2.0
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK32671fca;rport
From: "Unknown" <sip:Unknown@192.168.11.11>;tag=as7e9b86db
To: <sip:sanfrancisco-1.vtnoc.net>
Contact: <sip:Unknown@192.168.11.11>
Call-ID: 1a916586184e75411b136c7a7bdf9c4b@192.168.11.11
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Tue, 22 Jan 2008 01:36:23 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0


---
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 71.94.236.209:5060;branch=z9hG4bK32671fca;received=71.94.236.209;rport=5060
From: "Unknown" <sip:Unknown@192.168.11.11>;tag=as7e9b86db
To: <sip:sanfrancisco-1.vtnoc.net>;tag=as0e04cc63
Call-ID: 1a916586184e75411b136c7a7bdf9c4b@192.168.11.11
CSeq: 102 OPTIONS
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Accept: application/sdp
Content-Length: 0


--- (11 headers 0 lines) ---
Destroying call '1a916586184e75411b136c7a7bdf9c4b@192.168.11.11'
12 headers, 0 lines
Reliably Transmitting (no NAT) to 216.246.105.146:5060:
OPTIONS sip:sanfrancisco-1.vtnoc.net SIP/2.0
Via: SIP/2.0/UDP 192.168.11.11:5060;branch=z9hG4bK0c31e4cd;rport
From: "Unknown" <sip:Unknown@192.168.11.11>;tag=as53a0b62c
To: <sip:sanfrancisco-1.vtnoc.net>
Contact: <sip:Unknown@192.168.11.11>
Call-ID: 03839a4d532b2b902fac1cf274951772@192.168.11.11
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Tue, 22 Jan 2008 01:37:23 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0


---
asterisk1*CLI> 
<-- SIP read from 216.246.105.146:5060: 
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 71.94.236.209:5060;branch=z9hG4bK0c31e4cd;received=71.94.236.209;rport=5060
From: "Unknown" <sip:Unknown@192.168.11.11>;tag=as53a0b62c
To: <sip:sanfrancisco-1.vtnoc.net>;tag=as077089af
Call-ID: 03839a4d532b2b902fac1cf274951772@192.168.11.11
CSeq: 102 OPTIONS
User-Agent: Viatalk SIP
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Accept: application/sdp
Content-Length: 0

With this information in hand, i commented out the peer section on the Gentoo box but left the ‘register’ line:

register => 1541705xxxx:f7epto96ff@sanfrancisco-1.vtnoc.net
;[ViatalkSIP]
;username=1541705xxxx
;type=peer
;secret=f7epto96ff
;qualify=yes
;insecure=port,invite
;host=sanfrancisco-1.vtnoc.net
;fromuser=1541705xxxx
;fromdomain=sanfrancisco-1.vtnoc.net
;dtmfmode=inband
;dtmf=auto
;disallow=all
;context=from-sip-trunk
;canreinvite=yes
;authuser=1541705xxxx
;allow=ulaw
;outboundproxy=sanfrancisco-1.vtnoc.net  ;proxy.provider.domain
;[/ViatalkSIP]

So, with only the ‘register’ line in the sip.conf, i start up asterisk console and take a look at debug output:

BigBox*CLI> sip set debug
SIP Debugging re-enabled
BigBox*CLI> mo
module  moh     
BigBox*CLI> module 
load    reload  show    unload  
BigBox*CLI> module 
load    reload  show    unload  
BigBox*CLI> module reload chan
chan_agent.so  chan_h323.so   chan_mgcp.so   chan_sip.so    chan_zap.so    chan_iax2.so   
BigBox*CLI> module reload chan_sip.so 
BigBox*CLI> 

Even with an chan_sip module reload, there is NO sip traffic. I waited several minutes before being sure (in copy output above).

This is indicative that the the ‘register’ line is the problem here. What have I done wrong with my new register line, or … is there some underlying issue i’m missing here?

Additionally, i just noticed all of my posts have my phone number them=- that was smart… DOH! Grrr. Editing now to remove.

take care
thenextdon13

Well, maybe i’m just a bit retarded. Or something was not clear to me…

Apparently the parsing algorithm in chan_sip.c is very picky about what is listed under the ‘general’ versus ‘authentication’ headers. By default, the ‘authentication’ header is uncommented in the conf file:

596 ; jblog = no                  ; Enables jitterbuffer frame logging. Defaults to "no".
597 ;-----------------------------------------------------------------------------------
598 
599 [authentication]
600 ; Global credentials for outbound calls, i.e. when a proxy challenges your
601 ; Asterisk server for authentication. These credentials override
602 ; any credentials in peer/register definition if realm is matched.
603 ;
604 ; This way, Asterisk can authenticate for outbound calls to other
605 ; realms. We match realm on the proxy challenge and pick an set of 
606 ; credentials from this list
607 ; Syntax:
608 ;       auth = <user>:<secret>@<realm>
609 ;       auth = <user>#<md5secret>@<realm>
610 ; Example:
611 ;auth=mark:topsecret@digium.com
612 ; 
613 ; You may also add auth= statements to [peer] definitions 
614 ; Peer auth= override all other authentication settings if we match on realm
615 

The ‘Load peers, users and friends’ section (20328 for 1.6 beta) checks for ‘general’ or ‘authenication’ header (on line 20332)

20328         /* Load peers, users and friends */
20329         cat = NULL;
20330         while ( (cat = ast_category_browse(cfg, cat)) ) {
20331                 const char *utype;
20332                 if (!strcasecmp(cat, "general") || !strcasecmp(cat, "authentication"))
20333                         continue;
20334                 utype = ast_variable_retrieve(cfg, cat, "type");
20335                 if (!utype) {
20336                         ast_log(LOG_WARNING, "Section '%s' lacks type\n", cat);
20337                         continue;
20338                 } else {
20339                         int is_user = 0, is_peer = 0;
20340                         if (!strcasecmp(utype, "user"))
20341                                 is_user = 1;
20342                         else if (!strcasecmp(utype, "friend"))
20343                                 is_user = is_peer = 1;
20344                         else if (!strcasecmp(utype, "peer"))
20345                                 is_peer = 1;
20346                         else {
20347                                 ast_log(LOG_WARNING, "Unknown type '%s' for '%s' in %s\n", utype, cat, "sip.conf");
20348                                 continue;
20349                         }
20350                         if (is_user) {
20351                                 user = build_user(cat, ast_variable_browse(cfg, cat), 0);
20352                                 if (user) {
20353                                         ASTOBJ_CONTAINER_LINK(&userl,user);
20354                                         unref_user(user);
20355                                         user_count++;
20356                                 }
20357                         }
20358                         if (is_peer) {
20359                                 peer = build_peer(cat, ast_variable_browse(cfg, cat), NULL, 0);
20360                                 if (peer) {
20361                                         ASTOBJ_CONTAINER_LINK(&peerl,peer);
20362                                         unref_peer(peer);
20363                                         peer_count++;
20364                                 }
20365                         }
20366                 }
20367         }

The only place the ‘register =’ is recognized is in the set of else/if statements following this:

19929         /* Read the [general] config section of sip.conf (or from realtime config) */
19930         for (v = ast_variable_browse(cfg, "general"); v; v = v->next) {
19931                 if (handle_common_options(&global_flags[0], &dummy[0], v))
19932                         continue;
19933                 /* handle jb conf */
19934                 if (!ast_jb_read_conf(&global_jbconf, v->name, v->value))
19935                         continue;
19936 
19937                 /* Create the dialogs list */
19938                 if (!strcasecmp(v->name, "context")) {
19939                         ast_copy_string(default_context, v->value, sizeof(default_context));
19940                 } else if (!strcasecmp(v->name, "subscribecontext")) {
19941                         ast_copy_string(default_subscribecontext, v->value, sizeo
...
...
...
20172                 } else if (!strcasecmp(v->name, "register")) {
20173                         if (sip_register(v->value, v->lineno) == 0)

This means that Peers, users, and friends can be loaded either after the ‘authentication’ header or after the ‘general’ header, but many, MANY options cannot be (including the register = string).

Basic lesson learned: Use the default config file and insert the config lines within the file where the examples are shown. (In this case, the default sip.conf ‘authentication’ header occurs after the examples of the register= string).

I am unsure of the reason for this. But seeing as it appears that the ‘authentication’ string is only compared in the two following code snippets- 'Build list of authentication to various SIP realms…‘
and
’Load peers, users and friends’

20269         /* Build list of authentication to various SIP realms, i.e. service providers */
20270         for (v = ast_variable_browse(cfg, "authentication"); v ; v = v->next) {
20271                 /* Format for authentication is auth = username:password@realm */
20272                 if (!strcasecmp(v->name, "auth"))
20273                         authl = add_realm_authentication(authl, v->value, v->lineno);
20274         }
20275 

and

20328         /* Load peers, users and friends */
20329         cat = NULL;
20330         while ( (cat = ast_category_browse(cfg, cat)) ) {
20331                 const char *utype;
20332                 if (!strcasecmp(cat, "general") || !strcasecmp(cat, "authentication"))
20333                         continue;
20334                 utype = ast_variable_retrieve(cfg, cat, "type");
20335                 if (!utype) {
20336                         ast_log(LOG_WARNING, "Section '%s' lacks type\n", cat);
20337                         continue;
20338                 } else {
20339                         int is_user = 0, is_peer = 0;
20340                         if (!strcasecmp(utype, "user"))
20341                                 is_user = 1;
20342                         else if (!strcasecmp(utype, "friend"))
20343                                 is_user = is_peer = 1;
20344                         else if (!strcasecmp(utype, "peer"))
20345                                 is_peer = 1;
20346                         else {
20347                                 ast_log(LOG_WARNING, "Unknown type '%s' for '%s' in %s\n", utype, cat, "sip.conf");
20348                                 continue;
20349                         }
20350                         if (is_user) {
20351                                 user = build_user(cat, ast_variable_browse(cfg, cat), 0);
20352                                 if (user) {
20353                                         ASTOBJ_CONTAINER_LINK(&userl,user);
20354                                         unref_user(user);
20355                                         user_count++;
20356                                 }
20357                         }
20358                         if (is_peer) {
20359                                 peer = build_peer(cat, ast_variable_browse(cfg, cat), NULL, 0);
20360                                 if (peer) {
20361                                         ASTOBJ_CONTAINER_LINK(&peerl,peer);
20362                                         unref_peer(peer);
20363                                         peer_count++;
20364                                 }
20365                         }
20366                 }
20367         }

Now, i haven’t studied the code nearly long enough to understand exactly what is going on here… but wouldn’t it make sense to put this section at the absolute end of the config file, and make a note stating that everything that is required to be loaded under the ‘general’ tab must occur before the ‘authentication’ section? … this would probably break something huh.

BOTTOM LINE!
be ABSOLUTELY SURE that ANYTHING you want defined in the ‘General’ section is done BEFORE the ‘Authentication’ section!!

Hope this helps some poor fool keep from troubleshooting for an entire weekend like I did! :smile: I guess I learned something tho :smile:.

thenextdon13