Incoming calls dropped mysteriously

Inbound calls come in on a Broadvoice SIP trunk. The CLI shows a message Using SIP RTP CoS mark 5

Then the call never comes in. Usually the next message would be an incoming call on extension xxxxxxxxx.

I turned on the sip debug and got this, does it mean anything?

VERBOSE[6347] chan_sip.c: Scheduling destruction of SIP dialog '73413bcd54266c971475e8b1454d23f5@sip.broadvoice.com’ in 32000 ms (Method: REGISTER)
[Jun 9 21:00:02] NOTICE[6347] chan_sip.c: Outbound Registration: Expiry for sip.broadvoice.com is 30 sec (Scheduling reregistration in 23 s)
[Jun 9 21:00:02] VERBOSE[6347] chan_sip.c:
<— SIP read from UDP://206.15.136.221:5060 —>
INVITE sip:2122021963@69.33.220.168:5060 SIP/2.0
Call-ID: 1f80231-f8@206.15.136.221
CSeq: 1 INVITE
From: "Chicgozn03 IL"sip:773710XXXX@206.15.136.221;user=phone;tag=3567
To: "Tuvia Vinitsky"sip:707@xxx.xxx.xxx.xxxx
Via: SIP/2.0/UDP 206.15.136.221:5060
Contact: sip:773710XXXX@206.15.136.221:5060
Supported: 100rel
Content-Length: 311
Content-Type: application/sdp

v=0
o=3457124599 10 10 IN IP4 206.15.136.247
s=-
c=IN IP4 206.15.136.250
t=0 0
m=audio 12710 RTP/AVP 0 8 18 96 97 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:96 iLBC/8000
a=fmtp:96 mode=30
a=rtpmap:97 t38/8000
a=rtpmap:101 telephone-event/8000

Thanks.

Now all I get is
Using SIP RTP Cos Mark 5
Using SIP VRTP Cos Mark 6

Any advice welcome.

would need to see more of the SIP trace + console output to let you know what happened.

OK, massive ignoramus here: What I posted was the result of SIP SET DEBUG ON. What other debug can I turn on?

Thanks

what you posted was just an invite. If you are connecting over PuTTy or something, make sure the buffer is long enough to capture multiple hundred lines of output.

sip set debug on
core set verbose 100

Once both of those have been issues, make a call. Once the problem has occurred and the call has ended

sip set debug off
core set verbose 3

post up the results.

Here it is:


[Jun 13 21:43:59] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://147.135.28.128:5060 —>
SIP/2.0 200 OK
Call-ID: 2aa189ba069d07bd52217ecc2e1df101@sip.broadvoice.com
CSeq: 8499 REGISTER
From: sip:2122021963@sip.broadvoice.com;tag=as10a18e08
To: sip:2122021963@sip.broadvoice.com
Via: SIP/2.0/UDP 69.33.220.168:5060;branch=z9hG4bK212651c0;received=69.33.220.162;rport=4669
Contact: sip:s@69.33.220.168
Expires: 30
Content-Length: 0

<------------->
[Jun 13 21:43:59] VERBOSE[12575] chan_sip.c: — (9 headers 0 lines) —
[Jun 13 21:44:01] VERBOSE[12575] chan_sip.c: Retransmitting #3 (no NAT) to 147.135.28.128:5060:
REGISTER sip:sip.broadvoice.com SIP/2.0
Via: SIP/2.0/UDP 69.33.220.168:5060;branch=z9hG4bK212651c0;rport
Max-Forwards: 70
From: sip:2122021963@sip.broadvoice.com;tag=as10a18e08
To: sip:2122021963@sip.broadvoice.com
Call-ID: 2aa189ba069d07bd52217ecc2e1df101@sip.broadvoice.com
CSeq: 8499 REGISTER
User-Agent: Asterisk PBX 1.6.1.0
Authorization: Digest username=“2122021963”, realm=“BroadWorks”, algorithm=MD5, uri=“sip:sip.broadvoice.com”, nonce=“BroadWorksXfvsp2zqnTs7337fBW”, response=“ca3b9f9ca98775adb951d3e8a8d57d2e”, qop=auth, cnonce=“237d066d”, nc=000020cd
Expires: 120
Contact: sip:s@69.33.220.168
Content-Length: 0


[Jun 13 21:44:01] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://147.135.28.128:5060 —>
SIP/2.0 200 OK
Call-ID: 2aa189ba069d07bd52217ecc2e1df101@sip.broadvoice.com
CSeq: 8499 REGISTER
From: sip:2122021963@sip.broadvoice.com;tag=as10a18e08
To: sip:2122021963@sip.broadvoice.com
Via: SIP/2.0/UDP 69.33.220.168:5060;branch=z9hG4bK212651c0;received=69.33.220.162;rport=4669
Contact: sip:s@69.33.220.168
Expires: 30
Content-Length: 0

<------------->
[Jun 13 21:44:01] VERBOSE[12575] chan_sip.c: — (9 headers 0 lines) —
[Jun 13 21:44:01] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://147.135.28.128:5060 —>
INVITE sip:2122021963@69.33.220.168:5060 SIP/2.0
Call-ID: 501b4-5@147.135.28.128
CSeq: 1 INVITE
From: "Chicgozn03 IL"sip:7737103248@147.135.28.128;user=phone;tag=8abd
To: "Tuvia Vinitsky"sip:s@69.33.220.168
Via: SIP/2.0/UDP 147.135.28.128:5060
Contact: sip:7737103248@147.135.28.128:5060
Supported: 100rel
Content-Length: 311
Content-Type: application/sdp

v=0
o=2475105527 10 10 IN IP4 147.135.28.247
s=-
c=IN IP4 147.135.28.248
t=0 0
m=audio 25750 RTP/AVP 0 8 18 96 97 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:96 iLBC/8000
a=fmtp:96 mode=30
a=rtpmap:97 t38/8000
a=rtpmap:101 telephone-event/8000

<------------->
[Jun 13 21:44:01] VERBOSE[12575] chan_sip.c: — (10 headers 14 lines) —
[Jun 13 21:44:01] VERBOSE[12575] netsock.c: == Using SIP RTP CoS mark 5
[Jun 13 21:44:01] VERBOSE[12575] netsock.c: == Using SIP VRTP CoS mark 6
[Jun 13 21:44:01] VERBOSE[12575] chan_sip.c: Sending to 147.135.28.128 : 5060 (no NAT)
[Jun 13 21:44:01] VERBOSE[12575] chan_sip.c: Using INVITE request as basis request - 501b4-5@147.135.28.128
[Jun 13 21:44:01] VERBOSE[12575] chan_sip.c: Found peer ‘sip.broadvoice.com’ for ‘7737103248’ from 147.135.28.128:5060
[Jun 13 21:44:01] VERBOSE[12575] chan_sip.c:
<— Reliably Transmitting (no NAT) to 147.135.28.128:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 147.135.28.128:5060;received=147.135.28.128
From: "Chicgozn03 IL"sip:7737103248@147.135.28.128;user=phone;tag=8abd
To: "Tuvia Vinitsky"sip:s@69.33.220.168;tag=as55597f11
Call-ID: 501b4-5@147.135.28.128
CSeq: 1 INVITE
Server: Asterisk PBX 1.6.1.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="4f08b512"
Content-Length: 0

<------------>
[Jun 13 21:44:01] VERBOSE[12575] chan_sip.c: Scheduling destruction of SIP dialog ‘501b4-5@147.135.28.128’ in 32000 ms (Method: INVITE)
[Jun 13 21:44:01] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://147.135.28.128:5060 —>
ACK sip:2122021963@69.33.220.168:5060 SIP/2.0
Call-ID: 501b4-5@147.135.28.128
CSeq: 1 ACK
From: "Chicgozn03 IL"sip:7737103248@147.135.28.128;user=phone;tag=8abd
To: "Tuvia Vinitsky"sip:s@69.33.220.168;tag=as55597f11
Via: SIP/2.0/UDP 147.135.28.128:5060
Content-Length: 0

<------------->
[Jun 13 21:44:01] VERBOSE[12575] chan_sip.c: — (7 headers 0 lines) —
[Jun 13 21:44:05] VERBOSE[12575] chan_sip.c: Retransmitting #4 (no NAT) to 147.135.28.128:5060:
REGISTER sip:sip.broadvoice.com SIP/2.0
Via: SIP/2.0/UDP 69.33.220.168:5060;branch=z9hG4bK212651c0;rport
Max-Forwards: 70
From: sip:2122021963@sip.broadvoice.com;tag=as10a18e08
To: sip:2122021963@sip.broadvoice.com
Call-ID: 2aa189ba069d07bd52217ecc2e1df101@sip.broadvoice.com
CSeq: 8499 REGISTER
User-Agent: Asterisk PBX 1.6.1.0
Authorization: Digest username=“2122021963”, realm=“BroadWorks”, algorithm=MD5, uri=“sip:sip.broadvoice.com”, nonce=“BroadWorksXfvsp2zqnTs7337fBW”, response=“ca3b9f9ca98775adb951d3e8a8d57d2e”, qop=auth, cnonce=“237d066d”, nc=000020cd
Expires: 120
Contact: sip:s@69.33.220.168
Content-Length: 0


[Jun 13 21:44:05] VERBOSE[12575] chan_sip.c: Really destroying SIP dialog '2aa189ba069d07bd52217ecc2e1df101@sip.broadvoice.com’ Method: REGISTER
[Jun 13 21:44:05] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://147.135.28.128:5060 —>
SIP/2.0 200 OK
Call-ID: 2aa189ba069d07bd52217ecc2e1df101@sip.broadvoice.com
CSeq: 8499 REGISTER
From: sip:2122021963@sip.broadvoice.com;tag=as10a18e08
To: sip:2122021963@sip.broadvoice.com
Via: SIP/2.0/UDP 69.33.220.168:5060;branch=z9hG4bK212651c0;received=69.33.220.162;rport=4669
Contact: sip:s@69.33.220.168
Expires: 30
Content-Length: 0

<------------->
[Jun 13 21:44:05] VERBOSE[12575] chan_sip.c: — (9 headers 0 lines) —
[Jun 13 21:44:05] VERBOSE[12575] chan_sip.c: Scheduling destruction of SIP dialog '2aa189ba069d07bd52217ecc2e1df101@sip.broadvoice.com’ in 32000 ms (Method: REGISTER)
[Jun 13 21:44:05] NOTICE[12575] chan_sip.c: Outbound Registration: Expiry for sip.broadvoice.com is 30 sec (Scheduling reregistration in 23 s)
[Jun 13 21:44:12] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://147.135.28.128:5060 —>
NOTIFY sip:2122021963@sip.broadvoice.com:5060 SIP/2.0
Call-ID: BW2246463121306092110820308@192.168.0.3
CSeq: 777287060 NOTIFY
From: sip:sip.broadvoice.com;tag=242478937-1244947606312-
To: sip:2122021963@sip.broadvoice.com
Via: SIP/2.0/UDP 147.135.28.128:5060;branch=z9hG4bK-BroadWorks.192.168.0.3-192.168.28.128V5060-0-777287060-242478937-1244947606312-
Contact: sip:147.135.28.128:5060
Event: message-summary
Subscription-State:terminated
Content-Length: 44
Content-Type: application/simple-message-summary

Messages-Waiting: yes
voice-message: 29/0

<------------->
[Jun 13 21:44:12] VERBOSE[12575] chan_sip.c: — (11 headers 2 lines) —
[Jun 13 21:44:12] VERBOSE[12575] chan_sip.c:
<— Transmitting (no NAT) to 147.135.28.128:5060 —>
SIP/2.0 489 Bad event
Via: SIP/2.0/UDP 147.135.28.128:5060;branch=z9hG4bK-BroadWorks.192.168.0.3-192.168.28.128V5060-0-777287060-242478937-1244947606312-;received=147.135.28.128
From: sip:sip.broadvoice.com;tag=242478937-1244947606312-
To: sip:2122021963@sip.broadvoice.com;tag=as04360d10
Call-ID: BW2246463121306092110820308@192.168.0.3
CSeq: 777287060 NOTIFY
Server: Asterisk PBX 1.6.1.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Content-Length: 0

<------------>
[Jun 13 21:44:13] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://147.135.28.128:5060 —>
NOTIFY sip:2122021963@sip.broadvoice.com:5060 SIP/2.0
Call-ID: BW2246463121306092110820308@192.168.0.3
CSeq: 777287060 NOTIFY
From: sip:sip.broadvoice.com;tag=242478937-1244947606312-
To: sip:2122021963@sip.broadvoice.com
Via: SIP/2.0/UDP 147.135.28.128:5060;branch=z9hG4bK-BroadWorks.192.168.0.3-192.168.28.128V5060-0-777287060-242478937-1244947606312-
Contact: sip:147.135.28.128:5060
Event: message-summary
Subscription-State:terminated
Content-Length: 44
Content-Type: application/simple-message-summary

Messages-Waiting: yes
voice-message: 29/0

<------------->
[Jun 13 21:44:13] VERBOSE[12575] chan_sip.c: — (11 headers 2 lines) —
[Jun 13 21:44:13] VERBOSE[12575] chan_sip.c:
<— Transmitting (no NAT) to 147.135.28.128:5060 —>
SIP/2.0 489 Bad event
Via: SIP/2.0/UDP 147.135.28.128:5060;branch=z9hG4bK-BroadWorks.192.168.0.3-192.168.28.128V5060-0-777287060-242478937-1244947606312-;received=147.135.28.128
From: sip:sip.broadvoice.com;tag=242478937-1244947606312-
To: sip:2122021963@sip.broadvoice.com;tag=as62c04545
Call-ID: BW2246463121306092110820308@192.168.0.3
CSeq: 777287060 NOTIFY
Server: Asterisk PBX 1.6.1.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Content-Length: 0

<------------>
[Jun 13 21:44:13] VERBOSE[12575] chan_sip.c: Really destroying SIP dialog ‘NzM1MjhjMzM3MTQyODdlYjQ2ZDg3YTkyYmE0NTJiZjE.’ Method: REGISTER
[Jun 13 21:44:14] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://147.135.28.128:5060 —>
NOTIFY sip:2122021963@sip.broadvoice.com:5060 SIP/2.0
Call-ID: BW2246463121306092110820308@192.168.0.3
CSeq: 777287060 NOTIFY
From: sip:sip.broadvoice.com;tag=242478937-1244947606312-
To: sip:2122021963@sip.broadvoice.com
Via: SIP/2.0/UDP 147.135.28.128:5060;branch=z9hG4bK-BroadWorks.192.168.0.3-192.168.28.128V5060-0-777287060-242478937-1244947606312-
Contact: sip:147.135.28.128:5060
Event: message-summary
Subscription-State:terminated
Content-Length: 44
Content-Type: application/simple-message-summary

Messages-Waiting: yes
voice-message: 29/0

<------------->
[Jun 13 21:44:14] VERBOSE[12575] chan_sip.c: — (11 headers 2 lines) —
[Jun 13 21:44:14] VERBOSE[12575] chan_sip.c:
<— Transmitting (no NAT) to 147.135.28.128:5060 —>
SIP/2.0 489 Bad event
Via: SIP/2.0/UDP 147.135.28.128:5060;branch=z9hG4bK-BroadWorks.192.168.0.3-192.168.28.128V5060-0-777287060-242478937-1244947606312-;received=147.135.28.128
From: sip:sip.broadvoice.com;tag=242478937-1244947606312-
To: sip:2122021963@sip.broadvoice.com;tag=as421fbf59
Call-ID: BW2246463121306092110820308@192.168.0.3
CSeq: 777287060 NOTIFY
Server: Asterisk PBX 1.6.1.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Content-Length: 0

<------------>
[Jun 13 21:44:14] VERBOSE[12575] chan_sip.c: Really destroying SIP dialog ‘903ac0b7-23311e2@69.33.220.181’ Method: REGISTER
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://147.135.28.128:5060 —>
NOTIFY sip:2122021963@sip.broadvoice.com:5060 SIP/2.0
Call-ID: BW2246463121306092110820308@192.168.0.3
CSeq: 777287060 NOTIFY
From: sip:sip.broadvoice.com;tag=242478937-1244947606312-
To: sip:2122021963@sip.broadvoice.com
Via: SIP/2.0/UDP 147.135.28.128:5060;branch=z9hG4bK-BroadWorks.192.168.0.3-192.168.28.128V5060-0-777287060-242478937-1244947606312-
Contact: sip:147.135.28.128:5060
Event: message-summary
Subscription-State:terminated
Content-Length: 44
Content-Type: application/simple-message-summary

Messages-Waiting: yes
voice-message: 29/0

<------------->
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c: — (11 headers 2 lines) —
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c:
<— Transmitting (no NAT) to 147.135.28.128:5060 —>
SIP/2.0 489 Bad event
Via: SIP/2.0/UDP 147.135.28.128:5060;branch=z9hG4bK-BroadWorks.192.168.0.3-192.168.28.128V5060-0-777287060-242478937-1244947606312-;received=147.135.28.128
From: sip:sip.broadvoice.com;tag=242478937-1244947606312-
To: sip:2122021963@sip.broadvoice.com;tag=as3beb6d61
Call-ID: BW2246463121306092110820308@192.168.0.3
CSeq: 777287060 NOTIFY
Server: Asterisk PBX 1.6.1.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Content-Length: 0

<------------>
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://69.33.220.181:5060 —>
REGISTER sip:69.33.220.168 SIP/2.0
Via: SIP/2.0/UDP 69.33.220.181:5060;branch=z9hG4bK-c375c15c
From: FAX MACHINE sip:VCIFAX@69.33.220.168;tag=6f75c5037984fa06o0
To: FAX MACHINE sip:VCIFAX@69.33.220.168
Call-ID: 903ac0b7-23311e2@69.33.220.181
CSeq: 84769 REGISTER
Max-Forwards: 70
Authorization: Digest username=“VCIFAX”,realm=“asterisk”,nonce=“5e85f0c2”,uri=“sip:69.33.220.168”,algorithm=MD5,response="dfab016d10b92c373fcbbd2dc9c512cc"
Contact: FAX MACHINE sip:VCIFAX@69.33.220.181:5060;expires=36
User-Agent: Sipura/SPA2000-2.0.13(g)
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura

<------------->
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c: — (13 headers 0 lines) —
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c: Sending to 69.33.220.181 : 5060 (no NAT)
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c:
<— Transmitting (no NAT) to 69.33.220.181:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 69.33.220.181:5060;branch=z9hG4bK-c375c15c;received=69.33.220.181
From: FAX MACHINE sip:VCIFAX@69.33.220.168;tag=6f75c5037984fa06o0
To: FAX MACHINE sip:VCIFAX@69.33.220.168;tag=as6694edd2
Call-ID: 903ac0b7-23311e2@69.33.220.181
CSeq: 84769 REGISTER
Server: Asterisk PBX 1.6.1.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="57c4518a"
Content-Length: 0

<------------>
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c: Scheduling destruction of SIP dialog ‘903ac0b7-23311e2@69.33.220.181’ in 32000 ms (Method: REGISTER)
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://69.33.220.181:5060 —>
REGISTER sip:69.33.220.168 SIP/2.0
Via: SIP/2.0/UDP 69.33.220.181:5060;branch=z9hG4bK-8ea39245
From: FAX MACHINE sip:VCIFAX@69.33.220.168;tag=6f75c5037984fa06o0
To: FAX MACHINE sip:VCIFAX@69.33.220.168
Call-ID: 903ac0b7-23311e2@69.33.220.181
CSeq: 84770 REGISTER
Max-Forwards: 70
Authorization: Digest username=“VCIFAX”,realm=“asterisk”,nonce=“57c4518a”,uri=“sip:69.33.220.168”,algorithm=MD5,response="a46537770cb2ff41c599a5d96fafe83f"
Contact: FAX MACHINE sip:VCIFAX@69.33.220.181:5060;expires=36
User-Agent: Sipura/SPA2000-2.0.13(g)
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura

<------------->
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c: — (13 headers 0 lines) —
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c: Sending to 69.33.220.181 : 5060 (no NAT)
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c:
<— Transmitting (no NAT) to 69.33.220.181:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 69.33.220.181:5060;branch=z9hG4bK-8ea39245;received=69.33.220.181
From: FAX MACHINE sip:VCIFAX@69.33.220.168;tag=6f75c5037984fa06o0
To: FAX MACHINE sip:VCIFAX@69.33.220.168;tag=as6694edd2
Call-ID: 903ac0b7-23311e2@69.33.220.181
CSeq: 84770 REGISTER
Server: Asterisk PBX 1.6.1.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Expires: 60
Contact: sip:VCIFAX@69.33.220.181:5060;expires=60
Date: Sun, 14 Jun 2009 02:44:16 GMT
Content-Length: 0

<------------>
[Jun 13 21:44:16] VERBOSE[12575] chan_sip.c: Scheduling destruction of SIP dialog ‘903ac0b7-23311e2@69.33.220.181’ in 32000 ms (Method: REGISTER)
[Jun 13 21:44:20] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://147.135.28.128:5060 —>
NOTIFY sip:2122021963@sip.broadvoice.com:5060 SIP/2.0
Call-ID: BW2246463121306092110820308@192.168.0.3
CSeq: 777287060 NOTIFY
From: sip:sip.broadvoice.com;tag=242478937-1244947606312-
To: sip:2122021963@sip.broadvoice.com
Via: SIP/2.0/UDP 147.135.28.128:5060;branch=z9hG4bK-BroadWorks.192.168.0.3-192.168.28.128V5060-0-777287060-242478937-1244947606312-
Contact: sip:147.135.28.128:5060
Event: message-summary
Subscription-State:terminated
Content-Length: 44
Content-Type: application/simple-message-summary

Messages-Waiting: yes
voice-message: 29/0

<------------->
[Jun 13 21:44:20] VERBOSE[12575] chan_sip.c: — (11 headers 2 lines) —
[Jun 13 21:44:20] VERBOSE[12575] chan_sip.c:
<— Transmitting (no NAT) to 147.135.28.128:5060 —>
SIP/2.0 489 Bad event
Via: SIP/2.0/UDP 147.135.28.128:5060;branch=z9hG4bK-BroadWorks.192.168.0.3-192.168.28.128V5060-0-777287060-242478937-1244947606312-;received=147.135.28.128
From: sip:sip.broadvoice.com;tag=242478937-1244947606312-
To: sip:2122021963@sip.broadvoice.com;tag=as32d15810
Call-ID: BW2246463121306092110820308@192.168.0.3
CSeq: 777287060 NOTIFY
Server: Asterisk PBX 1.6.1.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Content-Length: 0

<------------>
[Jun 13 21:44:22] VERBOSE[12575] chan_sip.c:
<— SIP read from UDP://69.33.220.174:28732 —>

<------------->
[Jun 13 21:44:24] VERBOSE[12510] dnsmgr.c: – Refreshing DNS lookups.

This is the message you are sending in response to the INVITE from Broadvoice.

<--- Reliably Transmitting (no NAT) to 147.135.28.128:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 147.135.28.128:5060;received=147.135.28.128 From: "Chicgozn03 IL"<sip:7737103248@147.135.28.128;user=phone>;tag=8abd To: "Tuvia Vinitsky"<sip:s@69.33.220.168>;tag=as55597f11 Call-ID: 501b4-5@147.135.28.128 CSeq: 1 INVITE Server: Asterisk PBX 1.6.1.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="4f08b512" Content-Length: 0

There is something wrong with your sip.conf for this trunk. 401 should only be returned by a Registrar, which your server is not acting as right now. If anything, your system should be returning a 407, Proxy Authorization required.

Post up the relevant portion of your sip.conf… but please remove/replace IP addresses, usernames and passwords.

I assume this is an asterisk 1.6 install… is that correct?

Asterisk 1.6, yes. sip.conf per broadvoice’s instructions:
[authentication]

[general]
disallow=all
allow = ulaw
allow=alaw
allow=gsm
allow=g729
allowoverlap = no
authname = blahblah
bindaddr = 0.0.0.0
bindport = 5060
context = default
; broadvoice says to use the /EXT, but asterisk docs say without it you
; get the s extension
register = blahblah@sip.broadvoice.com:password:blahblah@sip.broadvoice.com
registerattempts = 0
registertimeout = 30
callerid = "Support"
pedantic = no ; per broadvoice
musicclass=default
videosupport = yes

[sip.broadvoice.com]
disallow=all
allow = ulaw
allow=alaw
allow=gsm
allow=g729
authname=blahblah
context=default
dtmfmode=inband
dtmf=inband
fromdomain=sip.broadvoice.com
fromuser=blahblah
host=sip.broadvoice.com
insecure=very
secret=password
type=peer
user=phone
username=blahblaf
canreinvite=no

[706]
callerid = "S"
canreinvite = no
dtmfmode = rfc2833
host = dynamic
nat = no
secret =
username =
type = friend
mailbox = 706@default
incominglimit=3

[708]
type = friend
host = dynamic
dtmfmode = rfc2833
nat = no
username =
secret =
canreinvite = no
callerid = "i"
mailbox = 708@default
incominglimit=3

[707]
type = friend
host = dynamic
dtmfmode = rfc2833
nat = no
username =
secret =
canreinvite = no
callerid = "Tddd"
mailbox=707@default
incominglimit=3

[709]
type = friend
host = dynamic
dtmfmode = rfc2833
nat = no
username =
secret =
canreinvite = no
callerid = "Eli"
mailbox=709@default
incominglimit=3

[VCIFAX]
type = friend
host = dynamic
dtmfmode = rfc2833
nat = no
username =
secret =
callerid ="VCIFAX"
authname = VCIFAX
incominglimit=1

Hullo! How about this: broadvoice’s required setting of insecure=very, does not even exist as a setting. I wondered if they meant to relax the invite, which is the problem in the sip logs, so I tried:
insecure=invite

and at least for the last 10 minutes, it seems to be working.