Outbound calls drop on connection intermittently

New installation of of the FreePBX distro on our own in-house hardware. Migrated from an Elastix VPS in the cloud, partly because I thought it might solve this problem.

Starting last week, we began to have issues with outbound calls. A call is passed to our provider (Vitelity), and as soon as it’s answered, it drops. This is intermittent, but seems to happen in clumps, or everything is fine for a while, and then we can’t make calls for a while, rinse, repeat.

I’d recently done an major update on the Elastix system, and figured that had caused some sort of issue. Since I was planning on moving away from that system anyway, I got FreePBX set up at the end of the week and over the weekend, and we were up and running on Monday morning, but the problem persists. Different server, different network, different distro, even different phones in a couple of cases. Figured it was Vitelity, so I opened a ticket with them and after digging into their logs, they informed me that the BYE signal was coming from my end…

I’ve searched everything I can think of to find people who’ve had the same issue, and most of what I found was from years ago and is unrelated. The most likely thing I can come up with is issues with RTP/firewall, but disabling the firewall doesn’t solve the problem.

I captured the sip debug output from one of these calls, which is below. Has anyone seen this recently? I’ve been running various * distros for almost a decade and haven’t run into anything like this before that couldn’t be solved by flushing the firewall rules. Even * doesn’t know why it hung up, according to the debug log.

TIA

X.X.X.X = OUR PBX IP (PUBLIC, NOT BEHIND NAT)

<--- SIP read from UDP:64.2.142.216:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP X.X.X.X:5160;branch=z9hG4bK32d78e67;received=X.X.X.X
From: <sip:[email protected]:5160>;tag=as68734862
To: <sip:[email protected]>
Call-ID: [email protected]:5160
CSeq: 103 INVITE
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Contact: <sip:[email protected]>
Content-Length: 0

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

<--- SIP read from UDP:64.2.142.216:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP X.X.X.X:5160;branch=z9hG4bK32d78e67;received=X.X.X.X
From: <sip:[email protected]:5160>;tag=as68734862
To: <sip:[email protected]>;tag=as1f0fd561
Call-ID: [email protected]:5160
CSeq: 103 INVITE
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Type: application/sdp
Content-Length: 334

v=0
o=root 18246 18246 IN IP4 64.2.142.216
s=session
c=IN IP4 64.2.142.216
t=0 0
m=audio 19544 RTP/AVP 0 8 3 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
<------------->
--- (11 headers 16 lines) ---
sip_route_dump: no route/path
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 3
Found RTP audio format 18
Found RTP audio format 101
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format GSM for ID 3
Found audio description format G729 for ID 18
Found audio description format telephone-event for ID 101
Capabilities: us - (ulaw|alaw|gsm|g726|g723|g726aal2|adpcm|slin|slin|slin|slin|slin|slin|slin|slin|slin|lpc10|g729|speex|speex|speex|ilbc|g722|siren7|siren14|testlaw|g719|opus|jpeg|png|h261|h263|h263p|h264|mpeg4|vp8|red|t140|silk|silk|silk|silk), peer - audio=(ulaw|gsm|alaw|g729)/video=(nothing)/text=(nothing), combined - (ulaw|alaw|gsm|g729)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 64.2.142.216:19544
    -- SIP/vitel-outbound-0000000d is making progress passing it to PJSIP/102-00000019

<--- SIP read from UDP:64.2.142.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP X.X.X.X:5160;branch=z9hG4bK32d78e67;received=X.X.X.X
From: <sip:[email protected]:5160>;tag=as68734862
To: <sip:[email protected]>;tag=as1f0fd561
Call-ID: [email protected]:5160
CSeq: 103 INVITE
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Type: application/sdp
Content-Length: 334

v=0
o=root 18246 18247 IN IP4 64.2.142.216
s=session
c=IN IP4 64.2.142.216
t=0 0
m=audio 19544 RTP/AVP 0 8 3 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
<------------->
--- (11 headers 16 lines) ---
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 3
Found RTP audio format 18
Found RTP audio format 101
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format GSM for ID 3
Found audio description format G729 for ID 18
Found audio description format telephone-event for ID 101
Capabilities: us - (ulaw|alaw|gsm|g726|g723|g726aal2|adpcm|slin|slin|slin|slin|slin|slin|slin|slin|slin|lpc10|g729|speex|speex|speex|ilbc|g722|siren7|siren14|testlaw|g719|opus|jpeg|png|h261|h263|h263p|h264|mpeg4|vp8|red|t140|silk|silk|silk|silk), peer - audio=(ulaw|gsm|alaw|g729)/video=(nothing)/text=(nothing), combined - (ulaw|alaw|gsm|g729)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 64.2.142.216:19544
sip_route_dump: no route/path
[2016-12-21 10:22:52] WARNING[2431][C-0000000e]: chan_sip.c:16592 __set_address_from_contact: Invalid contact uri  (missing sip: or sips:), attempting to use anyway
[2016-12-21 10:22:52] WARNING[2431][C-0000000e]: chan_sip.c:16605 __set_address_from_contact: Invalid URI: parse_uri failed to acquire hostport
Transmitting (no NAT) to 64.2.142.216:5060:
ACK sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP X.X.X.X:5160;branch=z9hG4bK774eb655
Max-Forwards: 70
From: <sip:[email protected]:5160>;tag=as68734862
To: <sip:[email protected]>;tag=as1f0fd561
Contact: <sip:[email protected]:5160>
Call-ID: [email protected]:5160
CSeq: 103 ACK
User-Agent: FPBX-13.0.190.7(13.13.1)
Content-Length: 0

---
Reliably Transmitting (no NAT) to 64.2.142.216:5060:
BYE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP X.X.X.X:5160;branch=z9hG4bK07263c34
Max-Forwards: 70
From: <sip:[email protected]:5160>;tag=as68734862
To: <sip:[email protected]>;tag=as1f0fd561
Call-ID: [email protected]:5160
CSeq: 104 BYE
User-Agent: FPBX-13.0.190.7(13.13.1)
Proxy-Authorization: Digest username="myusername", realm="asterisk", algorithm=MD5, uri="sip:[email protected]", nonce="61f2cbea", response="78bab559a93fe55939070a02f664509a"
X-Asterisk-HangupCause: Unknown
X-Asterisk-HangupCauseCode: 0
Content-Length: 0




---
Scheduling destruction of SIP dialog '[email protected]:5160' in 32000 ms (Method: INVITE)
    -- SIP/vitel-outbound-0000000d answered PJSIP/102-00000019
    -- Channel SIP/vitel-outbound-0000000d joined 'simple_bridge' basic-bridge <d87be888-6633-4be3-9af7-0ed72301cf3f>
    -- Channel PJSIP/102-00000019 joined 'simple_bridge' basic-bridge <d87be888-6633-4be3-9af7-0ed72301cf3f>
    -- Channel SIP/vitel-outbound-0000000d left 'simple_bridge' basic-bridge <d87be888-6633-4be3-9af7-0ed72301cf3f>
    -- Channel PJSIP/102-00000019 left 'simple_bridge' basic-bridge <d87be888-6633-4be3-9af7-0ed72301cf3f>
  == Spawn extension (macro-dialout-trunk, s, 23) exited non-zero on 'PJSIP/102-00000019' in macro 'dialout-trunk'
  == Spawn extension (from-internal, 5033730000, 6) exited non-zero on 'PJSIP/102-00000019'
    -- Executing [[email protected]:1] Macro("PJSIP/102-00000019", "hangupcall") in new stack
    -- Executing [[email protected]:1] GotoIf("PJSIP/102-00000019", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,3)
    -- Executing [[email protected]:3] ExecIf("PJSIP/102-00000019", "0?Set(CDR(recordingfile)=)") in new stack
    -- Executing [[email protected]:4] Hangup("PJSIP/102-00000019", "") in new stack
  == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'PJSIP/102-00000019' in macro 'hangupcall'
  == Spawn extension (from-internal, h, 1) exited non-zero on 'PJSIP/102-00000019'
  == MixMonitor close filestream (mixed)
  == End MixMonitor Recording PJSIP/102-00000019
Scheduling destruction of SIP dialog '[email protected]:5160' in 32000 ms (Method: INVITE)
Reliably Transmitting (no NAT) to 64.2.142.216:5060:
BYE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP X.X.X.X:5160;branch=z9hG4bK21083f8c
Max-Forwards: 70
From: <sip:[email protected]:5160>;tag=as68734862
To: <sip:[email protected]>;tag=as1f0fd561
Call-ID: [email protected]:5160
CSeq: 105 BYE
User-Agent: FPBX-13.0.190.7(13.13.1)
Proxy-Authorization: Digest username="myusername", realm="asterisk", algorithm=MD5, uri="sip:[email protected]", nonce="61f2cbea", response="78bab559a93fe55939070a02f664509a"
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

---

<--- SIP read from UDP:64.2.142.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP X.X.X.X:5160;branch=z9hG4bK07263c34;received=X.X.X.X
From: <sip:[email protected]:5160>;tag=as68734862
To: <sip:[email protected]>;tag=as1f0fd561
Call-ID: [email protected]:5160
CSeq: 104 BYE
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0

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

<--- SIP read from UDP:64.2.142.216:5060 --->
SIP/2.0 481 Call leg/transaction does not exist
Via: SIP/2.0/UDP X.X.X.X:5160;branch=z9hG4bK21083f8c;received=X.X.X.X
From: <sip:[email protected]:5160>;tag=as68734862
To: <sip:[email protected]>;tag=as1f0fd561
Call-ID: [email protected]:5160
CSeq: 105 BYE
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0

<------------->
--- (10 headers 0 lines) ---
Really destroying SIP dialog '[email protected]:5160' Method: INVITE

have you asked vitelity what they see on their end? we have not tried using pjsip with vitelity so i would ask them to look at the logs of your call. that should give you an answer pretty quickly

It’s just sip to vitelity. The pjsip lines are talking to the endpoint. I did talk to vitelity and they just confirmed that my system was hanging up (sending BYE). I’ve whitelisted their /24 on my firewall and made a couple of changes to the trunk definition to match their config example, and that may have helped. We’re reaaallly slow today so there hasn’t been many outbound calls made, but so far, no problems. IIRC, all I changed was removing “allow=all” and “nat=no” from the config. Doubt that had any effect.

are you using an external firewall or the firewall on the pbx? the fact that the pbx is sending the BYE indicates that there is something it does not like. a codec mismatch perhaps?

The only firewall is the built-in sangoma “responsive” firewall. I’ve always managed firewall rules & fail2ban myself, but thought I’d let the distro handle it this time and give it a try. So far I’m not all that impressed, and may go back to manual management.

In any event, the codec idea may make sense. We haven’t had the problem since I removed “allow=all” from the config, but there hasn’t been many calls made either. For now I’m going to see if the problem comes back after the changes to the firewall and trunk. Hopefully that solved it.

i think once you learn the built in firewall you will find that it does a very good job, not perfect but very good. the key though is understanding how to configure it. i am sure you know this but

  1. set all nics to external
  2. add all networks that should be accessing your pbx to trusted
  3. add those same networks to the fail2ban white list
  4. enable the responsive firewall and the appropriate protocol(s) - chan sip, pjsip,etc.
    5.carefully look at the services (two tabs of them) and set the ones you don’t use to reject and set the others to nothing. this will basically tell the firewall to allow access to those services only from the trusted networks.
  5. review the provisioning protocols in the endpoint manager and make sure what you think you are using is enabled (don’t forget that there is a corresponding service in the firewall config).

Everything is/was set correctly according to those points. The changes to the trunk config didn’t seem to do the trick, so I went with what I knew instead of trying something “next generation”, and blew away all the extensions and recreated them as chan_sip. Haven’t had the problem since. I still don’t know what the problem was at a technical level, but it’s working now. Something in the bridging of the two protocols may be broken.

were you trying to us pj sip for the trunks?

No, just for the extensions. Internal calls (the few we make) were fine, with users in the same office or dispersed. It was only when we sent a call to Vitelity. I also temporarily set up a Callcentric trunk and we didn’t have the problem when I routed calls through that trunk at first, but it eventually showed up.