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.
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide