[SOLVED] SIP and OpenVPN

Hi all: It was my understanding that when using OpenVPN, the SIP session would see the OpenVPN IP as RTP source, not the “original” IP, but that doesn’t seem to be the case.

I have a pfSense router on network 192.168.10.0, its IP is 192.168.10.1

There is an OpenVPN server instance running on my pfSense router, set to TUN on network 172.16.0.0

My FreePBX IP is 192.168.10.4, set to nat=no, as it also has a public IP on a second ethernet card to connect to my VoIP provider.

I have a softphone installed on my phone, and my home network is on 192.168.0.0 (pfSense and FreePBX are on my office). The phone’s IP is 192.168.0.21

When I connect my phone to OpenVPN, I get the IP 172.168.0.6 and I can register, make and receive calls on my softphone app, as long as I have set the extension to nat=yes, because I don’t get any audio if the extension is set to nat=no, but that is what I don’t seem to understand correctly. It was my understanding that no matter whether I’m behind NAT or not, Asterisk should be seeing the session as coming from IP 172.16.0.6, and not from 192.168.0.21, because that is the IP of the OpenVPN connection. I have set networks 192.168.10.0 and 172.16.0.0 as local on SIP settings.

This is a diagram of the network, hope it is legible.

My softphone (extension 151)
192.168.0.21
172.16.0.6 (OpenVPN Client IP)
|
|
My home router
Dynamic public IP 190.17.xxx.xxx
NAT Network 192.168.0.0
192.168.0.1
|
|
Internet
|
|
My office router (pfSense)
Static public IP 190.11.xxx.xxx
NAT Network 192.168.10.0
OpenVPN Server network 172.16.0.0
192.168.10.1
|
|
FreePBX
192.168.10.4

Below is the SIP debug for a call to 7777, which is the simulated incoming call feature code. For sure I can see that Asterisk find the RTP data on 192.168.0.21 instead of 172.16.0.6. Is this what should really be happening, or have I misconfigured some setting that is causing this? As said before, the call works perfectly when the extension is set to nat=yes, so my question is not related to call or audio failure, I’m trying to understand why Asterisk sees the RTP as coming from 192.168.0.21 instead of 172.16.0.0, considering the OpenVPN connection should make the underlaying network 192.168.0.0 invisible to Asterisk, but maybe that is where I’m wrong.

Reading through the debug trace, it can be seen that Asterisk detects the RTP on 192.168.0.21 instead of 172.16.0.6 and that is the part I don’t understand, I assume that Asterisk should not be even seeing network 192.168.0.0 because I’m connected to the OpenVPN server. The extension is set to nat=yes and the call works correctly as expected, I’m just trying to understand how is it even possible that Asterisk is seeing the IP 192.168.0.21 as the RTP IP. I can also provide the trace of a call with the extension set to nat=no if anyone thinks it might be helpful.

<— SIP read from UDP:172.16.0.6:58348 —>
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.0.21:58348;rport;branch=z9hG4bKPjOV9zWBGBEDeYnwj0fn0UF4Wom86CwGTO
Max-Forwards: 70
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected]
Contact: sip:[email protected]:58348;ob
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26364 INVITE
Route: sip:192.168.10.4;transport=udp;lr
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: CSipSimple_p1-23/r2457
Content-Type: application/sdp
Content-Length: 310

v=0
o=- 3721990072 3721990072 IN IP4 192.168.0.21
s=pjmedia
c=IN IP4 192.168.0.21
t=0 0
m=audio 4000 RTP/AVP 3 0 8 101
c=IN IP4 192.168.0.21
a=rtcp:4001 IN IP4 192.168.0.21
a=sendrecv
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
<------------->
— (16 headers 14 lines) —
Sending to 172.16.0.6:58348 (no NAT)
Sending to 172.16.0.6:58348 (no NAT)
Using INVITE request as basis request - JEkmtKuIAloO0ulAV55OAPB32zekdFsT
Found peer ‘151’ for ‘151’ from 172.16.0.6:58348

<— Reliably Transmitting (NAT) to 172.16.0.6:58348 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.0.21:58348;branch=z9hG4bKPjOV9zWBGBEDeYnwj0fn0UF4Wom86CwGTO;received=172.16.0.6;rport=58348
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected];tag=as220e12a5
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26364 INVITE
Server: FPBX-13.0.192.19(13.18.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="37de9eb7"
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘JEkmtKuIAloO0ulAV55OAPB32zekdFsT’ in 6400 ms (Method: INVITE)

<— SIP read from UDP:172.16.0.6:58348 —>
ACK sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.0.21:58348;rport;branch=z9hG4bKPjOV9zWBGBEDeYnwj0fn0UF4Wom86CwGTO
Max-Forwards: 70
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected];tag=as220e12a5
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26364 ACK
Route: sip:192.168.10.4;transport=udp;lr
Content-Length: 0

<------------->
— (9 headers 0 lines) —

<— SIP read from UDP:172.16.0.6:58348 —>
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.0.21:58348;rport;branch=z9hG4bKPjw0dYn46zbTv8hWCCTK.hM8HaBoYJubmz
Max-Forwards: 70
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected]
Contact: sip:[email protected]:58348;ob
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26365 INVITE
Route: sip:192.168.10.4;transport=udp;lr
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: CSipSimple_p1-23/r2457
Authorization: Digest username=“151”, realm=“asterisk”, nonce=“37de9eb7”, uri="sip:[email protected]", response=“0532eafbf9b91f98af854cd7e5b31e09”, algorithm=MD5
Content-Type: application/sdp
Content-Length: 310

v=0
o=- 3721990072 3721990072 IN IP4 192.168.0.21
s=pjmedia
c=IN IP4 192.168.0.21
t=0 0
m=audio 4000 RTP/AVP 3 0 8 101
c=IN IP4 192.168.0.21
a=rtcp:4001 IN IP4 192.168.0.21
a=sendrecv
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
<------------->
— (17 headers 14 lines) —
Sending to 172.16.0.6:58348 (NAT)
Using INVITE request as basis request - JEkmtKuIAloO0ulAV55OAPB32zekdFsT
Found peer ‘151’ for ‘151’ from 172.16.0.6:58348
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
Found RTP audio format 3
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 101
Found audio description format GSM for ID 3
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format telephone-event for ID 101
Capabilities: us - (g729|g722|ulaw|alaw|g723|g726|ilbc|gsm), peer - audio=(ulaw|gsm|alaw)/video=(nothing)/text=(nothing), combined - (ulaw|alaw|gsm)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 192.168.0.21:4000
Looking for 7777 in from-internal (domain 192.168.10.4)
sip_route_dump: route/path hop: sip:[email protected]:58348;ob

<— Transmitting (NAT) to 172.16.0.6:58348 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.0.21:58348;branch=z9hG4bKPjw0dYn46zbTv8hWCCTK.hM8HaBoYJubmz;received=172.16.0.6;rport=58348
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected]
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26365 INVITE
Server: FPBX-13.0.192.19(13.18.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
– Executing [7777@from-internal:1] Macro(“SIP/151-00000013”, “user-callerid,”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/151-00000013”, “TOUCH_MONITOR=1513001270.160”) in new stack
– Executing [s@macro-user-callerid:2] Set(“SIP/151-00000013”, “AMPUSER=151”) in new stack
– Executing [s@macro-user-callerid:3] GotoIf(“SIP/151-00000013”, “0?report”) in new stack
– Executing [s@macro-user-callerid:4] ExecIf(“SIP/151-00000013”, “1?Set(REALCALLERIDNUM=151)”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/151-00000013”, “AMPUSER=151”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/151-00000013”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:7] Set(“SIP/151-00000013”, “AMPUSERCIDNAME=Ariel Grin - Celular”) in new stack
– Executing [s@macro-user-callerid:8] GotoIf(“SIP/151-00000013”, “0?report”) in new stack
– Executing [s@macro-user-callerid:9] Set(“SIP/151-00000013”, “AMPUSERCID=151”) in new stack
– Executing [s@macro-user-callerid:10] Set(“SIP/151-00000013”, “__DIAL_OPTIONS=Ttr”) in new stack
– Executing [s@macro-user-callerid:11] Set(“SIP/151-00000013”, “CALLERID(all)=“Ariel Grin - Celular” <151>”) in new stack
– Executing [s@macro-user-callerid:12] GotoIf(“SIP/151-00000013”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:13] ExecIf(“SIP/151-00000013”, “0?Set(GROUP(concurrency_limit)=151)”) in new stack
– Executing [s@macro-user-callerid:14] GosubIf(“SIP/151-00000013”, “7?sub-ccss,s,1(from-internal,7777)”) in new stack
– Executing [s@sub-ccss:1] ExecIf(“SIP/151-00000013”, “0?Return()”) in new stack
– Executing [s@sub-ccss:2] Set(“SIP/151-00000013”, “CCSS_SETUP=TRUE”) in new stack
– Executing [s@sub-ccss:3] GosubIf(“SIP/151-00000013”, “0?monitor_config,1(from-internal,7777):monitor_default,1(from-internal,7777)”) in new stack
– Executing [monitor_default@sub-ccss:1] GotoIf(“SIP/151-00000013”, “0?is_exten”) in new stack
– Executing [monitor_default@sub-ccss:2] StackPop(“SIP/151-00000013”, “”) in new stack
– Executing [monitor_default@sub-ccss:3] Return(“SIP/151-00000013”, “FALSE”) in new stack
– Executing [s@macro-user-callerid:15] ExecIf(“SIP/151-00000013”, “0?Set(CHANNEL(language)=)”) in new stack
– Executing [s@macro-user-callerid:16] NoOp(“SIP/151-00000013”, “Macro Depth is 1”) in new stack
– Executing [s@macro-user-callerid:17] GotoIf(“SIP/151-00000013”, “1?report2:macroerror”) in new stack
– Goto (macro-user-callerid,s,19)
– Executing [s@macro-user-callerid:19] GotoIf(“SIP/151-00000013”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:20] Set(“SIP/151-00000013”, “__TTL=64”) in new stack
– Executing [s@macro-user-callerid:21] GotoIf(“SIP/151-00000013”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,37)
– Executing [s@macro-user-callerid:37] Set(“SIP/151-00000013”, “CALLERID(number)=151”) in new stack
– Executing [s@macro-user-callerid:38] Set(“SIP/151-00000013”, “CALLERID(name)=Ariel Grin - Celular”) in new stack
– Executing [s@macro-user-callerid:39] GotoIf(“SIP/151-00000013”, “0?cnum”) in new stack
– Executing [s@macro-user-callerid:40] Set(“SIP/151-00000013”, “CDR(cnam)=Ariel Grin - Celular”) in new stack
– Executing [s@macro-user-callerid:41] Set(“SIP/151-00000013”, “CDR(cnum)=151”) in new stack
– Executing [s@macro-user-callerid:42] Set(“SIP/151-00000013”, “CHANNEL(language)=es”) in new stack
– Executing [7777@from-internal:2] Goto(“SIP/151-00000013”, “from-pstn,7777,1”) in new stack
– Goto (from-pstn,7777,1)
– Executing [7777@from-pstn:1] NoOp(“SIP/151-00000013”, “Catch-All DID Match - Found 7777 - You probably want a DID for this.”) in new stack
– Executing [7777@from-pstn:2] Log(“SIP/151-00000013”, “WARNING,Friendly Scanner from 192.168.0.21”) in new stack
[2017-12-11 11:07:50] WARNING[26795][C-0000000e]: Ext. 7777:2 @ from-pstn: Friendly Scanner from 192.168.0.21
– Executing [7777@from-pstn:3] Set(“SIP/151-00000013”, “__FROM_DID=7777”) in new stack
– Executing [7777@from-pstn:4] Goto(“SIP/151-00000013”, “ext-did,s,1”) in new stack
– Goto (ext-did,s,1)
– Executing [s@ext-did:1] Set(“SIP/151-00000013”, “__DIRECTION=INBOUND”) in new stack
– Executing [s@ext-did:2] Gosub(“SIP/151-00000013”, “sub-record-check,s,1(in,s,dontcare)”) in new stack
– Executing [s@sub-record-check:1] GotoIf(“SIP/151-00000013”, “0?initialized”) in new stack
– Executing [s@sub-record-check:2] Set(“SIP/151-00000013”, “__REC_STATUS=INITIALIZED”) in new stack
– Executing [s@sub-record-check:3] Set(“SIP/151-00000013”, “NOW=1513001270”) in new stack
– Executing [s@sub-record-check:4] Set(“SIP/151-00000013”, “__DAY=11”) in new stack
– Executing [s@sub-record-check:5] Set(“SIP/151-00000013”, “__MONTH=12”) in new stack
– Executing [s@sub-record-check:6] Set(“SIP/151-00000013”, “__YEAR=2017”) in new stack
– Executing [s@sub-record-check:7] Set(“SIP/151-00000013”, “__TIMESTR=20171211-110750”) in new stack
– Executing [s@sub-record-check:8] Set(“SIP/151-00000013”, “__FROMEXTEN=151”) in new stack
– Executing [s@sub-record-check:9] Set(“SIP/151-00000013”, “__MON_FMT=wav”) in new stack
– Executing [s@sub-record-check:10] NoOp(“SIP/151-00000013”, “Recordings initialized”) in new stack
– Executing [s@sub-record-check:11] ExecIf(“SIP/151-00000013”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [s@sub-record-check:12] Set(“SIP/151-00000013”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [s@sub-record-check:13] ExecIf(“SIP/151-00000013”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [s@sub-record-check:14] GotoIf(“SIP/151-00000013”, “2?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [s@sub-record-check:17] GotoIf(“SIP/151-00000013”, “1?sub-record-check,in,1”) in new stack
– Goto (sub-record-check,in,1)
– Executing [in@sub-record-check:1] NoOp(“SIP/151-00000013”, “Inbound Recording Check to s”) in new stack
– Executing [in@sub-record-check:2] Set(“SIP/151-00000013”, “FROMEXTEN=unknown”) in new stack
– Executing [in@sub-record-check:3] ExecIf(“SIP/151-00000013”, “3?Set(FROMEXTEN=151)”) in new stack
– Executing [in@sub-record-check:4] Gosub(“SIP/151-00000013”, “recordcheck,1(dontcare,in,s)”) in new stack
– Executing [recordcheck@sub-record-check:1] NoOp(“SIP/151-00000013”, “Starting recording check against dontcare”) in new stack
– Executing [recordcheck@sub-record-check:2] Goto(“SIP/151-00000013”, “dontcare”) in new stack
– Goto (sub-record-check,recordcheck,3)
– Executing [recordcheck@sub-record-check:3] Return(“SIP/151-00000013”, “”) in new stack
– Executing [in@sub-record-check:5] Return(“SIP/151-00000013”, “”) in new stack
– Executing [s@ext-did:3] Gosub(“SIP/151-00000013”, “app-blacklist-check,s,1()”) in new stack
– Executing [s@app-blacklist-check:1] GotoIf(“SIP/151-00000013”, “0?blacklisted”) in new stack
– Executing [s@app-blacklist-check:2] Set(“SIP/151-00000013”, “CALLED_BLACKLIST=1”) in new stack
– Executing [s@app-blacklist-check:3] Return(“SIP/151-00000013”, “”) in new stack
– Executing [s@ext-did:4] ExecIf(“SIP/151-00000013”, “0?Set(__FROM_DID=s)”) in new stack
– Executing [s@ext-did:5] Set(“SIP/151-00000013”, “CDR(did)=7777”) in new stack
– Executing [s@ext-did:6] ExecIf(“SIP/151-00000013”, “0 ?Set(CALLERID(name)=151)”) in new stack
– Executing [s@ext-did:7] Set(“SIP/151-00000013”, “__MOHCLASS=”) in new stack
– Executing [s@ext-did:8] Set(“SIP/151-00000013”, “__REVERSAL_REJECT=FALSE”) in new stack
– Executing [s@ext-did:9] GotoIf(“SIP/151-00000013”, “1?post-reverse-charge”) in new stack
– Goto (ext-did,s,11)
– Executing [s@ext-did:11] NoOp(“SIP/151-00000013”, “”) in new stack
– Executing [s@ext-did:12] Set(“SIP/151-00000013”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
– Executing [s@ext-did:13] Set(“SIP/151-00000013”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
– Executing [s@ext-did:14] Set(“SIP/151-00000013”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
– Executing [s@ext-did:15] Set(“SIP/151-00000013”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
– Executing [s@ext-did:16] Set(“SIP/151-00000013”, “CIDSFSCHEME=YmFzZV9EZWZhdWx0”) in new stack
– Executing [s@ext-did:17] AGI(“SIP/151-00000013”, “/var/www/html/admin/modules/superfecta/agi/superfecta.agi”) in new stack
– Launched AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi
/var/www/html/admin/modules/superfecta/agi/superfecta.agi: Executing Scheme…
/var/www/html/admin/modules/superfecta/agi/superfecta.agi: Scheme Asked is: Default
/var/www/html/admin/modules/superfecta/agi/superfecta.agi: The DID is: s
/var/www/html/admin/modules/superfecta/agi/superfecta.agi: The CNUM is: 151
/var/www/html/admin/modules/superfecta/agi/superfecta.agi: The CNAME is: Ariel Grin - Celular
/var/www/html/admin/modules/superfecta/agi/superfecta.agi:
/var/www/html/admin/modules/superfecta/agi/superfecta.agi: Starting scheme Default
/var/www/html/admin/modules/superfecta/agi/superfecta.agi: Converting result to UTF-8
/var/www/html/admin/modules/superfecta/agi/superfecta.agi: Setting caller id to: Ariel Grin - Celular
/var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Determined to be: ‘Ariel Grin - Celular’
/var/www/html/admin/modules/superfecta/agi/superfecta.agi: Attempting to set lookupcid
– <SIP/151-00000013>AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi completed, returning 0
– Executing [s@ext-did:18] Set(“SIP/151-00000013”, “CALLERID(name)=Ariel Grin - Celular”) in new stack
– Executing [s@ext-did:19] NoOp(“SIP/151-00000013”, “CallerID Entry Point”) in new stack
– Executing [s@ext-did:20] Goto(“SIP/151-00000013”, “timeconditions,1,1”) in new stack
– Goto (timeconditions,1,1)
– Executing [1@timeconditions:1] Set(“SIP/151-00000013”, “DB(TC/1/INUSESTATE)=INUSE”) in new stack
– Executing [1@timeconditions:2] Set(“SIP/151-00000013”, “DB(TC/1/NOT_INUSESTATE)=NOT_INUSE”) in new stack
– Executing [1@timeconditions:3] NoOp(“SIP/151-00000013”, “TIMENOW: 11:07,Mon,11,Dec”) in new stack
– Executing [1@timeconditions:4] NoOp(“SIP/151-00000013”, “TIMEMATCHED: TRUE”) in new stack
– Executing [1@timeconditions:5] GotoIfTime(“SIP/151-00000013”, “09:30-18:30,mon-fri,,?truestate”) in new stack
– Goto (timeconditions,1,14)
– Executing [1@timeconditions:14] GotoIf(“SIP/151-00000013”, “0?falsegoto”) in new stack
– Executing [1@timeconditions:15] ExecIf(“SIP/151-00000013”, “0?Set(DB(TC/1)=)”) in new stack
– Executing [1@timeconditions:16] Set(“SIP/151-00000013”, “DEVICE_STATE(Custom:TC1)=NOT_INUSE”) in new stack
– Executing [1@timeconditions:17] ExecIf(“SIP/151-00000013”, “0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)”) in new stack
– Executing [1@timeconditions:18] GotoIf(“SIP/151-00000013”, “1?app-daynight,0,1”) in new stack
– Goto (app-daynight,0,1)
– Executing [0@app-daynight:1] GotoIf(“SIP/151-00000013”, “0?from-did-direct,101,1:ivr-1,s,1”) in new stack
– Goto (ivr-1,s,1)
– Executing [s@ivr-1:1] Set(“SIP/151-00000013”, “_IVR_CONTEXT_ivr-1=”) in new stack
– Executing [s@ivr-1:2] Set(“SIP/151-00000013”, “_IVR_CONTEXT=ivr-1”) in new stack
– Executing [s@ivr-1:3] Set(“SIP/151-00000013”, “__IVR_RETVM=”) in new stack
– Executing [s@ivr-1:4] GotoIf(“SIP/151-00000013”, “0?skip”) in new stack
– Executing [s@ivr-1:5] Answer(“SIP/151-00000013”, “”) in new stack
Audio is at 15258
Adding codec ulaw to SDP
Adding codec alaw to SDP
Adding codec gsm to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<— Reliably Transmitting (NAT) to 172.16.0.6:58348 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.0.21:58348;branch=z9hG4bKPjw0dYn46zbTv8hWCCTK.hM8HaBoYJubmz;received=172.16.0.6;rport=58348
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected];tag=as4b18ea4e
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26365 INVITE
Server: FPBX-13.0.192.19(13.18.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: sip:[email protected]:5060
Content-Type: application/sdp
Require: timer
Content-Length: 299

v=0
o=root 1444674531 1444674531 IN IP4 192.168.10.4
s=Asterisk PBX 13.18.3
c=IN IP4 192.168.10.4
t=0 0
m=audio 15258 RTP/AVP 0 8 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

<------------>
Retransmitting #1 (NAT) to 172.16.0.6:58348:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.0.21:58348;branch=z9hG4bKPjw0dYn46zbTv8hWCCTK.hM8HaBoYJubmz;received=172.16.0.6;rport=58348
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected];tag=as4b18ea4e
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26365 INVITE
Server: FPBX-13.0.192.19(13.18.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: sip:[email protected]:5060
Content-Type: application/sdp
Require: timer
Content-Length: 299

v=0
o=root 1444674531 1444674531 IN IP4 192.168.10.4
s=Asterisk PBX 13.18.3
c=IN IP4 192.168.10.4
t=0 0
m=audio 15258 RTP/AVP 0 8 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv


<— SIP read from UDP:172.16.0.6:58348 —>
ACK sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.21:58348;rport;branch=z9hG4bKPjMI6JkxEnwoiONncTJotGl7Dc6kjGVC…
Max-Forwards: 70
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected];tag=as4b18ea4e
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26365 ACK
Content-Length: 0

<------------->
— (8 headers 0 lines) —

<— SIP read from UDP:172.16.0.6:58348 —>
ACK sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.21:58348;rport;branch=z9hG4bKPjMI6JkxEnwoiONncTJotGl7Dc6kjGVC…
Max-Forwards: 70
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected];tag=as4b18ea4e
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26365 ACK
Content-Length: 0

<------------->
— (8 headers 0 lines) —
– Executing [s@ivr-1:6] Wait(“SIP/151-00000013”, “1”) in new stack
– Executing [s@ivr-1:7] Set(“SIP/151-00000013”, “IVR_MSG=custom/ivr”) in new stack
– Executing [s@ivr-1:8] Set(“SIP/151-00000013”, “TIMEOUT(digit)=3”) in new stack
– Digit timeout set to 3.000
– Executing [s@ivr-1:9] ExecIf(“SIP/151-00000013”, “1?Background(custom/ivr)”) in new stack
– <SIP/151-00000013> Playing ‘custom/ivr.ulaw’ (language ‘es’)

<— SIP read from UDP:172.16.0.6:58348 —>
INVITE sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.21:58348;rport;branch=z9hG4bKPj1Gc-gyyIetWKvBUMhJdhUIKKhRAYHmD9
Max-Forwards: 70
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected];tag=as4b18ea4e
Contact: sip:[email protected]:58348;ob
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26366 INVITE
Authorization: Digest username=“151”, realm=“asterisk”, nonce=“37de9eb7”, uri="sip:[email protected]", response=“0532eafbf9b91f98af854cd7e5b31e09”, algorithm=MD5
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800;refresher=uas
Min-SE: 90
Content-Type: application/sdp
Content-Length: 263

v=0
o=- 3721990072 3721990073 IN IP4 192.168.0.21
s=pjmedia
c=IN IP4 192.168.0.21
t=0 0
m=audio 4000 RTP/AVP 0 101
c=IN IP4 192.168.0.21
a=rtcp:4001 IN IP4 192.168.0.21
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=sendrecv
<------------->
— (15 headers 12 lines) —
Sending to 172.16.0.6:58348 (NAT)
Found RTP audio format 0
Found RTP audio format 101
Found audio description format PCMU for ID 0
Found audio description format telephone-event for ID 101
Capabilities: us - (g729|g722|ulaw|alaw|g723|g726|ilbc|gsm), peer - audio=(ulaw)/video=(nothing)/text=(nothing), combined - (ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 192.168.0.21:4000

<— Transmitting (NAT) to 172.16.0.6:58348 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.0.21:58348;branch=z9hG4bKPj1Gc-gyyIetWKvBUMhJdhUIKKhRAYHmD9;received=172.16.0.6;rport=58348
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected];tag=as4b18ea4e
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26366 INVITE
Server: FPBX-13.0.192.19(13.18.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
Audio is at 15258
Adding codec ulaw to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<— Reliably Transmitting (NAT) to 172.16.0.6:58348 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.0.21:58348;branch=z9hG4bKPj1Gc-gyyIetWKvBUMhJdhUIKKhRAYHmD9;received=172.16.0.6;rport=58348
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected];tag=as4b18ea4e
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26366 INVITE
Server: FPBX-13.0.192.19(13.18.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: sip:[email protected]:5060
Content-Type: application/sdp
Require: timer
Content-Length: 252

v=0
o=root 1444674531 1444674532 IN IP4 192.168.10.4
s=Asterisk PBX 13.18.3
c=IN IP4 192.168.10.4
t=0 0
m=audio 15258 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

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

<— SIP read from UDP:172.16.0.6:58348 —>
ACK sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.21:58348;rport;branch=z9hG4bKPjgxvftDsp7NXD6WPtI4jqYftQxbrTpJ3w
Max-Forwards: 70
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected];tag=as4b18ea4e
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26366 ACK
Content-Length: 0

<------------->
— (8 headers 0 lines) —

<— SIP read from UDP:172.16.0.6:58348 —>
BYE sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.21:58348;rport;branch=z9hG4bKPjcmXepMdrV0vUn7k-yPL-mttm1nwEWZfY
Max-Forwards: 70
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected];tag=as4b18ea4e
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26367 BYE
User-Agent: CSipSimple_p1-23/r2457
Content-Length: 0

<------------->
— (9 headers 0 lines) —
Sending to 172.16.0.6:58348 (NAT)
Scheduling destruction of SIP dialog ‘JEkmtKuIAloO0ulAV55OAPB32zekdFsT’ in 6400 ms (Method: BYE)

<— Transmitting (NAT) to 172.16.0.6:58348 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.0.21:58348;branch=z9hG4bKPjcmXepMdrV0vUn7k-yPL-mttm1nwEWZfY;received=172.16.0.6;rport=58348
From: sip:[email protected];tag=TgGGFaZcvJ2hq-1cC9JMlVw6BhLV9VNt
To: sip:[email protected];tag=as4b18ea4e
Call-ID: JEkmtKuIAloO0ulAV55OAPB32zekdFsT
CSeq: 26367 BYE
Server: FPBX-13.0.192.19(13.18.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

<------------>
== Spawn extension (ivr-1, s, 9) exited non-zero on ‘SIP/151-00000013’
– Executing [h@ivr-1:1] Hangup(“SIP/151-00000013”, “”) in new stack
== Spawn extension (ivr-1, h, 1) exited non-zero on 'SIP/151-00000013’
Really destroying SIP dialog ‘adb-cqtE78cwhkf7cwA.61jyrxlmdFvC’ Method: REGISTER
Really destroying SIP dialog ‘JEkmtKuIAloO0ulAV55OAPB32zekdFsT’ Method: BYE

I reviewed the SIP debug trace several times after posting this and I found out that the only conflicting issue, which was the use of external IP instead of OpenVPN IP, was coming from my VoIP app, which is CSipSimple. So I decided to try Zoiper, and set the extension to nat=no and the call worked correctly as expected, so it seems at least in my case, that the issue was with the way CSipSimple determines the source IP of the RTP stream, incorrectly using the external IP instead of the OpnVPN IP.