08-03-2011 02:28 PM - edited 03-21-2019 04:27 AM
Hi Guys,
We have a client with an SPA900, SPA400 and 4x SPA942s. They signed up for a new SIP service through Nexvortex. All outbound calls work great, but an inbound call to either of their DIDs fails. The DIDs have been provisioned and I can see calls hitting SYSLOG. The error I receive is as follows:
08-03-2011 16:00:00 Local0.Info 192.168.1.4
08-03-2011 16:00:00 Local0.Info 192.168.1.4 [2]<<66.23.129.253:5060(445)
08-03-2011 16:00:00 Local0.Info 192.168.1.4
08-03-2011 16:00:00 Local0.Info 192.168.1.4 [2]->66.23.129.253:5060(692)
08-03-2011 16:00:00 Local0.Info 192.168.1.4 pri--REJECT Call(reason=39)-->pub
08-03-2011 15:59:58 Local2.Debug 192.168.1.52 [0]RegOK. NextReg in 29 (1)
08-03-2011 15:59:51 Local0.Info 192.168.1.4
08-03-2011 15:59:51 Local0.Info 192.168.1.4 [2]->66.23.129.253:5060(611)
Currently, we have a contact rule setup to send each DID to a specific extension. If I remove the Contact List Rule, the phones still will not ring when an inbound call is received.
Any ideas?
Thanks
Madison
08-04-2011 11:20 AM
This is what I am seeing from syslog when I place a call to the SPA 9000. For reference 192.168.1.4 is the PBX (SPA 9000). Any help here would be much appreciated.
Record-Route: <sip:17736445362@66.23.129.253:5060;nat=yes;ftag=a9d5ed0-13c4-4e3adfe5-6fb53347-577f1e44;lr=on>
From: <17084660658>;tag=a9d5ed0-13c4-4e3adfe5-6fb53347-577f1e4417084660658>
To: <17736445362>17736445362>
Call-ID: CXC-36-6b334650-a9d5ed0-13c4-4e3adfe5-6fb53347-683fd4d6@208.94.157.10
CSeq: 1 INVITE
Via: SIP/2.0/UDP 66.23.129.253:5060;branch=z9hG4bKa2ff.1bccbaa.0
Via: SIP/2.0/UDP 208.94.157.10:5060;branch=z9hG4bK-8e4a9-4e3adfe5-6fb53347-28f0cb2d
Max-Forwards: 16
P-Asserted-Identity: <>>17084660658@cxc.dashcs.com:5060>
Content-Disposition: session;handling=required
Contact: <17084660658>17084660658>
Min-SE: 900
Session-Expires: 1800
Content-Type: application/sdp
Content-Length: 238
v=0
o=Acme_UAS 0 1 IN IP4 208.94.157.10
s=SIP Media Capabilities
c=IN IP4 208.94.157.10
t=0 0
m=audio 20062 RTP/AVP 0 18 101
a=rtpmap:0 PCMU/8000
...
2011-08-04 13:07:30 Local0.Info 192.168.1.4
2011-08-04 13:07:30 Local0.Info 192.168.1.4
2011-08-04 13:07:30 Local0.Info 192.168.1.4 [2]->66.23.129.253:5060(621)
2011-08-04 13:07:30 Local0.Info 192.168.1.4 [2]->66.23.129.253:5060(621)
2011-08-04 13:07:30 Local7.Debug 192.168.1.4 SIP/2.0 100 Trying
To: <sip:17736445362@66.23.129.253:5060>
From: <17084660658>;tag=a9d5ed0-13c4-4e3adfe5-6fb53347-577f1e4417084660658>
Call-ID: CXC-36-6b334650-a9d5ed0-13c4-4e3adfe5-6fb53347-683fd4d6@208.94.157.10
CSeq: 1 INVITE
Via: SIP/2.0/UDP 66.23.129.253:5060;branch=z9hG4bKa2ff.1bccbaa.0
Via: SIP/2.0/UDP 208.94.157.10:5060;branch=z9hG4bK-8e4a9-4e3adfe5-6fb53347-28f0cb2d
Record-Route: <17736445362>17736445362>
Server: Linksys/SPA9000-6.1.5
Allow-Events: talk, hold, conference, x-spa-cti
Content-Length: 0
2011-08-04 13:07:30 Local0.Info 192.168.1.4
2011-08-04 13:07:30 Local0.Info 192.168.1.4
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [5060]STUN trying 0
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [16402]STUN trying 0
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [16403]STUN trying 0
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [16404]STUN trying 0
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [16405]STUN trying 0
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [5060]STUN trying 1
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [16402]STUN trying 1
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [16403]STUN trying 1
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [16404]STUN trying 1
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [16405]STUN trying 1
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [5060]STUN trying 2
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [16402]STUN trying 2
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [16403]STUN trying 2
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [16404]STUN trying 2
2011-08-04 13:07:30 Local2.Debug 192.168.1.4 [16405]STUN trying 2
2011-08-04 13:07:31 Local2.Debug 192.168.1.4 [5060]STUN trying 3
2011-08-04 13:07:31 Local2.Debug 192.168.1.4 [16402]STUN trying 3
2011-08-04 13:07:31 Local2.Debug 192.168.1.4 [16403]STUN trying 3
2011-08-04 13:07:31 Local2.Debug 192.168.1.4 [16404]STUN trying 3
2011-08-04 13:07:31 Local2.Debug 192.168.1.4 [16405]STUN trying 3
2011-08-04 13:07:32 Local2.Debug 192.168.1.4 [5060]STUN trying 4
2011-08-04 13:07:32 Local2.Debug 192.168.1.4 [16402]STUN trying 4
2011-08-04 13:07:32 Local2.Debug 192.168.1.4 [16403]STUN trying 4
2011-08-04 13:07:32 Local2.Debug 192.168.1.4 [16404]STUN trying 4
2011-08-04 13:07:32 Local2.Debug 192.168.1.4 [16405]STUN trying 4
2011-08-04 13:07:33 Local2.Debug 192.168.1.4 [5060]STUN trying 5
2011-08-04 13:07:33 Local2.Debug 192.168.1.4 [16402]STUN trying 5
2011-08-04 13:07:33 Local2.Debug 192.168.1.4 [16403]STUN trying 5
2011-08-04 13:07:33 Local2.Debug 192.168.1.4 [16404]STUN trying 5
2011-08-04 13:07:33 Local2.Debug 192.168.1.4 [16405]STUN trying 5
2011-08-04 13:07:34 Local2.Debug 192.168.1.56 [0]RegOK. NextReg in 29 (1)
2011-08-04 13:07:36 Local2.Debug 192.168.1.4 [5060]STUN trying 6
2011-08-04 13:07:36 Local2.Debug 192.168.1.4 [16402]STUN trying 6
2011-08-04 13:07:36 Local2.Debug 192.168.1.4 [16403]STUN trying 6
2011-08-04 13:07:36 Local2.Debug 192.168.1.4 [16404]STUN trying 6
2011-08-04 13:07:36 Local2.Debug 192.168.1.4 [16405]STUN trying 6
2011-08-04 13:07:36 Local2.Debug 192.168.1.4 [5060]STUN trying 7
2011-08-04 13:07:36 Local2.Debug 192.168.1.4 [16402]STUN trying 7
2011-08-04 13:07:36 Local2.Debug 192.168.1.4 [16403]STUN trying 7
2011-08-04 13:07:36 Local2.Debug 192.168.1.4 [16404]STUN trying 7
2011-08-04 13:07:36 Local2.Debug 192.168.1.4 [16405]STUN trying 7
2011-08-04 13:07:38 Local2.Debug 192.168.1.4 [5060]STUN trying 8
2011-08-04 13:07:38 Local2.Debug 192.168.1.4 [16402]STUN trying 8
2011-08-04 13:07:38 Local2.Debug 192.168.1.4 [16403]STUN trying 8
2011-08-04 13:07:38 Local2.Debug 192.168.1.4 [16404]STUN trying 8
2011-08-04 13:07:38 Local2.Debug 192.168.1.4 [16405]STUN trying 8
2011-08-04 13:07:40 Local2.Debug 192.168.1.4 [2:0]STUN Failed
2011-08-04 13:07:40 Local0.Info 192.168.1.4 [pxy]->192.168.1.55:5060(644)
2011-08-04 13:07:40 Local0.Info 192.168.1.4 [pxy]->192.168.1.55:5060(644)
2011-08-04 13:07:40 Local7.Debug 192.168.1.4 INVITE sip:102@192.168.1.55:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.4:6060;branch=z9hG4bK-b05c6c34;rport
From: <17084660658>;tag=7268b01854cde66bo217084660658>
To: <102>102>
Call-ID: e2332f5c-b181cff7@192.168.1.4
CSeq: 101 INVITE
Max-Forwards: 70
Contact: "" <17084660658>17084660658>
Expires: 240
User-Agent: Linksys/SPA9000-6.1.5
Allow-Events: talk, hold, conference, x-spa-cti
Content-Length: 67
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura, replaces
Content-Type: application/sdp
v=0
o=- IN IP4 173.161.44.5
s=-
c=IN IP4 173.161.44.5
t=0 0
2011-08-04 13:07:40 Local0.Info 192.168.1.4
2011-08-04 13:07:40 Local0.Info 192.168.1.4
2011-08-04 13:07:40 Local0.Info 192.168.1.4 [pxy]<<192.168.1.55:5060(292)
2011-08-04 13:07:40 Local0.Info 192.168.1.4 [pxy]<<192.168.1.55:5060(292)
2011-08-04 13:07:40 Local7.Debug 192.168.1.4 SIP/2.0 100 Trying
To: <sip:102@192.168.1.4>
From: <17084660658>;tag=7268b01854cde66bo217084660658>
Call-ID: e2332f5c-b181cff7@192.168.1.4
CSeq: 101 INVITE
Via: SIP/2.0/UDP 192.168.1.4:6060;branch=z9hG4bK-b05c6c34
Server: Linksys/SPA942-6.1.5(a)
Content-Length: 0
2011-08-04 13:07:40 Local0.Info 192.168.1.4
2011-08-04 13:07:40 Local0.Info 192.168.1.4
2011-08-04 13:07:40 Local0.Info 192.168.1.4 [pxy]<<192.168.1.55:5060(373)
2011-08-04 13:07:40 Local0.Info 192.168.1.4 [pxy]<<192.168.1.55:5060(373)
2011-08-04 13:07:40 Local7.Debug 192.168.1.4 SIP/2.0 488 Not Acceptable Here
To: <sip:102@192.168.1.4>;tag=d2d4205569b90bd9i0
From: <17084660658>;tag=7268b01854cde66bo217084660658>
Call-ID: e2332f5c-b181cff7@192.168.1.4
CSeq: 101 INVITE
Via: SIP/2.0/UDP 192.168.1.4:6060;branch=z9hG4bK-b05c6c34
Warning: 304 spa "Media type not available"
Server: Linksys/SPA942-6.1.5(a)
Content-Length: 0
2011-08-04 13:07:40 Local0.Info 192.168.1.4
2011-08-04 13:07:40 Local0.Info 192.168.1.4
2011-08-04 13:07:40 Local0.Info 192.168.1.4 [pxy]->192.168.1.55:5060(454)
2011-08-04 13:07:40 Local0.Info 192.168.1.4 [pxy]->192.168.1.55:5060(454)
2011-08-04 13:07:40 Local7.Debug 192.168.1.4 ACK sip:102@192.168.1.55:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.4:6060;branch=z9hG4bK-b05c6c34;rport
From: <17084660658>;tag=7268b01854cde66bo217084660658>
To: <102>;tag=d2d4205569b90bd9i0102>
Call-ID: e2332f5c-b181cff7@192.168.1.4
CSeq: 101 ACK
Max-Forwards: 70
Contact: "" <17084660658>17084660658>
User-Agent: Linksys/SPA9000-6.1.5
Allow-Events: talk, hold, conference, x-spa-cti
Content-Length: 0
2011-08-04 13:07:40 Local0.Info 192.168.1.4
2011-08-04 13:07:40 Local0.Info 192.168.1.4
2011-08-04 13:07:40 Local0.Info 192.168.1.4 pri--REJECT Call(reason=39)-->pub
2011-08-04 13:07:40 Local0.Info 192.168.1.4 pri--REJECT Call(reason=39)-->pub
2011-08-04 13:07:40 Local0.Info 192.168.1.4 [2]->66.23.129.253:5060(702)
2011-08-04 13:07:40 Local0.Info 192.168.1.4 [2]->66.23.129.253:5060(702)
2011-08-04 13:07:40 Local7.Debug 192.168.1.4 SIP/2.0 488 Not Acceptable Here
To: <sip:17736445362@66.23.129.253:5060>;tag=e1d1f9009ab6f2a4i2
From: <17084660658>;tag=a9d5ed0-13c4-4e3adfe5-6fb53347-577f1e4417084660658>
Call-ID: CXC-36-6b334650-a9d5ed0-13c4-4e3adfe5-6fb53347-683fd4d6@208.94.157.10
CSeq: 1 INVITE
Via: SIP/2.0/UDP 66.23.129.253:5060;branch=z9hG4bKa2ff.1bccbaa.0
Via: SIP/2.0/UDP 208.94.157.10:5060;branch=z9hG4bK-8e4a9-4e3adfe5-6fb53347-28f0cb2d
Record-Route: <17736445362>17736445362>
Warning: 304 spa "Media type not available"
Server: Linksys/SPA9000-6.1.5
Allow-Events: talk, hold, conference, x-spa-cti
Content-Length: 006
2011-08-04 13:07:40 Local0.Info 192.168.1.4
2011-08-04 13:07:40 Local0.Info 192.168.1.4
2011-08-04 13:07:40 Local0.Info 192.168.1.4 [2]<<66.23.129.253:5060(455)
2011-08-04 13:07:40 Local0.Info 192.168.1.4 [2]<<66.23.129.253:5060(455)
2011-08-04 13:07:40 Local7.Debug 192.168.1.4 ACK sip:17736445362@173.161.44.5;transport=udp SIP/2.0
Via: SIP/2.0/UDP 66.23.129.253:5060;branch=z9hG4bKa2ff.1bccbaa.0
From: <17084660658>;tag=a9d5ed0-13c4-4e3adfe5-6fb53347-577f1e4417084660658>
Call-ID: CXC-36-6b334650-a9d5ed0-13c4-4e3adfe5-6fb53347-683fd4d6@208.94.157.10
To: <17736445362>;tag=e1d1f9009ab6f2a4i217736445362>
CSeq: 1 ACK
User-Agent: Sip EXpress router(0.9.6 (x86_64/linux))
Content-Length: 0
2011-08-04 13:07:40 Local0.Info 192.168.1.4
2011-08-04 13:07:40 Local0.Info 192.168.1.4
2011-08-04 13:07:40 Local2.Debug 192.168.1.4 DLG Terminated 3a43f8
2011-08-04 13:07:40 Local2.Debug 192.168.1.4 Sess Terminated 3c1bb4
2011-08-04 13:07:50 Local3.Debug 192.168.1.4 [3]RegOK. NextReg in 28 (1)
2011-08-04 13:07:50 Local0.Info 192.168.1.4 +++ full fxo report
2011-08-04 13:07:50 Local0.Info 192.168.1.4 +++ full fxo report
2011-08-04 13:07:50 Local0.Info 192.168.1.4 +++[3]fxo port mask = 0
2011-08-04 13:07:50 Local0.Info 192.168.1.4 +++[3]fxo port mask = 0
2011-08-04 13:07:50 Local2.Debug 192.168.1.4 [3]SubOK. NextSub in 29 (1)
2011-08-04 13:07:54 Local0.Info 192.168.1.4 [2]->66.23.129.253:5060(484)
2011-08-04 13:07:54 Local0.Info 192.168.1.4 [2]->66.23.129.253:5060(484)
2011-08-04 13:07:54 Local7.Debug 192.168.1.4 SUBSCRIBE sip:8888@192.168.15.18:5090 SIP/2.0
Via: SIP/2.0/UDP 173.161.44.5:5060;branch=z9hG4bK-1786c7de;rport
From: ""
To: ""
Call-ID: 8d91ce4e-2db97380@192.168.1.4
CSeq: 59623 SUBSCRIBE
Max-Forwards: 70
Contact: ""
Expires: 30
Event: message-summary
User-Agent: Linksys/SPA9000-6.1.5
Allow-Events: talk, hold, conference, x-spa-cti
Content-Length: 0
2011-08-04 13:07:54 Local0.Info 192.168.1.4
2011-08-04 13:07:54 Local0.Info 192.168.1.4
2011-08-04 13:07:54 Local0.Info 192.168.1.4 [2]<<66.23.129.253:5060(383)
2011-08-04 13:07:54 Local0.Info 192.168.1.4 [2]<<66.23.129.253:5060(383)
2011-08-04 13:07:54 Local7.Debug 192.168.1.4 SIP/2.0 500 I'm terribly sorry, server error occurred (1/SL)
Via: SIP/2.0/UDP 173.161.44.5:5060;branch=z9hG4bK-1786c7de;rport=5060
From: ""
To: ""
Call-ID: 8d91ce4e-2db97380@192.168.1.4
CSeq: 59623 SUBSCRIBE
Server: nVSIP 12.02.01
Content-Length: 0
2011-08-04 13:07:54 Local0.Info 192.168.1.4
2011-08-04 13:07:54 Local0.Info 192.168.1.4
2011-08-04 13:07:54 Local2.Debug 192.168.1.4 [2]SUBS:Failed(43). Retry in 30s
08-04-2011 12:05 PM
Now it appears that roughly 1/20 calls are being received.
08-05-2011 01:00 PM
Does anyone know what the message
pri--REJECT Call(reason=39)-->pub
means?
08-05-2011 02:57 PM
I asked my carrier to do a trace and they said my system is rejecting incoming calls with a "484 rejection"
Any help would be much appreciated.
08-12-2011 06:38 AM
The solution ended up being an issue with the SPA9000 and it's communication with the Nexvortex stun server. I switched to the 3cx stun server and everything started working fine.
Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: