Incoming calls drop after a few seconds

pmlco · February 28, 2017, 5:00pm

Hello!

One of my SIP termination providers is Viatalk. Yesterday, incoming calls started to drop after 5/6 seconds. It had been working well for years, and I have not changed the configuration, so I assume it’s a change on their end (I’ve opened a support ticket, but so far no response.) Here is the relevant entry in sip.conf

[viatalk-3]
outboundproxy=hightower.vtnoc.net,force
type=peer
defaultuser=myphonenumber
fromuser=myphonenumber
authuser=myphonenumber
fromdomain=grimlock.vtnoc.net
insecure=invite
host=grimlock.vtnoc.net
secret=<secret>
remotesecret=<secret>
context=incoming-on-vt
accountcode=def-viatalk3
dtmfmode=inband ; VT uses inband dtmf
allow=ulaw
directmedia=no
qualify=3000
disallowed_methods = UPDATE ; changed oct 2011
description=my phone number

The sip dialog

[Feb 28 11:40:26] Asterisk 13.14.0 built by root @ pbx on a i686 running Linux on 2017-02-27 19:06:59 UTC
[Feb 28 11:41:08] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
INVITE sip:my.phone.number@192.168.71.8:5060 SIP/2.0
Record-Route: <sip:198.8.63.63;lr;ftag=gK0278ff3b;did=c4e.6b3e2754>
Record-Route: <sip:198.8.62.14;lr;ftag=gK0278ff3b>
Via: SIP/2.0/UDP 198.8.63.63:5060;branch=z9hG4bKfd55.f2a57e26.0
Via: SIP/2.0/UDP 198.8.62.14:5060;rport=5060;received=198.8.62.14;branch=z9hG4bKfd55.0bdc4f77.0
Via: SIP/2.0/UDP 4.55.18.97:5060;branch=z9hG4bK02B616c50455c301730
From: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
To: <sip:+my.phone.number@198.8.62.14:5060>
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 26347 INVITE
Max-Forwards: 67
Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE
Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed
Contact: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>
Supported: 100rel
Content-Length:  302
Content-Disposition: session; handling=required
Content-Type: application/sdp
Remote-Party-ID: Ian Jones <sip:incoming.phone.number@4.55.18.97:5060>

v=0
o=Sonus_UAC 4773 23584 IN IP4 4.55.18.97
s=SIP Media Capabilities   
c=IN IP4 4.55.18.70 
t=0 0
m=audio 18726 RTP/AVP 0 8 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=maxptime:20

<------------->
[Feb 28 11:41:08] VERBOSE[1680] chan_sip.c: --- (19 headers 14 lines) ---
[Feb 28 11:41:08] VERBOSE[1680] chan_sip.c: Sending to 198.8.63.63:5060 (NAT)
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Sending to 198.8.63.63:5060 (NAT)
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Using INVITE request as basis request - 503509327_26353629@4.55.18.97
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Found peer 'viatalk-3' for '+incoming.phone.number' from 198.8.63.63:5060
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Found RTP audio format 0
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Found RTP audio format 8
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Found RTP audio format 18
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Found RTP audio format 101
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Found audio description format PCMU for ID 0
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Found audio description format PCMA for ID 8
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Found audio description format G729 for ID 18
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Found audio description format telephone-event for ID 101
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Capabilities: us - (ulaw), peer - audio=(ulaw|alaw|g729)/video=(nothing)/text=(nothing), combined - (ulaw)
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Non-codec capabilities (dtmf): us - 0x0 (nothing), peer - 0x1 (telephone-event|), combined - 0x0 (nothing)
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Peer audio RTP is at port 4.55.18.70:18726
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: Looking for my.phone.number in incoming-on-vt (domain 192.168.71.8)
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] sip/route.c: sip_route_dump: route/path hop: <sip:198.8.63.63;lr;ftag=gK0278ff3b;did=c4e.6b3e2754>
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] sip/route.c: sip_route_dump: route/path hop: <sip:198.8.62.14;lr;ftag=gK0278ff3b>
[Feb 28 11:41:08] VERBOSE[1680][C-0000006e] chan_sip.c: 
<--- Transmitting (NAT) to 198.8.63.63:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 198.8.63.63:5060;branch=z9hG4bKfd55.f2a57e26.0;received=198.8.63.63;rport=5060
Via: SIP/2.0/UDP 198.8.62.14:5060;rport=5060;received=198.8.62.14;branch=z9hG4bKfd55.0bdc4f77.0
Via: SIP/2.0/UDP 4.55.18.97:5060;branch=z9hG4bK02B616c50455c301730
Record-Route: <sip:198.8.63.63;lr;ftag=gK0278ff3b;did=c4e.6b3e2754>
Record-Route: <sip:198.8.62.14;lr;ftag=gK0278ff3b>
From: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
To: <sip:+my.phone.number@198.8.62.14:5060>
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 26347 INVITE
Server: Asterisk PBX 13.14.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:my.phone.number@my.ip.address:5060>
Content-Length: 0


<------------>
[Feb 28 11:41:08] VERBOSE[16271][C-0000006e] chan_sip.c: Audio is at 10012
[Feb 28 11:41:08] VERBOSE[16271][C-0000006e] chan_sip.c: Adding codec ulaw to SDP
[Feb 28 11:41:08] VERBOSE[16271][C-0000006e] chan_sip.c: 
<--- Reliably Transmitting (NAT) to 198.8.63.63:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 198.8.63.63:5060;branch=z9hG4bKfd55.f2a57e26.0;received=198.8.63.63;rport=5060
Via: SIP/2.0/UDP 198.8.62.14:5060;rport=5060;received=198.8.62.14;branch=z9hG4bKfd55.0bdc4f77.0
Via: SIP/2.0/UDP 4.55.18.97:5060;branch=z9hG4bK02B616c50455c301730
Record-Route: <sip:198.8.63.63;lr;ftag=gK0278ff3b;did=c4e.6b3e2754>
Record-Route: <sip:198.8.62.14;lr;ftag=gK0278ff3b>
From: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
To: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 26347 INVITE
Server: Asterisk PBX 13.14.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:my.phone.number@my.ip.address:5060>
Content-Type: application/sdp
Content-Length: 198

v=0
o=root 1006485374 1006485374 IN IP4 my.ip.address
s=Asterisk PBX 13.14.0
c=IN IP4 my.ip.address
t=0 0
m=audio 10012 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=ptime:20
a=maxptime:150
a=sendrecv

<------------>
[Feb 28 11:41:08] VERBOSE[1680] chan_sip.c: Retransmitting #1 (NAT) to 198.8.63.63:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 198.8.63.63:5060;branch=z9hG4bKfd55.f2a57e26.0;received=198.8.63.63;rport=5060
Via: SIP/2.0/UDP 198.8.62.14:5060;rport=5060;received=198.8.62.14;branch=z9hG4bKfd55.0bdc4f77.0
Via: SIP/2.0/UDP 4.55.18.97:5060;branch=z9hG4bK02B616c50455c301730
Record-Route: <sip:198.8.63.63;lr;ftag=gK0278ff3b;did=c4e.6b3e2754>
Record-Route: <sip:198.8.62.14;lr;ftag=gK0278ff3b>
From: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
To: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 26347 INVITE
Server: Asterisk PBX 13.14.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:my.phone.number@my.ip.address:5060>
Content-Type: application/sdp
Content-Length: 198

v=0
o=root 1006485374 1006485374 IN IP4 my.ip.address
s=Asterisk PBX 13.14.0
c=IN IP4 my.ip.address
t=0 0
m=audio 10012 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=ptime:20
a=maxptime:150
a=sendrecv

---
[Feb 28 11:41:08] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
ACK sip:my.phone.number@192.168.71.8:5060 SIP/2.0
Record-Route: <sip:198.8.63.63;lr;ftag=gK0278ff3b>
Record-Route: <sip:198.8.62.14;lr;ftag=gK0278ff3b>
Via: SIP/2.0/UDP 198.8.63.63:5060;branch=z9hG4bKfd55.f2a57e26.2
Via: SIP/2.0/UDP 198.8.62.14:5060;rport=5060;received=198.8.62.14;branch=z9hG4bKfd55.0bdc4f77.2
Via: SIP/2.0/UDP 4.55.18.97:5060;branch=z9hG4bK02B617871541245cd25
From: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
To: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 26347 ACK
Max-Forwards: 68
Content-Length: 0
P-hint: rr-enforced
P-hint: rr-enforced


<------------->
[Feb 28 11:41:08] VERBOSE[1680] chan_sip.c: --- (14 headers 0 lines) ---
[Feb 28 11:41:08] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
ACK sip:my.phone.number@192.168.71.8:5060 SIP/2.0
Record-Route: <sip:198.8.63.63;lr;ftag=gK0278ff3b>
Record-Route: <sip:198.8.62.14;lr;ftag=gK0278ff3b>
Via: SIP/2.0/UDP 198.8.63.63:5060;branch=z9hG4bKfd55.f2a57e26.2
Via: SIP/2.0/UDP 198.8.62.14:5060;rport=5060;received=198.8.62.14;branch=z9hG4bKfd55.0bdc4f77.2
Via: SIP/2.0/UDP 4.55.18.97:5060;branch=z9hG4bK02B61796a3d1245cd25
From: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
To: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 26347 ACK
Max-Forwards: 68
Content-Length: 0
P-hint: rr-enforced
P-hint: rr-enforced


<------------->
[Feb 28 11:41:08] VERBOSE[1680] chan_sip.c: --- (14 headers 0 lines) ---
[Feb 28 11:41:14] VERBOSE[16271][C-0000006e] chan_sip.c: Audio is at 10012
[Feb 28 11:41:14] VERBOSE[16271][C-0000006e] chan_sip.c: Adding codec ulaw to SDP
[Feb 28 11:41:14] VERBOSE[16271][C-0000006e] chan_sip.c: Reliably Transmitting (NAT) to 198.8.63.63:5060:
INVITE sip:+incoming.phone.number@4.55.18.97:5060 SIP/2.0
Via: SIP/2.0/UDP my.ip.address:5060;branch=z9hG4bK628b85b9;rport
Route: <sip:198.8.63.63;lr;ftag=gK0278ff3b;did=c4e.6b3e2754>,<sip:198.8.62.14;lr;ftag=gK0278ff3b>
Max-Forwards: 70
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Contact: <sip:my.phone.number@my.ip.address:5060>
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 INVITE
User-Agent: Asterisk PBX 13.14.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Remote-Party-ID: "Le Jardin" <sip:81@4.55.18.97>;party=called;privacy=off;screen=no
Content-Type: application/sdp
Content-Length: 198

v=0
o=root 1006485374 1006485375 IN IP4 my.ip.address
s=Asterisk PBX 13.14.0
c=IN IP4 my.ip.address
t=0 0
m=audio 10012 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=ptime:20
a=maxptime:150
a=sendrecv

---
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: Retransmitting #1 (NAT) to 198.8.63.63:5060:
INVITE sip:+incoming.phone.number@4.55.18.97:5060 SIP/2.0
Via: SIP/2.0/UDP my.ip.address:5060;branch=z9hG4bK628b85b9;rport
Route: <sip:198.8.63.63;lr;ftag=gK0278ff3b;did=c4e.6b3e2754>,<sip:198.8.62.14;lr;ftag=gK0278ff3b>
Max-Forwards: 70
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Contact: <sip:my.phone.number@my.ip.address:5060>
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 INVITE
User-Agent: Asterisk PBX 13.14.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Remote-Party-ID: "Le Jardin" <sip:81@4.55.18.97>;party=called;privacy=off;screen=no
Content-Type: application/sdp
Content-Length: 198

v=0
o=root 1006485374 1006485375 IN IP4 my.ip.address
s=Asterisk PBX 13.14.0
c=IN IP4 my.ip.address
t=0 0
m=audio 10012 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=ptime:20
a=maxptime:150
a=sendrecv

---
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.71.8:5060;received=192.168.71.8;branch=z9hG4bK628b85b9;rport=5060
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 INVITE
Server: OpenSIPS (1.8.5-tls (x86_64/linux))
Content-Length: 0
Warning: 392 198.8.63.63:5060 "Noisy feedback tells:  pid=24021 req_src_ip=my.ip.address req_src_port=5060 in_uri=sip:+incoming.phone.number@4.55.18.97:5060 out_uri=sip:+incoming.phone.number@4.55.18.97:5060 via_cnt==1"


<------------->
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: --- (9 headers 0 lines) ---
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
SIP/2.0 100 Giving a try
Via: SIP/2.0/UDP 192.168.71.8:5060;received=192.168.71.8;branch=z9hG4bK628b85b9;rport=5060
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 INVITE
Server: OpenSIPS (1.8.5-tls (x86_64/linux))
Content-Length: 0
Warning: 392 198.8.63.63:5060 "Noisy feedback tells:  pid=24021 req_src_ip=my.ip.address req_src_port=5060 in_uri=sip:+incoming.phone.number@4.55.18.97:5060 out_uri=sip:incoming.phone.number@4.55.18.97:5060 via_cnt==1"


<------------->
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: --- (9 headers 0 lines) ---
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 192.168.71.8:5060;received=192.168.71.8;branch=z9hG4bK628b85b9;rport=5060
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 INVITE
Server: OpenSIPS (1.8.3-tls (x86_64/linux))
Content-Length: 0


<------------->
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: --- (8 headers 0 lines) ---
[Feb 28 11:41:14] VERBOSE[1680][C-0000006e] chan_sip.c: Transmitting (NAT) to 198.8.63.63:5060:
ACK sip:+incoming.phone.number@4.55.18.97:5060 SIP/2.0
Via: SIP/2.0/UDP my.ip.address:5060;branch=z9hG4bK628b85b9;rport
Max-Forwards: 70
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Contact: <sip:my.phone.number@my.ip.address:5060>
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 ACK
User-Agent: Asterisk PBX 13.14.0
Content-Length: 0


---
[Feb 28 11:41:14] VERBOSE[16271][C-0000006e] chan_sip.c: Scheduling destruction of SIP dialog '503509327_26353629@4.55.18.97' in 6400 ms (Method: ACK)
[Feb 28 11:41:14] VERBOSE[16271][C-0000006e] chan_sip.c: Reliably Transmitting (NAT) to 198.8.63.63:5060:
BYE sip:+incoming.phone.number@4.55.18.97:5060 SIP/2.0
Via: SIP/2.0/UDP my.ip.address:5060;branch=z9hG4bK2e4dc5a1;rport
Route: <sip:198.8.63.63;lr;ftag=gK0278ff3b;did=c4e.6b3e2754>,<sip:198.8.62.14;lr;ftag=gK0278ff3b>
Max-Forwards: 70
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 103 BYE
User-Agent: Asterisk PBX 13.14.0
X-Asterisk-HangupCause: Unallocated (unassigned) number
X-Asterisk-HangupCauseCode: 1
Content-Length: 0


---
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.71.8:5060;received=192.168.71.8;branch=z9hG4bK628b85b9;rport=5060
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 INVITE
Record-Route: <sip:198.8.62.14:5060;lr;ftag=as59c718cd>
Record-Route: <sip:198.8.63.63:5060;lr;ftag=as59c718cd>
Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed
Contact: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>
Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE
Content-Length:  175
Content-Disposition: session; handling=required
Content-Type: application/sdp

v=0
o=Sonus_UAC 4773 23585 IN IP4 4.55.18.97
s=SIP Media Capabilities
c=IN IP4 4.55.18.70
t=0 0
m=audio 18726 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=sendrecv
a=maxptime:20

<------------->
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: --- (14 headers 9 lines) ---
[Feb 28 11:41:14] VERBOSE[1680][C-0000006e] chan_sip.c: Transmitting (NAT) to 198.8.63.63:5060:
ACK sip:+incoming.phone.number@4.55.18.97:5060 SIP/2.0
Via: SIP/2.0/UDP my.ip.address:5060;branch=z9hG4bK332100d2;rport
Route: <sip:198.8.63.63;lr;ftag=gK0278ff3b;did=c4e.6b3e2754>,<sip:198.8.62.14;lr;ftag=gK0278ff3b>
Max-Forwards: 70
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Contact: <sip:my.phone.number@my.ip.address:5060>
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 ACK
User-Agent: Asterisk PBX 13.14.0
Content-Length: 0


---
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.71.8:5060;received=192.168.71.8;branch=z9hG4bK628b85b9;rport=5060
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 INVITE
Server: OpenSIPS (1.8.5-tls (x86_64/linux))
Content-Length: 0
Warning: 392 198.8.63.63:5060 "Noisy feedback tells:  pid=24010 req_src_ip=my.ip.address req_src_port=5060 in_uri=sip:+incoming.phone.number@4.55.18.97:5060 out_uri=sip:+incoming.phone.number@4.55.18.97:5060 via_cnt==1"


<------------->
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: --- (9 headers 0 lines) ---
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.71.8:5060;received=192.168.71.8;branch=z9hG4bK628b85b9;rport=5060
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 INVITE
Record-Route: <sip:198.8.62.14:5060;lr;ftag=as59c718cd>
Record-Route: <sip:198.8.63.63:5060;lr;ftag=as59c718cd>
Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed
Contact: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>
Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE
Content-Length:  175
Content-Disposition: session; handling=required
Content-Type: application/sdp

v=0
o=Sonus_UAC 4773 23585 IN IP4 4.55.18.97
s=SIP Media Capabilities
c=IN IP4 4.55.18.70
t=0 0
m=audio 18726 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=sendrecv
a=maxptime:20

<------------->
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: --- (14 headers 9 lines) ---
[Feb 28 11:41:14] VERBOSE[1680][C-0000006e] chan_sip.c: Transmitting (NAT) to 198.8.63.63:5060:
ACK sip:+incoming.phone.number@4.55.18.97:5060 SIP/2.0
Via: SIP/2.0/UDP my.ip.address:5060;branch=z9hG4bK5e60e922;rport
Route: <sip:198.8.63.63;lr;ftag=gK0278ff3b;did=c4e.6b3e2754>,<sip:198.8.62.14;lr;ftag=gK0278ff3b>
Max-Forwards: 70
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Contact: <sip:my.phone.number@my.ip.address:5060>
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 ACK
User-Agent: Asterisk PBX 13.14.0
Content-Length: 0


---
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: Retransmitting #1 (NAT) to 198.8.63.63:5060:
BYE sip:+incoming.phone.number@4.55.18.97:5060 SIP/2.0
Via: SIP/2.0/UDP my.ip.address:5060;branch=z9hG4bK2e4dc5a1;rport
Route: <sip:198.8.63.63;lr;ftag=gK0278ff3b;did=c4e.6b3e2754>,<sip:198.8.62.14;lr;ftag=gK0278ff3b>
Max-Forwards: 70
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 103 BYE
User-Agent: Asterisk PBX 13.14.0
X-Asterisk-HangupCause: Unallocated (unassigned) number
X-Asterisk-HangupCauseCode: 1
Content-Length: 0


---
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.71.8:5060;received=192.168.71.8;branch=z9hG4bK2e4dc5a1;rport=5060
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 103 BYE
Record-Route: <sip:198.8.62.14:5060;lr;ftag=as59c718cd>
Record-Route: <sip:198.8.63.63:5060;lr;ftag=as59c718cd>
Content-Length: 0


<------------->
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: --- (9 headers 0 lines) ---
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: Really destroying SIP dialog '503509327_26353629@4.55.18.97' Method: ACK
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.71.8:5060;received=192.168.71.8;branch=z9hG4bK2e4dc5a1;rport=5060
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 103 BYE
Record-Route: <sip:198.8.62.14:5060;lr;ftag=as59c718cd>
Record-Route: <sip:198.8.63.63:5060;lr;ftag=as59c718cd>
Content-Length: 0


<------------->
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: --- (9 headers 0 lines) ---
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.71.8:5060;received=192.168.71.8;branch=z9hG4bK628b85b9;rport=5060
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 INVITE
Record-Route: <sip:198.8.62.14:5060;lr;ftag=as59c718cd>
Record-Route: <sip:198.8.63.63:5060;lr;ftag=as59c718cd>
Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed
Contact: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>
Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE
Content-Length:  175
Content-Disposition: session; handling=required
Content-Type: application/sdp

v=0
o=Sonus_UAC 4773 23585 IN IP4 4.55.18.97
s=SIP Media Capabilities
c=IN IP4 4.55.18.70
t=0 0
m=audio 18726 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=sendrecv
a=maxptime:20

<------------->
[Feb 28 11:41:14] VERBOSE[1680] chan_sip.c: --- (14 headers 9 lines) ---
[Feb 28 11:41:15] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.71.8:5060;received=192.168.71.8;branch=z9hG4bK628b85b9;rport=5060
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 INVITE
Record-Route: <sip:198.8.62.14:5060;lr;ftag=as59c718cd>
Record-Route: <sip:198.8.63.63:5060;lr;ftag=as59c718cd>
Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed
Contact: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>
Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE
Content-Length:  175
Content-Disposition: session; handling=required
Content-Type: application/sdp

v=0
o=Sonus_UAC 4773 23585 IN IP4 4.55.18.97
s=SIP Media Capabilities
c=IN IP4 4.55.18.70
t=0 0
m=audio 18726 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=sendrecv
a=maxptime:20

<------------->
[Feb 28 11:41:15] VERBOSE[1680] chan_sip.c: --- (14 headers 9 lines) ---
[Feb 28 11:41:17] VERBOSE[1680] chan_sip.c: 
<--- SIP read from UDP:198.8.63.63:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.71.8:5060;received=192.168.71.8;branch=z9hG4bK628b85b9;rport=5060
From: <sip:+my.phone.number@198.8.62.14:5060>;tag=as59c718cd
To: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>;tag=gK0278ff3b
Call-ID: 503509327_26353629@4.55.18.97
CSeq: 102 INVITE
Record-Route: <sip:198.8.62.14:5060;lr;ftag=as59c718cd>
Record-Route: <sip:198.8.63.63:5060;lr;ftag=as59c718cd>
Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed
Contact: "Ian Jones" <sip:+incoming.phone.number@4.55.18.97:5060>
Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE
Content-Length:  175
Content-Disposition: session; handling=required
Content-Type: application/sdp

v=0
o=Sonus_UAC 4773 23585 IN IP4 4.55.18.97
s=SIP Media Capabilities
c=IN IP4 4.55.18.70
t=0 0
m=audio 18726 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=sendrecv
a=maxptime:20

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

The problem would seem to be:

SIP read from UDP:198.8.63.63:5060 --->SIP/2.0 404 Not Found

Any suggestions?
Thanks
Ian

david551 · February 28, 2017, 10:33pm

404 means you dialled an unknown number.

However the exchange looks very messed up, with the other side sending a successful final completion after sending a failed final status, with the same branch, tags, and call-ID. It looks like they have broken the configuration on their OpenSIPS proxy.

pmlco · March 1, 2017, 12:29am

Thank you for that David - useful information to present to Viatalk. However, their support for Asterisk has always been cursory at best, I think it is probably time to change providers. I was thinking of switching to Digium SIP Trunking. I suppose that Digium would support Asterisk…

Regards,
Ian

david551 · March 1, 2017, 8:01am

One other point. It is the outgoing leg that is failing.

pmlco · March 1, 2017, 12:34pm

Thanks, I will pass that on.

pmlco · March 1, 2017, 10:03pm

Update from ViaTalk:

After placing a few test calls to the number, I have found the issue. It appears that when your system responds to the incoming call, it attempts to send a reInvite packet. Normally this is fine, however your system is sending the reInvite packet with both the incoming number and the outgoing number as the number that is dialing you.

Any thoughts?

david551 · March 1, 2017, 10:38pm

What I thought was an outgoing leg is actually a re-INVITE. Your trace does not support their assertion that the re-INVITE has wrong addresses, and the addresses in To and From should be ignored, anyway.

However, there is an unrouteable address in the To that you received, which you returned to them. As you obfuscated what should be the same address in the Contact header, I suspect you are behind NAT, and something on the NAT boundary is rewriting the To address. If that is the case, I would disable that.

pmlco · March 1, 2017, 10:46pm

I am indeed behind NAT. I will investigate where the To address is being re-written. In the meantime, setting sendrpid = off seems to have fixed it. Thanks for your insight.