Inbound SIP, phones don't ring

system · August 14, 2012, 6:21am

Hi,
We are replacing a Linksys IP9000 with an IP04 asterisk appliance. We have a small office with 9*SPA942 Phones. All phones are on a different subnet to the servers and PC’s.

Outbound analog calls - [color=#00FF40]work as expected[/color]
Inbound analog calls -[color=#00FF40] work as expected[/color]
Outbound VOIP calls -[color=#00FF40] work as expected[/color]
Inbound VOIP calls -[color=#FF0000] phones don’t ring[/color]

It’s gotten to the point where I bought a hub off ebay so I could run wireshark and sniff some packets. Wireshark showed me I was getting 404 Errors talking to my provider

132233	9477.626498000	192.168.1.30	203.166.103.242	SIP	542	Request: OPTIONS sip:sip02.mytel.net.au
132234	9477.676292000	203.166.103.242	192.168.1.30	SIP	505	Status: 200 OK
132238	9477.824606000	203.166.103.242	192.168.1.30	SIP	535	Request: OPTIONS sip:587345@192.168.1.30
132239	9477.826563000	192.168.1.30	203.166.103.242	SIP	512	Status: 404 Not Found

That did help - I now have insecure=port,invite and fromdomain=mytel.net.au in sip.conf as a result of that. That appears to have fixed a 404 error. Now I have a 401 and a 489

142458	9943.220775000	192.168.1.30	203.166.103.242	SIP	605	Request: REGISTER sip:587345
142459	9943.268048000	203.166.103.242	192.168.1.30	SIP	477	Status: 100 Trying    (1 bindings)
142460	9943.268769000	203.166.103.242	192.168.1.30	SIP	535	Status: 401 Unauthorized    (0 bindings)
142461	9943.271551000	192.168.1.30	203.166.103.242	SIP	605	Request: REGISTER sip:587345
142462	9943.315080000	203.166.103.242	192.168.1.30	SIP	477	Status: 100 Trying    (1 bindings)
142463	9943.326463000	203.166.103.242	192.168.1.30	SIP	548	Status: 200 OK    (1 bindings)
142479	9945.251997000	192.168.1.30	192.168.1.15	SIP	548	Request: OPTIONS sip:105@192.168.1.15:5060
142480	9945.266897000	192.168.1.15	192.168.1.30	SIP	476	Status: 200 OK
142539	9950.378158000	203.166.103.242	192.168.1.30	SIP	601	Request: NOTIFY sip:587345@192.168.1.30
142540	9950.379806000	192.168.1.30	203.166.103.242	SIP	490	Status: 489 Bad event
142700	9958.067599000	192.168.1.30	203.166.103.242	SIP	542	Request: OPTIONS sip:sip02.mytel.net.au
142701	9958.110695000	203.166.103.242	192.168.1.30	SIP	505	Status: 200 OK
142704	9958.195743000	203.166.103.242	192.168.1.30	SIP	535	Request: OPTIONS sip:587345@192.168.1.30
142705	9958.197722000	192.168.1.30	203.166.103.242	SIP	512	Status: 404 Not Found

While packetsniffing, I’ve noticed many packets from the new box via IAX2 to 199.59.241.188. As iax.conf is almost empty (see below) I’m wondering where this is being started
Wireshark IAX2 example

307216	24483.800651000	192.168.1.30	199.59.241.188	IAX2	60	IAX, source call# 2, timestamp 30024ms LAGRQ

extensions.conf

[general]
static = yes
writeprotect = no
autofallthrough = yes
clearglobalvars = no
priorityjumping = no

[default]

; Pre-configured analog extensions, depends on IP0X model and what modules
; are installed.  Some of these may map to FXO ports

exten => 6001,1,Dial(Zap/1)
exten => 6002,1,Dial(Zap/2)


; Pre-configured SIP-phone extensions.  Primary use case is multiple SIP
; extensions and FXO analog Ports

exten => 100,1,Dial(SIP/100)
exten => 101,1,Dial(SIP/101)
exten => 102,1,Dial(SIP/102)
exten => 103,1,Dial(SIP/103)
exten => 104,1,Dial(SIP/104)
exten => 105,1,Dial(SIP/105)
exten => 106,1,Dial(SIP/106)
exten => 107,1,Dial(SIP/107)
exten => 108,1,Dial(SIP/108)
exten => 109,1,Dial(SIP/109)
; Secondary extensions, match extensions above :)
exten => 200,1,Dial(SIP/200)
exten => 201,1,Dial(SIP/201)
exten => 202,1,Dial(SIP/202)
exten => 203,1,Dial(SIP/203)
exten => 204,1,Dial(SIP/204)
exten => 205,1,Dial(SIP/205)
exten => 206,1,Dial(SIP/206)
exten => 207,1,Dial(SIP/207)
exten => 208,1,Dial(SIP/208)
exten => 209,1,Dial(SIP/209)

; Pre-configured mini-asterisk outgoing Analog group

exten => _0.,1,Dial(Zap/g2/${EXTEN:1})

; Pre-configured mini-asterisk outgoing VOIP line

exten => _9.,1,Dial(SIP/587345/${EXTEN:1}) 

; Pre-configured incoming calls
exten => s,1,Log(NOTICE, Incoming call from ${CALLERID(all)})
exten => s,2,Dial(SIP/102&SIP/105&SIP/106, 30) ;; mini-asterisk - don't remove this comment
exten => s,3,Dial(SIP/104&SIP/100)
exten => s,4,Hangup()

sip.conf

[general]
context=default			; Default context for incoming calls
allowguest=no			; Allow or reject guest calls (default is yes, this can also be set to 'osp'
bindport=5060			; UDP Port to bind to (SIP standard port is 5060)
bindaddr=0.0.0.0		; IP address to bind to (0.0.0.0 binds to all)
srvlookup=yes			; Enable DNS SRV lookups on outbound calls

[100]
type=friend
context=default
host=dynamic
secret=100
canreinvite=no
callerid=100
disallow=all
allow=ulaw,alaw
qualify=200


[101]
type=friend
context=default
host=dynamic
secret=101
canreinvite=no
callerid=101
disallow=all
allow=ulaw,alaw
qualify=200

; the rest of the extensions are here 102-109, 200-209.  Trimmed for brevity

[587345] ; "SIP-NAT" mini-asterisk do not remove this comment
; You reach your ITSP via a NAT router (most common)
type=friend
context=default
username=587345
secret=*******
host=sip02.mytel.net.au
canreinvite=no
disallow=all
allow=ulaw,alaw
qualify=yes
nat=yes
insecure=port,invite
fromdomain=mytel.net.au  ;This is set to my provider's domain after some reading

iax.conf - Most of it is commented out - only active lines pasted here

[general]
bandwidth=low
disallow=lpc10			; Icky sound quality...  Mr. Roboto.
jitterbuffer=no
tos=lowdelay
autokill=yes
iaxthreadcount = 8

[misery]
type=user
context=default

;
; Trust Caller*ID Coming from iaxtel.com
;
[iaxtel]
type=user
context=default
auth=rsa
inkeys=iaxtel

;
; Trust Caller*ID Coming from iax.fwdnet.net
;
[iaxfwd]
type=user
context=default
auth=rsa
inkeys=freeworlddialup
forcejitterbuffer=no

This is all I have right now - I can only run a live trace out of business hours

david55 · August 14, 2012, 7:27am

The sip set debug … and sip set history… commands in Asterisk can capture this level of trace without wireshark. tcpdump will run on the Asterisk box and can create pcap files for wireshark. wireshark itself will possibly also run on that box.

404 errors on OPTIONs are harmless when Asterisk is the requestor. Asterisk is only interested in whether or not it gets a response at all.

Anything that has diaplans using zap/ device addresses is using obsolete and unsupported software, unless they provide support themselves.

401 is normal, the protocol is try the request without authentication.

489 is probably just an unsupported feature.

insecure=port,invite is nearly always wrong (although it fails to insecurity, rather than loss of function). Most people who need insecure need insecure=invite. ITSPs seem to use port,invite (historically “very”) as a magic incantation, without thinking what is really needed.

insecure=port,invite is unlikely to be parsed correctly on a version of Asterisk that still supports zap/, although there may have been some overlap.

None of your traces show any inbound VoIP calls being attempted.

You seem to be in a NAT environment, but you have no options relevant to being inside NAT set (NB nat=yes is not relevant to being inside NAT, it is for dealing with broken devices which are inside NAT, when the Asterisk is outside - you are getting responses to your outgoing packets because the ITSP has something like that set, or because your router is modifying the packet contents.)

type=friend is usually more secure, without loss of function, if replaced by type=peer.

If you are going to use weak passwords on your local phones, you need to use strong device names. Using the MAC address is advised.

I’ve not use IAX.

dejanst · August 14, 2012, 7:34am

Do you need to register with your SIP provider/ Gateway? If yes, you are missing a register statement in sip.conf.

If your Asterisk is behind NAT and you are registering to a VoIP provider on a public IP address, you need to add the “externip=” and “localnet=” parameters in sip.conf.

Please issue a “sip set debug on” command in Asterisk CLI, make an incomming call and copy/paste the output to the forum. You disable the sip debug with “sip set debug off”

david55 · August 14, 2012, 9:55am

The trace shows that he must have either register or a callback extension, even though they are missing from the configuration files posted.

eternhost, and stunaddr are posible alternatives to externip.

system · August 19, 2012, 11:22pm

Sorry to take so long to reply.

There is a register line in sip.conf. I didn’t list it previously because I had re-enabled the old pabx, and disabled sip on the new one, so it was commented out

externip is commented out. Do I need to put our routers external IP there? How do I keep that up to date?

I have attempted to log an asterisk console session with an incoming phonecall, but I am obviously doing it wrong. I can see the inbound call, but by the time I copy paste its gone. Logging my session did nothing - putty hates me. How can I log my asterisk console session?

david55 · August 20, 2012, 6:45am

set /etc/asterisk/logger.conf appropriately and then capture from the log file (typically /var/log/asterisk/full.

system · August 20, 2012, 7:15am

This was a call from my mobile to our voip line. Mobile rang repeatedly, desk phone did not.

David, what is appropriately? Can I turn on full, or is that too much? Can I set up just sip logging? More to read

ip04*CLI> sip set debug
SIP Debugging re-enabled

Reliably Transmitting (NAT) to 203.166.103.242:5060:
OPTIONS sip:sip02.mytel.net.au SIP/2.0
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK7ce506f2;rport
From: "asterisk" <sip:asterisk@220.233.85.199>;tag=as11202869
To: <sip:sip02.mytel.net.au>
Contact: <sip:asterisk@220.233.85.199>
Call-ID: 7409f9e075cc67dc386369670cbe1ff8@220.233.85.199
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Sun, 14 Jan 2007 04:35:57 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


---

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK7ce506f2;received=203.219.222.55;rport=5060
From: "asterisk" <sip:asterisk@220.233.85.199>;tag=as11202869
To: <sip:sip02.mytel.net.au>;tag=as7439045f
Call-ID: 7409f9e075cc67dc386369670cbe1ff8@220.233.85.199
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:203.166.103.242>
Accept: application/sdp
Content-Length: 0


<------------->
--- (11 headers 0 lines) ---
Really destroying SIP dialog '7409f9e075cc67dc386369670cbe1ff8@220.233.85.199' Method: OPTIONS

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
OPTIONS sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK0e00976b;rport
From: "asterisk" <sip:asterisk@203.166.103.242>;tag=as114949df
To: <sip:587345@220.233.85.199>
Contact: <sip:asterisk@203.166.103.242>
Call-ID: 118863e84200bf9d17d8ddc133060af4@203.166.103.242
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Mon, 20 Aug 2012 06:55:25 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0


<------------->
--- (12 headers 0 lines) ---
Looking for 587345 in default (domain 220.233.85.199)

<--- Transmitting (no NAT) to 203.166.103.242:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK0e00976b;received=203.166.103.242;rport=5060
From: "asterisk" <sip:asterisk@203.166.103.242>;tag=as114949df
To: <sip:587345@220.233.85.199>;tag=as16b0beff
Call-ID: 118863e84200bf9d17d8ddc133060af4@203.166.103.242
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Accept: application/sdp
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '118863e84200bf9d17d8ddc133060af4@203.166.103.242' in 32000 ms (Method: OPTIONS)

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
INVITE sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK2c7a1238;rport
From: "0421903810" <sip:0421903810@gw03.mytel.net.au>;tag=as3522392e
To: <sip:587345@220.233.85.199>
Contact: <sip:0421903810@203.166.103.242>
Call-ID: 0c180ba1688949594fc8311c364d660c@gw03.mytel.net.au
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Mon, 20 Aug 2012 06:55:31 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Type: application/sdp
Content-Length: 316

v=0
o=root 11551 11551 IN IP4 203.166.103.242
s=session
c=IN IP4 203.166.103.242
t=0 0
m=audio 12314 RTP/AVP 8 0 18 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -

<------------->
--- (13 headers 14 lines) ---
Sending to 203.166.103.242 : 5060 (NAT)
Using INVITE request as basis request - 0c180ba1688949594fc8311c364d660c@gw03.mytel.net.au
Found peer '587345'
Found RTP audio format 8
Found RTP audio format 0
Found RTP audio format 18
Found RTP audio format 3
Found RTP audio format 101
Peer audio RTP is at port 203.166.103.242:12314
Found description format PCMA for ID 8
Found description format PCMU for ID 0
Found description format G729 for ID 18
Found description format GSM for ID 3
Found description format telephone-event for ID 101
Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x10e (gsm|ulaw|alaw|g729)/video=0x0 (nothing), combined - 0xc (ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Peer audio RTP is at port 203.166.103.242:12314
Looking for 587345 in default (domain 220.233.85.199)

<--- Reliably Transmitting (NAT) to 203.166.103.242:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK2c7a1238;received=203.166.103.242;rport=5060
From: "0421903810" <sip:0421903810@gw03.mytel.net.au>;tag=as3522392e
To: <sip:587345@220.233.85.199>;tag=as4fe66d84
Call-ID: 0c180ba1688949594fc8311c364d660c@gw03.mytel.net.au
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '0c180ba1688949594fc8311c364d660c@gw03.mytel.net.au' in 2752 ms (Method: INVITE)

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
ACK sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK2c7a1238;rport
From: "0421903810" <sip:0421903810@gw03.mytel.net.au>;tag=as3522392e
To: <sip:587345@220.233.85.199>;tag=as4fe66d84
Contact: <sip:0421903810@203.166.103.242>
Call-ID: 0c180ba1688949594fc8311c364d660c@gw03.mytel.net.au
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0


<------------->
--- (10 headers 0 lines) ---
Really destroying SIP dialog '0c180ba1688949594fc8311c364d660c@gw03.mytel.net.au' Method: ACK

Reliably Transmitting (no NAT) to 192.168.1.10:5060:
OPTIONS sip:106@192.168.1.10:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.30:5060;branch=z9hG4bK66495603;rport
From: "asterisk" <sip:asterisk@192.168.1.30>;tag=as7d230ea5
To: <sip:106@192.168.1.10:5060>
Contact: <sip:asterisk@192.168.1.30>
Call-ID: 06c962326c176f871f1e58e74454ecb9@192.168.1.30
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Sun, 14 Jan 2007 04:36:07 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


---

ip04*CLI>
<--- SIP read from 192.168.1.10:5060 --->
SIP/2.0 200 OK
To: <sip:106@192.168.1.10:5060>;tag=74404c2d428b10cci0
From: "asterisk" <sip:asterisk@192.168.1.30>;tag=as7d230ea5
Call-ID: 06c962326c176f871f1e58e74454ecb9@192.168.1.30
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.30:5060;branch=z9hG4bK66495603
Server: Linksys/SPA942-4.1.18
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER, SUBSCRIBE
Allow-Events: dialog


<------------->
--- (10 headers 0 lines) ---
Really destroying SIP dialog '06c962326c176f871f1e58e74454ecb9@192.168.1.30' Method: OPTIONS

[Jan 13 20:36:27] NOTICE[3087]: chan_sip.c:7147 sip_reregister:    -- Re-registration for  587345@587345
REGISTER 13 headers, 0 lines
Reliably Transmitting (NAT) to 203.166.103.242:5060:
REGISTER sip:mytel.net.au SIP/2.0
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK41875ffe;rport
From: <sip:587345@sip02.mytel.net.au>;tag=as250f2901
To: <sip:587345@sip02.mytel.net.au>
Call-ID: 026456d8033717d27f1dd90f59f17a58@mytel.net.au
CSeq: 106 REGISTER
User-Agent: Asterisk PBX
Max-Forwards: 70
Authorization: Digest username="587345", realm="asterisk", algorithm=MD5, uri="sip:mytel.net.au", nonce="19b3a28f", response="ffe6d8136630edef5fdf3137a8ee4798", opaque=""
Expires: 120
Contact: <sip:587345@220.233.85.199>
Event: registration
Content-Length: 0


---

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK41875ffe;received=203.219.222.55;rport=5060
From: <sip:587345@sip02.mytel.net.au>;tag=as250f2901
To: <sip:587345@sip02.mytel.net.au>
Call-ID: 026456d8033717d27f1dd90f59f17a58@mytel.net.au
CSeq: 106 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:587345@203.166.103.242>
Content-Length: 0


<------------->
--- (10 headers 0 lines) ---

<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK41875ffe;received=203.219.222.55;rport=5060
From: <sip:587345@sip02.mytel.net.au>;tag=as250f2901
To: <sip:587345@sip02.mytel.net.au>;tag=as24201993
Call-ID: 026456d8033717d27f1dd90f59f17a58@mytel.net.au
CSeq: 106 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="261ab743"
Content-Length: 0


<------------->
--- (10 headers 0 lines) ---
Responding to challenge, registration to domain/host name 587345
REGISTER 13 headers, 0 lines
Reliably Transmitting (NAT) to 203.166.103.242:5060:
REGISTER sip:mytel.net.au SIP/2.0
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK79088287;rport
From: <sip:587345@sip02.mytel.net.au>;tag=as068830ad
To: <sip:587345@sip02.mytel.net.au>
Call-ID: 026456d8033717d27f1dd90f59f17a58@mytel.net.au
CSeq: 107 REGISTER
User-Agent: Asterisk PBX
Max-Forwards: 70
Authorization: Digest username="587345", realm="asterisk", algorithm=MD5, uri="sip:mytel.net.au", nonce="261ab743", response="a93cc16b5dc761e2e519742002a64a1b", opaque=""
Expires: 120
Contact: <sip:587345@220.233.85.199>
Event: registration
Content-Length: 0


---

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK79088287;received=203.219.222.55;rport=5060
From: <sip:587345@sip02.mytel.net.au>;tag=as068830ad
To: <sip:587345@sip02.mytel.net.au>
Call-ID: 026456d8033717d27f1dd90f59f17a58@mytel.net.au
CSeq: 107 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:587345@203.166.103.242>
Content-Length: 0


<------------->
--- (10 headers 0 lines) ---

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK79088287;received=203.219.222.55;rport=5060
From: <sip:587345@sip02.mytel.net.au>;tag=as068830ad
To: <sip:587345@sip02.mytel.net.au>;tag=as24201993
Call-ID: 026456d8033717d27f1dd90f59f17a58@mytel.net.au
CSeq: 107 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Expires: 120
Contact: <sip:587345@220.233.85.199>;expires=120
Date: Mon, 20 Aug 2012 06:55:55 GMT
Content-Length: 0


<------------->
--- (12 headers 0 lines) ---
Scheduling destruction of SIP dialog '026456d8033717d27f1dd90f59f17a58@mytel.net.au' in 6400 ms (Method: REGISTER)
[Jan 13 20:36:27] NOTICE[3087]: chan_sip.c:12117 handle_response_register: Outbound Registration: Expiry for 587345 is 120 sec (Scheduling reregistration in 105 s)

Really destroying SIP dialog '118863e84200bf9d17d8ddc133060af4@203.166.103.242' Method: OPTIONS

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
NOTIFY sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK43a0809d;rport
From: "asterisk" <sip:asterisk@gw03.mytel.net.au>;tag=as48fee243
To: <sip:587345@220.233.85.199>
Contact: <sip:asterisk@203.166.103.242>
Call-ID: 04654a2971e701a154c239152c2fbc9d@gw03.mytel.net.au
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 94

Messages-Waiting: yes
Message-Account: sip:121@gw03.mytel.net.au
Voice-Message: 33/0 (0/0)

<------------->
--- (12 headers 3 lines) ---

<--- Transmitting (no NAT) to 203.166.103.242:5060 --->
SIP/2.0 489 Bad event
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK43a0809d;received=203.166.103.242;rport=5060
From: "asterisk" <sip:asterisk@gw03.mytel.net.au>;tag=as48fee243
To: <sip:587345@220.233.85.199>;tag=as5e65eb3d
Call-ID: 04654a2971e701a154c239152c2fbc9d@gw03.mytel.net.au
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


<------------>

Really destroying SIP dialog '026456d8033717d27f1dd90f59f17a58@mytel.net.au' Method: REGISTER

ip04*CLI> sip set debug off
SIP Debugging Disabled

We have a static ip. That makes my life a little easier. Phones are on a different subnet to computers. externip and localnet are now set (xxx’d out just because)

externip = xxx.xxx.xxx.xxx	; Address that we're going to put in outbound SIP messages
				; if we're behind a NAT

				; The externip and localnet is used
				; when registering and communicating with other proxies
				; that we're registered with
;externhost=foo.dyndns.net	; Alternatively you can specify an 
				; external host, and Asterisk will 
				; perform DNS queries periodically.  Not
				; recommended for production 
				; environments!  Use externip instead
;externrefresh=10		; How often to refresh externhost if 
				; used
				; You may add multiple local networks.  A reasonable set of defaults
				; are:
localnet=192.168.1.0/255.255.255.0;

dejanst · August 20, 2012, 7:23am

For the incomming call, I would gusess you are doing something wrong in the dialplan. Do the same call again and copy/paste the Asterisk CLI debug.

david55 · August 20, 2012, 7:25am

There are various categories, e.g. warning, notice and debug, that can be sent to a log. The sample files don’t send debug anywhere, so you normally need to add that to the log you are going to use for debugging.

system · August 21, 2012, 7:41am

This is a console debug session of an inbound call.


ip04*CLI> sip set debug
SIP Debugging enabled

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
INVITE sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK6d10186e;rport
From: "0421903810" <sip:0421903810@gw03.mytel.net.au>;tag=as6e237edd
To: <sip:587345@220.233.85.199>
Contact: <sip:0421903810@203.166.103.242>
Call-ID: 08f3dd1d2abd5d7a093fc0ce745b4ace@gw03.mytel.net.au
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Tue, 21 Aug 2012 07:20:24 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Type: application/sdp
Content-Length: 314

v=0
o=root 3735 3735 IN IP4 203.166.103.242
s=session
c=IN IP4 203.166.103.242
t=0 0
m=audio 13678 RTP/AVP 8 0 18 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -

<------------->
--- (13 headers 14 lines) ---
Sending to 203.166.103.242 : 5060 (NAT)
Using INVITE request as basis request - 08f3dd1d2abd5d7a093fc0ce745b4ace@gw03.mytel.net.au
Found peer '587345'
Found RTP audio format 8
Found RTP audio format 0
Found RTP audio format 18
Found RTP audio format 3
Found RTP audio format 101
Peer audio RTP is at port 203.166.103.242:13678
Found description format PCMA for ID 8
Found description format PCMU for ID 0
Found description format G729 for ID 18
Found description format GSM for ID 3
Found description format telephone-event for ID 101
Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x10e (gsm|ulaw|alaw|g729)/video=0x0 (nothing), combined - 0xc (ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Peer audio RTP is at port 203.166.103.242:13678
Looking for 587345 in default (domain 220.233.85.199)

<--- Reliably Transmitting (NAT) to 203.166.103.242:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK6d10186e;received=203.166.103.242;rport=5060
From: "0421903810" <sip:0421903810@gw03.mytel.net.au>;tag=as6e237edd
To: <sip:587345@220.233.85.199>;tag=as387a6458
Call-ID: 08f3dd1d2abd5d7a093fc0ce745b4ace@gw03.mytel.net.au
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '08f3dd1d2abd5d7a093fc0ce745b4ace@gw03.mytel.net.au' in 3072 ms (Method: INVITE)

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
ACK sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK6d10186e;rport
From: "0421903810" <sip:0421903810@gw03.mytel.net.au>;tag=as6e237edd
To: <sip:587345@220.233.85.199>;tag=as387a6458
Contact: <sip:0421903810@203.166.103.242>
Call-ID: 08f3dd1d2abd5d7a093fc0ce745b4ace@gw03.mytel.net.au
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0


<------------->
--- (10 headers 0 lines) ---
Really destroying SIP dialog '08f3dd1d2abd5d7a093fc0ce745b4ace@gw03.mytel.net.au' Method: ACK

Really destroying SIP dialog '9a0e5876-3e22c4e5@192.168.1.10' Method: REGISTER

Really destroying SIP dialog '5c283089-c8cf13ee@192.168.1.10' Method: REGISTER

Really destroying SIP dialog '483117ae4a55b41564f700663c697bb4@203.166.103.242' Method: OPTIONS

ip04*CLI> sip set debug off
SIP Debugging Disabled

This is the corresponding log entry. Logger was full => notice,warning,error,debug,verbose

[2012-08-21 00:17:55] WARNING[4122] pbx.c: Unable to register extension '6001', priority 1 in 'default', already in use
[2012-08-21 00:17:55] WARNING[4122] pbx.c: Unable to register extension '6002', priority 1 in 'default', already in use
[2012-08-21 00:18:07] WARNING[4208] pbx.c: Unable to register extension '6001', priority 1 in 'default', already in use
[2012-08-21 00:18:07] WARNING[4208] pbx.c: Unable to register extension '6002', priority 1 in 'default', already in use
[2012-08-21 00:18:09] NOTICE[4007] chan_sip.c: Peer '587345' is now Reachable. (49ms / 2000ms)
[2012-08-21 00:20:01] NOTICE[4007] chan_sip.c: Peer '106' is now Reachable. (13ms / 200ms)
[2012-08-21 00:20:01] NOTICE[4007] chan_sip.c: Peer '206' is now Reachable. (13ms / 200ms)
[2012-08-21 00:20:24] VERBOSE[4007] logger.c:
<--- SIP read from 203.166.103.242:5060 --->
INVITE sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK6d10186e;rport
From: "0421903810" <sip:0421903810@gw03.mytel.net.au>;tag=as6e237edd
To: <sip:587345@220.233.85.19[2012-08-21 00:20:24] VERBOSE[4007] logger.c: --- (13 headers 14 lines) ---
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Sending to 203.166.103.242 : 5060 (NAT)
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Using INVITE request as basis request - 08f3dd1d2abd5d7a093fc0ce745b4ace@gw03.mytel.net.au
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Found peer '587345'
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Found RTP audio format 8
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Found RTP audio format 0
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Found RTP audio format 18
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Found RTP audio format 3
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Found RTP audio format 101
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Peer audio RTP is at port 203.166.103.242:13678
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Found description format PCMA for ID 8
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Found description format PCMU for ID 0
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Found description format G729 for ID 18
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Found description format GSM for ID 3
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Found description format telephone-event for ID 101
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x10e (gsm|ulaw|alaw|g729)/video=0x0 (nothing), combined - 0xc (ulaw|alaw)
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Peer audio RTP is at port 203.166.103.242:13678
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Looking for 587345 in default (domain 220.233.85.199)
[2012-08-21 00:20:24] VERBOSE[4007] logger.c:
<--- Reliably Transmitting (NAT) to 203.166.103.242:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK6d10186e;received=203.166.103.242;rport=5060
From: "0421903810" <sip:0421903810@gw03.mytel.net.au>;tag=as6e237edd
T[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Scheduling destruction of SIP dialog '08f3dd1d2abd5d7a093fc0ce745b4ace@gw03.mytel.net.au' in 3072 ms (Method: INVITE)
[2012-08-21 00:20:24] VERBOSE[4007] logger.c:
<--- SIP read from 203.166.103.242:5060 --->
ACK sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK6d10186e;rport
From: "0421903810" <sip:0421903810@gw03.mytel.net.au>;tag=as6e237edd
To: <sip:587345@220.233.85.199>;[2012-08-21 00:20:24] VERBOSE[4007] logger.c: --- (10 headers 0 lines) ---
[2012-08-21 00:20:24] VERBOSE[4007] logger.c: Really destroying SIP dialog '08f3dd1d2abd5d7a093fc0ce745b4ace@gw03.mytel.net.au' Method: ACK
[2012-08-21 00:20:33] VERBOSE[4007] logger.c: Really destroying SIP dialog '9a0e5876-3e22c4e5@192.168.1.10' Method: REGISTER
[2012-08-21 00:20:33] VERBOSE[4007] logger.c: Really destroying SIP dialog '5c283089-c8cf13ee@192.168.1.10' Method: REGISTER
[2012-08-21 00:20:41] VERBOSE[4007] logger.c: Really destroying SIP dialog '483117ae4a55b41564f700663c697bb4@203.166.103.242' Method: OPTIONS
[2012-08-21 00:21:01] VERBOSE[4007] logger.c: Reliably Transmitting (no NAT) to 192.168.1.10:5060:
OPTIONS sip:106@192.168.1.10:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.30:5060;branch=z9hG4bK7508ae63;rport
From: "asterisk" <sip:asterisk@192.168.1.30>;tag=as3156d369
To: <sip:106@192.168.1.10:5060>
[2012-08-21 00:21:02] VERBOSE[4007] logger.c: Reliably Transmitting (no NAT) to 192.168.1.10:5061:
OPTIONS sip:206@192.168.1.10:5061 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.30:5060;branch=z9hG4bK3e4a3c3e;rport
From: "asterisk" <sip:asterisk@192.168.1.30>;tag=as1bdfc852
To: <sip:206@192.168.1.10:5061>
[2012-08-21 00:21:02] VERBOSE[4007] logger.c:
<--- SIP read from 192.168.1.10:5060 --->
SIP/2.0 200 OK
To: <sip:106@192.168.1.10:5060>;tag=7245ba19c62c9bb9i0
From: "asterisk" <sip:asterisk@192.168.1.30>;tag=as3156d369
Call-ID: 3fd47cdb68d4ec063daa7f6c5ac06f81@192.168.1.30
CSeq: 102 OPTIONS
Via:[2012-08-21 00:21:02] VERBOSE[4007] logger.c: --- (10 headers 0 lines) ---
[2012-08-21 00:21:02] VERBOSE[4007] logger.c: Really destroying SIP dialog '3fd47cdb68d4ec063daa7f6c5ac06f81@192.168.1.30' Method: OPTIONS
[2012-08-21 00:21:02] VERBOSE[4007] logger.c:
<--- SIP read from 192.168.1.10:5061 --->
SIP/2.0 200 OK
To: <sip:206@192.168.1.10:5061>;tag=753dc719964bf2b9i1
From: "asterisk" <sip:asterisk@192.168.1.30>;tag=as1bdfc852
Call-ID: 7303274f1b6027283b0f10976528cd66@192.168.1.30
CSeq: 102 OPTIONS
Via:[2012-08-21 00:21:02] VERBOSE[4007] logger.c: --- (10 headers 0 lines) ---
[2012-08-21 00:21:02] VERBOSE[4007] logger.c: Really destroying SIP dialog '7303274f1b6027283b0f10976528cd66@192.168.1.30' Method: OPTIONS
[2012-08-21 00:21:09] VERBOSE[4007] logger.c: Reliably Transmitting (NAT) to 203.166.103.242:5060:
OPTIONS sip:sip02.mytel.net.au SIP/2.0
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK3ae4cc99;rport
From: "asterisk" <sip:asterisk@220.233.85.199>;tag=as5ff78e16
To: <sip:sip02.mytel.net.au>
Co[2012-08-21 00:21:09] VERBOSE[4007] logger.c:
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK3ae4cc99;received=220.233.85.199;rport=5060
From: "asterisk" <sip:asterisk@220.233.85.199>;tag=as5ff78e16
To: <sip:sip02.mytel.net.au>;tag=a[2012-08-21 00:21:09] VERBOSE[4007] logger.c: --- (11 headers 0 lines) ---
[2012-08-21 00:21:09] VERBOSE[4007] logger.c: Really destroying SIP dialog '31b0b91175836fb81bb42fbd4bef17a7@220.233.85.199' Method: OPTIONS
[2012-08-21 00:21:09] VERBOSE[4007] logger.c:
<--- SIP read from 203.166.103.242:5060 --->
OPTIONS sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK62ff39eb;rport
From: "asterisk" <sip:asterisk@203.166.103.242>;tag=as1f30dcac
To: <sip:587345@220.233.85.199>
C[2012-08-21 00:21:09] VERBOSE[4007] logger.c: --- (12 headers 0 lines) ---
[2012-08-21 00:21:09] VERBOSE[4007] logger.c: Looking for 587345 in default (domain 220.233.85.199)
[2012-08-21 00:21:09] VERBOSE[4007] logger.c:
<--- Transmitting (no NAT) to 203.166.103.242:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK62ff39eb;received=203.166.103.242;rport=5060
From: "asterisk" <sip:asterisk@203.166.103.242>;tag=as1f30dcac
To: <sip:5873[2012-08-21 00:21:09] VERBOSE[4007] logger.c: Scheduling destruction of SIP dialog '1a5f10195f0950d9616b4f3866a92733@203.166.103.242' in 32000 ms (Method: OPTIONS)
[2012-08-21 00:21:39] NOTICE[4007] chan_sip.c:    -- Re-registration for  587345@587345
[2012-08-21 00:21:39] VERBOSE[4007] logger.c: REGISTER 13 headers, 0 lines
[2012-08-21 00:21:39] VERBOSE[4007] logger.c: Reliably Transmitting (NAT) to 203.166.103.242:5060:
REGISTER sip:mytel.net.au SIP/2.0
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK4e44e7c3;rport
From: <sip:587345@sip02.mytel.net.au>;tag=as6bca719a
To: <sip:587345@sip02.mytel.net.au>
Call-ID: [2012-08-21 00:21:39] VERBOSE[4007] logger.c:
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK4e44e7c3;received=220.233.85.199;rport=5060
From: <sip:587345@sip02.mytel.net.au>;tag=as6bca719a
To: <sip:587345@sip02.mytel.net.au>
Ca[2012-08-21 00:21:39] VERBOSE[4007] logger.c: --- (10 headers 0 lines) ---
[2012-08-21 00:21:39] VERBOSE[4007] logger.c:
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK4e44e7c3;received=220.233.85.199;rport=5060
From: <sip:587345@sip02.mytel.net.au>;tag=as6bca719a
To: <sip:587345@sip02.mytel.net.a[2012-08-21 00:21:39] VERBOSE[4007] logger.c: --- (10 headers 0 lines) ---
[2012-08-21 00:21:39] VERBOSE[4007] logger.c: Responding to challenge, registration to domain/host name 587345
[2012-08-21 00:21:39] VERBOSE[4007] logger.c: REGISTER 13 headers, 0 lines
[2012-08-21 00:21:39] VERBOSE[4007] logger.c: Reliably Transmitting (NAT) to 203.166.103.242:5060:
REGISTER sip:mytel.net.au SIP/2.0
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK319ee51d;rport
From: <sip:587345@sip02.mytel.net.au>;tag=as5b55d0bf
To: <sip:587345@sip02.mytel.net.au>
Call-ID: [2012-08-21 00:21:39] VERBOSE[4007] logger.c:
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK319ee51d;received=220.233.85.199;rport=5060
From: <sip:587345@sip02.mytel.net.au>;tag=as5b55d0bf
To: <sip:587345@sip02.mytel.net.au>
Ca[2012-08-21 00:21:39] VERBOSE[4007] logger.c: --- (10 headers 0 lines) ---
[2012-08-21 00:21:40] VERBOSE[4007] logger.c:
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK319ee51d;received=220.233.85.199;rport=5060
From: <sip:587345@sip02.mytel.net.au>;tag=as5b55d0bf
To: <sip:587345@sip02.mytel.net.au>;tag=as1[2012-08-21 00:21:40] VERBOSE[4007] logger.c: --- (12 headers 0 lines) ---
[2012-08-21 00:21:40] VERBOSE[4007] logger.c: Scheduling destruction of SIP dialog '190604ce0fcf9fc630c0f0e3480563ea@mytel.net.au' in 6400 ms (Method: REGISTER)
[2012-08-21 00:21:40] NOTICE[4007] chan_sip.c: Outbound Registration: Expiry for 587345 is 120 sec (Scheduling reregistration in 105 s)
[2012-08-21 00:21:41] VERBOSE[4007] logger.c: Really destroying SIP dialog '1a5f10195f0950d9616b4f3866a92733@203.166.103.242' Method: OPTIONS
[2012-08-21 00:21:46] VERBOSE[4007] logger.c: Really destroying SIP dialog '190604ce0fcf9fc630c0f0e3480563ea@mytel.net.au' Method: REGISTER
[2012-08-21 00:21:51] VERBOSE[4007] logger.c:
<--- SIP read from 203.166.103.242:5060 --->
NOTIFY sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK2553763f;rport
From: "asterisk" <sip:asterisk@gw03.mytel.net.au>;tag=as5f864f88
To: <sip:587345@220.233.85.199>
[2012-08-21 00:21:51] VERBOSE[4007] logger.c: --- (12 headers 3 lines) ---
[2012-08-21 00:21:51] VERBOSE[4007] logger.c:
<--- Transmitting (no NAT) to 203.166.103.242:5060 --->
SIP/2.0 489 Bad event
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK2553763f;received=203.166.103.242;rport=5060
From: "asterisk" <sip:asterisk@gw03.mytel.net.au>;tag=as5f864f88

Today I made the following changes - logger. I also set up rules in our gateway so that all sip(5060, tcp and udp), rtp (10k-20k udp) and iax2(udp as well) traffic would travel over wan2. The externip is set to the external interface of wan2 already.

For people who missed it, my dialplan is here again. This works for inbound analog, and outbound analog and sip. My whole problem is inbound sip. Especially when i can see it in the log, just out of reach

;Outbound Analog
exten => _0.,1,Dial(Zap/g2/${EXTEN:1})
;Outbound SIP
exten => _9.,1,Dial(SIP/587345/${EXTEN:1})

; Incoming calls
exten => s,1,Log(NOTICE, Incoming call from ${CALLERID(all)})
exten => s,2,Dial(SIP/102&SIP/105&SIP/106, 30) ;; mini-asterisk - don't remove this comment
exten => s,3,Dial(SIP/104&SIP/100)
exten => s,4,Hangup()

system · August 22, 2012, 6:24am

Today I modified my dialplan to the following, and changed the subject of this thread to be more accurate

exten => s,1,Log(NOTICE, Incoming call from ${CALLERID(all)})
exten => s,2,Answer()
exten => s,3,Dial(SIP/102&SIP/105&SIP/106, 30) ;; mini-asterisk - don't remove this comment
exten => s,4,Dial(SIP/104&SIP/100)
exten => s,5,Hangup()

Here is the SIP debug log from the CLI. Once again, phone did not ring

Asterisk 1.4.4, Copyright (C) 1999 - 2006 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 1.4.4 currently running on ip04 (pid = 63)
No entry for terminal type "dumb";
using dumb terminal settings.
Really destroying SIP dialog '9a0e5876-3e22c4e5@192.168.1.10' Method: REGISTER

Really destroying SIP dialog '5c283089-c8cf13ee@192.168.1.10' Method: REGISTER

ip04*CLI> sip set debug
<--- SIP read from 203.166.103.242:5060 --->
OPTIONS sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK12bf8545;rport
From: "asterisk" <sip:asterisk@203.166.103.242>;tag=as480b7ed7
To: <sip:587345@220.233.85.199>
Contact: <sip:asterisk@203.166.103.242>
Call-ID: 5b800a867b6ccf023b900af235673ca1@203.166.103.242
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Wed, 22 Aug 2012 06:11:32 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0


<------------->
--- (12 headers 0 lines) ---
Looking for 587345 in default (domain 220.233.85.199)

<--- Transmitting (no NAT) to 203.166.103.242:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK12bf8545;received=203.166.103.242;rport=5060
From: "asterisk" <sip:asterisk@203.166.103.242>;tag=as480b7ed7
To: <sip:587345@220.233.85.199>;tag=as2bd85e67
Call-ID: 5b800a867b6ccf023b900af235673ca1@203.166.103.242
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Accept: application/sdp
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '5b800a867b6ccf023b900af235673ca1@203.166.103.242' in 32000 ms (Method: OPTIONS)

ip04*CLI> sip set debug
SIP Debugging re-enabled

Reliably Transmitting (no NAT) to 192.168.1.10:5061:
OPTIONS sip:206@192.168.1.10:5061 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.30:5060;branch=z9hG4bK08281df3;rport
From: "asterisk" <sip:asterisk@192.168.1.30>;tag=as5e5dc060
To: <sip:206@192.168.1.10:5061>
Contact: <sip:asterisk@192.168.1.30>
Call-ID: 2cb208e8010d90de6346cf104eff318a@192.168.1.30
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Wed, 22 Aug 2012 06:11:39 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


---

ip04*CLI>
<--- SIP read from 192.168.1.10:5061 --->
SIP/2.0 200 OK
To: <sip:206@192.168.1.10:5061>;tag=913b4846ff2e19eci1
From: "asterisk" <sip:asterisk@192.168.1.30>;tag=as5e5dc060
Call-ID: 2cb208e8010d90de6346cf104eff318a@192.168.1.30
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.30:5060;branch=z9hG4bK08281df3
Server: Linksys/SPA942-4.1.18
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER, SUBSCRIBE
Allow-Events: dialog


<------------->
--- (10 headers 0 lines) ---
Really destroying SIP dialog '2cb208e8010d90de6346cf104eff318a@192.168.1.30' Method: OPTIONS

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
INVITE sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK0a1655a7;rport
From: "0421903810" <sip:0421903810@gw03.mytel.net.au>;tag=as23192825
To: <sip:587345@220.233.85.199>
Contact: <sip:0421903810@203.166.103.242>
Call-ID: 44f1fdae74ca270a4d07d18f1f5bc9f9@gw03.mytel.net.au
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Wed, 22 Aug 2012 06:11:49 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Type: application/sdp
Content-Length: 316

v=0
o=root 11368 11368 IN IP4 203.166.103.242
s=session
c=IN IP4 203.166.103.242
t=0 0
m=audio 17846 RTP/AVP 8 0 18 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -

<------------->
--- (13 headers 14 lines) ---
Sending to 203.166.103.242 : 5060 (NAT)
Using INVITE request as basis request - 44f1fdae74ca270a4d07d18f1f5bc9f9@gw03.mytel.net.au
Found peer '587345'
Found RTP audio format 8
Found RTP audio format 0
Found RTP audio format 18
Found RTP audio format 3
Found RTP audio format 101
Peer audio RTP is at port 203.166.103.242:17846
Found description format PCMA for ID 8
Found description format PCMU for ID 0
Found description format G729 for ID 18
Found description format GSM for ID 3
Found description format telephone-event for ID 101
Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x10e (gsm|ulaw|alaw|g729)/video=0x0 (nothing), combined - 0xc (ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Peer audio RTP is at port 203.166.103.242:17846
Looking for 587345 in default (domain 220.233.85.199)

<--- Reliably Transmitting (NAT) to 203.166.103.242:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK0a1655a7;received=203.166.103.242;rport=5060
From: "0421903810" <sip:0421903810@gw03.mytel.net.au>;tag=as23192825
To: <sip:587345@220.233.85.199>;tag=as39606e15
Call-ID: 44f1fdae74ca270a4d07d18f1f5bc9f9@gw03.mytel.net.au
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '44f1fdae74ca270a4d07d18f1f5bc9f9@gw03.mytel.net.au' in 3136 ms (Method: INVITE)

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
ACK sip:587345@220.233.85.199 SIP/2.0
Via: SIP/2.0/UDP 203.166.103.242:5060;branch=z9hG4bK0a1655a7;rport
From: "0421903810" <sip:0421903810@gw03.mytel.net.au>;tag=as23192825
To: <sip:587345@220.233.85.199>;tag=as39606e15
Contact: <sip:0421903810@203.166.103.242>
Call-ID: 44f1fdae74ca270a4d07d18f1f5bc9f9@gw03.mytel.net.au
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0


<------------->
--- (10 headers 0 lines) ---
Really destroying SIP dialog '44f1fdae74ca270a4d07d18f1f5bc9f9@gw03.mytel.net.au' Method: ACK

Reliably Transmitting (no NAT) to 192.168.1.10:5060:
OPTIONS sip:106@192.168.1.10:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.30:5060;branch=z9hG4bK10091b7f;rport
From: "asterisk" <sip:asterisk@192.168.1.30>;tag=as3959c5c1
To: <sip:106@192.168.1.10:5060>
Contact: <sip:asterisk@192.168.1.30>
Call-ID: 772db2883ec84ca222566d305ad47263@192.168.1.30
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Wed, 22 Aug 2012 06:11:59 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


---

ip04*CLI>
<--- SIP read from 192.168.1.10:5060 --->
SIP/2.0 200 OK
To: <sip:106@192.168.1.10:5060>;tag=5343d61662e2665ci0
From: "asterisk" <sip:asterisk@192.168.1.30>;tag=as3959c5c1
Call-ID: 772db2883ec84ca222566d305ad47263@192.168.1.30
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.1.30:5060;branch=z9hG4bK10091b7f
Server: Linksys/SPA942-4.1.18
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER, SUBSCRIBE
Allow-Events: dialog


<------------->
--- (10 headers 0 lines) ---
Really destroying SIP dialog '772db2883ec84ca222566d305ad47263@192.168.1.30' Method: OPTIONS

Really destroying SIP dialog '5b800a867b6ccf023b900af235673ca1@203.166.103.242' Method: OPTIONS

Reliably Transmitting (NAT) to 203.166.103.242:5060:
OPTIONS sip:sip02.mytel.net.au SIP/2.0
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK4e30ad5a;rport
From: "asterisk" <sip:asterisk@220.233.85.199>;tag=as31c0821b
To: <sip:sip02.mytel.net.au>
Contact: <sip:asterisk@220.233.85.199>
Call-ID: 4764fdb3731379d33ff25c295665384e@220.233.85.199
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Wed, 22 Aug 2012 06:12:16 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


---

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK4e30ad5a;received=220.233.85.199;rport=5060
From: "asterisk" <sip:asterisk@220.233.85.199>;tag=as31c0821b
To: <sip:sip02.mytel.net.au>;tag=as5a97ea88
Call-ID: 4764fdb3731379d33ff25c295665384e@220.233.85.199
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:203.166.103.242>
Accept: application/sdp
Content-Length: 0


<------------->
--- (11 headers 0 lines) ---
Really destroying SIP dialog '4764fdb3731379d33ff25c295665384e@220.233.85.199' Method: OPTIONS

[2012-08-22 06:12:18] NOTICE[88]: chan_sip.c:7147 sip_reregister:    -- Re-registration for  587345@587345
REGISTER 13 headers, 0 lines
Reliably Transmitting (NAT) to 203.166.103.242:5060:
REGISTER sip:mytel.net.au SIP/2.0
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK63f51060;rport
From: <sip:587345@sip02.mytel.net.au>;tag=as15531267
To: <sip:587345@sip02.mytel.net.au>
Call-ID: 5dac158d408b4aca4ebe1ea958d48347@mytel.net.au
CSeq: 199 REGISTER
User-Agent: Asterisk PBX
Max-Forwards: 70
Authorization: Digest username="587345", realm="asterisk", algorithm=MD5, uri="sip:mytel.net.au", nonce="6d418d77", response="e1a6f37a7af78ed0a2c5ce93ac213843", opaque=""
Expires: 120
Contact: <sip:587345@220.233.85.199>
Event: registration
Content-Length: 0


---

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK63f51060;received=220.233.85.199;rport=5060
From: <sip:587345@sip02.mytel.net.au>;tag=as15531267
To: <sip:587345@sip02.mytel.net.au>
Call-ID: 5dac158d408b4aca4ebe1ea958d48347@mytel.net.au
CSeq: 199 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:587345@203.166.103.242>
Content-Length: 0


<------------->
--- (10 headers 0 lines) ---

<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK63f51060;received=220.233.85.199;rport=5060
From: <sip:587345@sip02.mytel.net.au>;tag=as15531267
To: <sip:587345@sip02.mytel.net.au>;tag=as13c1dc4f
Call-ID: 5dac158d408b4aca4ebe1ea958d48347@mytel.net.au
CSeq: 199 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="6e1b6fca"
Content-Length: 0


<------------->
--- (10 headers 0 lines) ---
Responding to challenge, registration to domain/host name 587345
REGISTER 13 headers, 0 lines
Reliably Transmitting (NAT) to 203.166.103.242:5060:
REGISTER sip:mytel.net.au SIP/2.0
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK49e61890;rport
From: <sip:587345@sip02.mytel.net.au>;tag=as20dfa973
To: <sip:587345@sip02.mytel.net.au>
Call-ID: 5dac158d408b4aca4ebe1ea958d48347@mytel.net.au
CSeq: 200 REGISTER
User-Agent: Asterisk PBX
Max-Forwards: 70
Authorization: Digest username="587345", realm="asterisk", algorithm=MD5, uri="sip:mytel.net.au", nonce="6e1b6fca", response="da18f117f7b0009a0ac32ceca955324c", opaque=""
Expires: 120
Contact: <sip:587345@220.233.85.199>
Event: registration
Content-Length: 0


---

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK49e61890;received=220.233.85.199;rport=5060
From: <sip:587345@sip02.mytel.net.au>;tag=as20dfa973
To: <sip:587345@sip02.mytel.net.au>
Call-ID: 5dac158d408b4aca4ebe1ea958d48347@mytel.net.au
CSeq: 200 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:587345@203.166.103.242>
Content-Length: 0


<------------->
--- (10 headers 0 lines) ---

ip04*CLI>
<--- SIP read from 203.166.103.242:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 220.233.85.199:5060;branch=z9hG4bK49e61890;received=220.233.85.199;rport=5060
From: <sip:587345@sip02.mytel.net.au>;tag=as20dfa973
To: <sip:587345@sip02.mytel.net.au>;tag=as13c1dc4f
Call-ID: 5dac158d408b4aca4ebe1ea958d48347@mytel.net.au
CSeq: 200 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Expires: 120
Contact: <sip:587345@220.233.85.199>;expires=120
Date: Wed, 22 Aug 2012 06:12:18 GMT
Content-Length: 0


<------------->
--- (12 headers 0 lines) ---
Scheduling destruction of SIP dialog '5dac158d408b4aca4ebe1ea958d48347@mytel.net.au' in 6400 ms (Method: REGISTER)
[2012-08-22 06:12:18] NOTICE[88]: chan_sip.c:12117 handle_response_register: Outbound Registration: Expiry for 587345 is 120 sec (Scheduling reregistration in 105 s)

ip04*CLI>

david55 · August 22, 2012, 6:55am

Replace s by 0421903810; you have a proper DID line.

system · August 24, 2012, 1:09am

Despite vast misgivings - I need the s for default starting calls

I commented out my dialplan and set the following

exten => 0421903810,1,Dial(SIP/106) exten => s,1,Dial(SIP/206)

My desk phone is registered for both extensions. Tested incoming call from my mobile. Neither extension rang. No log because I was interrupted by my boss before I copy pasted

Topic		Replies	Views
Only ringtone but cannot answer the call Asterisk Support	4	275	January 18, 2009
[RESOLVED] Inbound Calls Not Ringing Phones Asterisk Support	6	2219	March 30, 2011
Inbound SIP Calls Not Working Asterisk Support	1	948	July 17, 2008
Inbound Call Issues Asterisk Support	19	1721	August 5, 2008
Need Help With Outbound Calls Asterisk Support	1	190	August 14, 2010

Inbound SIP, phones don't ring

Related topics