Line 2 works, but line 1 reports: Unable to retrieve PJSIP transport 'udp,tcp,ws,wss'

FreePBX 14 on Centos 7.5
Grandstream GXP2000

I have two inbound routes and two extensions (200, 400) supporting two phone numbers. Both are configured essentially identically, but only one can receive calls. The other (200) fails immediately with

ERROR[14481] res_pjsip.c: Unable to retrieve PJSIP transport ‘udp,tcp,ws,wss’

This is the only log message when the call fails.

I can call out on both lines with no problem – when calling my cell phone, the caller ID on shows the correct originating phone number.

Log of registration messages:

VERBOSE[726] res_pjsip_registrar.c: Added contact ‘sip:[email protected]:5062’ to AOR ‘200’ with expiration of 3600 seconds
VERBOSE[20580] res_pjsip/pjsip_configuration.c: Contact 200/sip:[email protected]:5062 has been created
VERBOSE[20580] res_pjsip/pjsip_configuration.c: Endpoint 200 is now Reachable
VERBOSE[20580] res_pjsip/pjsip_configuration.c: Contact 200/sip:[email protected]:5062 is now Reachable. RTT: 43.316 msec
VERBOSE[726] res_pjsip_registrar.c: Removed contact ‘sip:[email protected]:5064’ from AOR ‘400’ due to request
VERBOSE[9906] res_pjsip/pjsip_configuration.c: Contact 400/sip:[email protected]:5064 has been deleted
VERBOSE[726] res_pjsip_registrar.c: Added contact ‘sip:[email protected]:5064’ to AOR ‘400’ with expiration of 600 seconds
VERBOSE[20580] res_pjsip/pjsip_configuration.c: Contact 400/sip:[email protected]:5064 has been created
VERBOSE[20580] res_pjsip/pjsip_configuration.c: Endpoint 400 is now Reachable
VERBOSE[20580] res_pjsip/pjsip_configuration.c: Contact 400/sip:[email protected]:5064 is now Reachable. RTT: 42.140 msec

The pjsip.endpoint.conf:

[400]
type=endpoint
aors=400
auth=400-auth
tos_audio=ef
tos_video=af41
cos_audio=5
cos_video=4
allow=g729,ulaw,alaw,g726,g723,g722,g719
context=from-internal
callerid=Home <400>
dtmf_mode=rfc4733
mailboxes=400@device
mwi_subscribe_replaces_unsolicited=yes
aggregate_mwi=yes
use_avpf=no
rtcp_mux=no
ice_support=no
media_use_received_transport=no
trust_id_inbound=yes
media_encryption=no
timers=yes
media_encryption_optimistic=no
send_pai=yes
rtp_symmetric=yes
rewrite_contact=yes
force_rport=yes
language=en

[200]
type=endpoint
aors=200
auth=200-auth
tos_audio=ef
tos_video=af41
cos_audio=5
cos_video=4
allow=g729,ulaw,alaw,g726,g723,g722,g719
context=from-internal
callerid=Office <200>
dtmf_mode=rfc4733
mailboxes=200@device
mwi_subscribe_replaces_unsolicited=yes
aggregate_mwi=yes
use_avpf=no
rtcp_mux=no
ice_support=no
media_use_received_transport=no
trust_id_inbound=yes
media_encryption=no
timers=yes
media_encryption_optimistic=no
send_pai=yes
rtp_symmetric=yes
rewrite_contact=yes
force_rport=yes
language=en

[anonymous]
type=endpoint
context=from-sip-external
allow=all
transport=udp,tcp,ws,wss

[dpma_endpoint]
type=endpoint
context=dpma-invalid

I have deleted and recreated the OSS Endpoint configuration.
I have deleted and recreated the extension.

Any idea what the problem is/what else to try.?

Thanks.

I am at a loss here. Any suggestions as to what to try would be very much appreciated!

Why is this here?

Have you tried removing it?

Do you have anonymous calling turned on?

This endpoint gets created when you have Allow Guests turned on in pjsip settings.
I wonder why transport=udp,tcp,ws,wss is set. There is no transport with the name [udp,tcp,ws,wss].

@gbrose, what happens when you set allow guests to no?

ws and wss are related to Zulu 3.

Under General SIP Settings, ‘Allow Anonymous’ was NO and ‘Allow Guests’ was YES – believe this was the installation default.

Setting ‘Allow Guests’ to NO removed the Anonymous endpoint config block. And, the original error message is gone.

The second line (400) continues to work both in and outbound. First line (200) works outbound only. On inbound, now getting

NOTICE[726] res_pjsip/pjsip_distributor.c: Request ‘INVITE’ from ‘“650XXXXXXX” sip:[email protected]’ failed for ‘66.241.99.27:5060’ (callid: [email protected]) - No matching endpoint found
NOTICE[14481] res_pjsip/pjsip_distributor.c: Request ‘INVITE’ from ‘“650XXXXXXX” sip:[email protected]’ failed for ‘66.241.99.27:5060’ (callid: [email protected]) - No matching endpoint found
NOTICE[14481] res_pjsip/pjsip_distributor.c: Request ‘INVITE’ from ‘“650XXXXXXX” sip:[email protected]’ failed for ‘66.241.99.27:5060’ (callid: [email protected]) - Failed to authenticate

(The 650XXXXXXX phone number is correct.)

Both endpoints (apparently) register correctly:

VERBOSE[20580] res_pjsip/pjsip_configuration.c: Contact 200/sip:[email protected]:5062 has been created
VERBOSE[20580] res_pjsip/pjsip_configuration.c: Endpoint 200 is now Reachable
[2018-07-10 11:53:49] VERBOSE[9906] res_pjsip/pjsip_configuration.c: Contact 200/sip:[email protected]:5062 is now Reachable. RTT: 33.096 msec
VERBOSE[9906] res_pjsip/pjsip_configuration.c: Contact 400/sip:[email protected]:5064 has been created
res_pjsip/pjsip_configuration.c: Endpoint 400 is now Reachable
VERBOSE[20580] res_pjsip/pjsip_configuration.c: Contact 400/sip:[email protected]:5064 is now Reachable. RTT: 35.172 msec

The ‘Secret’ field under Extension → Extension:200 → General is set to the secret set in the Grandstream account 1 (line 1).

Or is the ‘Failed to authenticate’ indicating a different problem?

Thanks.

Yes, but I think the problem above is that a transport=udp,tcp,ws,wss is set in the endpoint section.
This would refer to a configured transport in pjsip.transports.conf, which would have to be named [udp,tcp,ws,wss]. I doubt that such a transport is automatically configured on FreePBX when you set allow guests.
Transports usually look something like this, and the name in brackets is specified in transport=name in the endpoint section:
[name]
type=transport
protocol=udp
bind=0.0.0.0

I think this is a FreePBX bug.

1 Like

Can you call 200 from 400?

400 → 200 No.

VERBOSE[4193][C-00000010] chan_sip.c: Got SIP response 486 “Busy here” back from 64.2.142.216:5060
VERBOSE[18393][C-00000010] app_dial.c: SIP/vitel-outbound-0000000d is busy
VERBOSE[18393][C-00000010] app_dial.c: Everyone is busy/congested at this time (1:1/0/0)
VERBOSE[18393][C-00000010] pbx.c: Executing [s@macro-dialout-trunk:33] NoOp(“PJSIP/400-00000010”, “Dial failed for some reason with DIALSTATUS = BUSY and HANGUPCAUSE = 17”) in new stack
VERBOSE[18393][C-00000010] pbx.c: Executing [s@macro-dialout-trunk:34] GotoIf(“PJSIP/400-00000010”, “0?continue,1:s-BUSY,1”) in new stack
VERBOSE[18393][C-00000010] pbx_builtins.c: Goto (macro-dialout-trunk,s-BUSY,1)
VERBOSE[18393][C-00000010] pbx.c: Executing [s-BUSY@macro-dialout-trunk:1] NoOp(“PJSIP/400-00000010”, “Dial failed due to trunk reporting BUSY - giving up”) in new stack

200 → 400 does work as expected.

Yes BUT as @avayax stated thats not a valid transport.

This is a bug and should be reported as such

So when you are dialing 200 you are sending the call out to your voice service provider Vitelity.
Why?

Not sure how I have control over that. I do have one trunk that connects with Vitelity, one outbound route, and two inbound routes. Each inbound connects with a respective extension. Really basic setup.

So you have two extensions registered to your local server and when you call on from the other the call gets sent out your trunk to the PSTN?

Not sure why that is.

Can you show us a sip invite when you call 200 from 400?
sip set debug peer 400 from asterisk CLI.
Then sip set debug off

The connection to Vitelity is chan_sip. The extensions use pjsip. Is this is what you wanted to debug?

perk*CLI> sip show peers
Name/username Host Dyn Forcerport Comedia ACL Port Status Description
vitel-inbound/xxxxxx 66.241.99.27 Yes Yes 5060 Unmonitored
vitel-outbound/xxxxxxx 64.2.142.190 Yes Yes 5060 Unmonitored
2 sip peers [Monitored: 0 online, 0 offline Unmonitored: 2 online, 0 offline]

Those are my trunk connections.

These are the endpoints

perk*CLI> pjsip show endpoints
Endpoint: 200/200 Not in use 0 of inf
InAuth: 200-auth/200
Aor: 200 1
Contact: 200/sip:[email protected]:5062 649dc7ffff Avail 25.853
Identify: 200-identify/200

Endpoint: 400/400 Not in use 0 of inf
InAuth: 400-auth/400
Aor: 400 1
Contact: 400/sip:[email protected]:5064 48c43c5cd6 Avail 29.563
Identify: 400-identify/400

Endpoint: dpma_endpoint Unavailable 0 of inf

No, let us see a SIP Invite when you place a call to 400.
The command is actually pjsip set logger on for pjsip and sip set debug on for chansip.
So do a pjsip set logger on and place the call from 400 to 200 and then do the same thing with sip set debug on.

That shows you the flow of sip messages which might have information we can work with.

Here we go:

perk*CLI> pjsip set logger on
PJSIP Logging enabled
<--- Received SIP request (979 bytes) from UDP:192.168.71.5:5064 --->
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.71.5:5064;branch=z9hG4bKccdd7a37feb5f4bf
From: "Home" <sip:[email protected]>;tag=a7da1ca078e38948
To: <sip:[email protected]>
Contact: <sip:[email protected]:5064;transport=udp>
Supported: replaces, timer, path
P-Early-Media: Supported
Call-ID: [email protected]
CSeq: 30130 INVITE
User-Agent: Grandstream GXP2000 1.2.5.3
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
Content-Type: application/sdp
Content-Length: 403

v=0
o=400 8000 8000 IN IP4 192.168.71.5
s=SIP Call
c=IN IP4 192.168.71.5
t=0 0
m=audio 5044 RTP/AVP 18 0 8 2 4 9 97 3 101
a=sendrecv
a=rtpmap:18 G729/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:9 G722/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=20
a=rtpmap:3 GSM/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11

<--- Transmitting SIP response (509 bytes) to UDP:192.168.71.5:5064 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.71.5:5064;rport=5064;received=192.168.71.5;branch=z9hG4bKccdd7a37feb5f4bf
Call-ID: [email protected]
From: "Home" <sip:[email protected]>;tag=a7da1ca078e38948
To: <sip:[email protected]>;tag=z9hG4bKccdd7a37feb5f4bf
CSeq: 30130 INVITE
WWW-Authenticate: Digest  realm="asterisk",nonce="1531259964/3464481f833d5c50666f878b8418a5ea",opaque="2d5bdd494f3cc9aa",algorithm=md5,qop="auth"
Server: FPBX-14.0.3.6(13.19.1)
Content-Length:  0


<--- Received SIP request (522 bytes) from UDP:192.168.71.5:5064 --->
ACK sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.71.5:5064;branch=z9hG4bKccdd7a37feb5f4bf
From: "Home" <sip:[email protected]>;tag=a7da1ca078e38948
To: <sip:[email protected]>;tag=z9hG4bKccdd7a37feb5f4bf
Contact: <sip:[email protected]:5064;transport=udp>
Supported: path
Call-ID: [email protected]
CSeq: 30130 ACK
User-Agent: Grandstream GXP2000 1.2.5.3
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
Content-Length: 0


<--- Received SIP request (1259 bytes) from UDP:192.168.71.5:5064 --->
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.71.5:5064;branch=z9hG4bKfef9610a8bacb63f
From: "Home" <sip:[email protected]>;tag=a7da1ca078e38948
To: <sip:[email protected]>
Contact: <sip:[email protected]:5064;transport=udp>
Supported: replaces, timer, path
P-Early-Media: Supported
Authorization: Digest username="400", realm="asterisk", algorithm=MD5, uri="sip:[email protected]", qop=auth, nc=00000001, cnonce="294f43d15a0196e0", opaque="2d5bdd494f3cc9aa", nonce="1531259964/3464481f833d5c50666f878b8418a5ea", response="33d908351239e68ee7c627e6ecbbec79"
Call-ID: [email protected]
CSeq: 30131 INVITE
User-Agent: Grandstream GXP2000 1.2.5.3
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
Content-Type: application/sdp
Content-Length: 403

v=0
o=400 8000 8001 IN IP4 192.168.71.5
s=SIP Call
c=IN IP4 192.168.71.5
t=0 0
m=audio 5044 RTP/AVP 18 0 8 2 4 9 97 3 101
a=sendrecv
a=rtpmap:18 G729/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:9 G722/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=20
a=rtpmap:3 GSM/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11

  == Setting global variable 'SIPDOMAIN' to '192.168.122.67'
<--- Transmitting SIP response (328 bytes) to UDP:192.168.71.5:5064 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.71.5:5064;rport=5064;received=192.168.71.5;branch=z9hG4bKfef9610a8bacb63f
Call-ID: [email protected]
From: "Home" <sip:[email protected]>;tag=a7da1ca078e38948
To: <sip:[email protected]>
CSeq: 30131 INVITE
Server: FPBX-14.0.3.6(13.19.1)
Content-Length:  0


  == Using SIP RTP Audio TOS bits 184
  == Using SIP RTP Audio TOS bits 184 in TCLASS field.
  == Using SIP RTP Audio CoS mark 5
    -- Executing [3252100@from-internal:1] Macro("PJSIP/400-00000015", "user-callerid,LIMIT,EXTERNAL,") in new stack
    -- Executing [s@macro-user-callerid:1] Set("PJSIP/400-00000015", "TOUCH_MONITOR=1531259964.45") in new stack
    -- Executing [s@macro-user-callerid:2] Set("PJSIP/400-00000015", "AMPUSER=400") in new stack
    -- Executing [s@macro-user-callerid:3] GotoIf("PJSIP/400-00000015", "0?report") in new stack
    -- Executing [s@macro-user-callerid:4] ExecIf("PJSIP/400-00000015", "1?Set(REALCALLERIDNUM=400)") in new stack
    -- Executing [s@macro-user-callerid:5] Set("PJSIP/400-00000015", "AMPUSER=400") in new stack
    -- Executing [s@macro-user-callerid:6] GotoIf("PJSIP/400-00000015", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:7] Set("PJSIP/400-00000015", "AMPUSERCIDNAME=The Rosenbergs") in new stack
    -- Executing [s@macro-user-callerid:8] ExecIf("PJSIP/400-00000015", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
    -- Executing [s@macro-user-callerid:9] GotoIf("PJSIP/400-00000015", "0?report") in new stack
    -- Executing [s@macro-user-callerid:10] Set("PJSIP/400-00000015", "AMPUSERCID=400") in new stack
    -- Executing [s@macro-user-callerid:11] Set("PJSIP/400-00000015", "__DIAL_OPTIONS=HhTtr") in new stack
    -- Executing [s@macro-user-callerid:12] Set("PJSIP/400-00000015", "CALLERID(all)="The Rosenbergs" <400>") in new stack
    -- Executing [s@macro-user-callerid:13] GotoIf("PJSIP/400-00000015", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:14] ExecIf("PJSIP/400-00000015", "1?Set(GROUP(concurrency_limit)=400)") in new stack
    -- Executing [s@macro-user-callerid:15] ExecIf("PJSIP/400-00000015", "0?Set(CHANNEL(language)=)") in new stack
    -- Executing [s@macro-user-callerid:16] NoOp("PJSIP/400-00000015", "Macro Depth is 1") in new stack
    -- Executing [s@macro-user-callerid:17] GotoIf("PJSIP/400-00000015", "1?report2:macroerror") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] GotoIf("PJSIP/400-00000015", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,37)
    -- Executing [s@macro-user-callerid:37] Set("PJSIP/400-00000015", "CALLERID(number)=400") in new stack
    -- Executing [s@macro-user-callerid:38] Set("PJSIP/400-00000015", "CALLERID(name)=The Rosenbergs") in new stack
    -- Executing [s@macro-user-callerid:39] GotoIf("PJSIP/400-00000015", "0?cnum") in new stack
    -- Executing [s@macro-user-callerid:40] Set("PJSIP/400-00000015", "CDR(cnam)=The Rosenbergs") in new stack
    -- Executing [s@macro-user-callerid:41] Set("PJSIP/400-00000015", "CDR(cnum)=400") in new stack
    -- Executing [s@macro-user-callerid:42] Set("PJSIP/400-00000015", "CHANNEL(language)=en") in new stack
    -- Executing [3252100@from-internal:2] Gosub("PJSIP/400-00000015", "sub-record-check,s,1(out,3252100,dontcare)") in new stack
    -- Executing [s@sub-record-check:1] GotoIf("PJSIP/400-00000015", "0?initialized") in new stack
    -- Executing [s@sub-record-check:2] Set("PJSIP/400-00000015", "__REC_STATUS=INITIALIZED") in new stack
    -- Executing [s@sub-record-check:3] Set("PJSIP/400-00000015", "NOW=1531259964") in new stack
    -- Executing [s@sub-record-check:4] Set("PJSIP/400-00000015", "__DAY=10") in new stack
    -- Executing [s@sub-record-check:5] Set("PJSIP/400-00000015", "__MONTH=07") in new stack
    -- Executing [s@sub-record-check:6] Set("PJSIP/400-00000015", "__YEAR=2018") in new stack
    -- Executing [s@sub-record-check:7] Set("PJSIP/400-00000015", "__TIMESTR=20180710-145924") in new stack
    -- Executing [s@sub-record-check:8] Set("PJSIP/400-00000015", "__FROMEXTEN=400") in new stack
    -- Executing [s@sub-record-check:9] Set("PJSIP/400-00000015", "__MON_FMT=wav") in new stack
    -- Executing [s@sub-record-check:10] NoOp("PJSIP/400-00000015", "Recordings initialized") in new stack
    -- Executing [s@sub-record-check:11] ExecIf("PJSIP/400-00000015", "0?Set(ARG3=dontcare)") in new stack
    -- Executing [s@sub-record-check:12] Set("PJSIP/400-00000015", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [s@sub-record-check:13] ExecIf("PJSIP/400-00000015", "0?Set(REC_STATUS=NO)") in new stack
    -- Executing [s@sub-record-check:14] GotoIf("PJSIP/400-00000015", "3?checkaction") in new stack
    -- Goto (sub-record-check,s,17)
    -- Executing [s@sub-record-check:17] GotoIf("PJSIP/400-00000015", "1?sub-record-check,out,1") in new stack
    -- Goto (sub-record-check,out,1)
    -- Executing [out@sub-record-check:1] NoOp("PJSIP/400-00000015", "Outbound Recording Check from 400 to 3252100") in new stack
    -- Executing [out@sub-record-check:2] Set("PJSIP/400-00000015", "RECMODE=dontcare") in new stack
    -- Executing [out@sub-record-check:3] ExecIf("PJSIP/400-00000015", "1?Goto(routewins)") in new stack
    -- Goto (sub-record-check,out,7)
    -- Executing [out@sub-record-check:7] Gosub("PJSIP/400-00000015", "recordcheck,1(dontcare,out,3252100)") in new stack
    -- Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/400-00000015", "Starting recording check against dontcare") in new stack
    -- Executing [recordcheck@sub-record-check:2] Goto("PJSIP/400-00000015", "dontcare") in new stack
    -- Goto (sub-record-check,recordcheck,3)
    -- Executing [recordcheck@sub-record-check:3] Return("PJSIP/400-00000015", "") in new stack
    -- Executing [out@sub-record-check:8] Return("PJSIP/400-00000015", "") in new stack
    -- Executing [3252100@from-internal:3] ExecIf("PJSIP/400-00000015", "0 ?Set(CDR(accountcode)=)") in new stack
    -- Executing [3252100@from-internal:4] Set("PJSIP/400-00000015", "MOHCLASS=default") in new stack
    -- Executing [3252100@from-internal:5] Set("PJSIP/400-00000015", "_NODEST=") in new stack
    -- Executing [3252100@from-internal:6] Macro("PJSIP/400-00000015", "dialout-trunk,1,16503252100,,off") in new stack
    -- Executing [s@macro-dialout-trunk:1] Set("PJSIP/400-00000015", "DIAL_TRUNK=1") in new stack
    -- Executing [s@macro-dialout-trunk:2] ExecIf("PJSIP/400-00000015", "0?Set(DIAL_OPTIONS=Hhtr)") in new stack
    -- Executing [s@macro-dialout-trunk:3] GosubIf("PJSIP/400-00000015", "0?sub-pincheck,s,1()") in new stack
    -- Executing [s@macro-dialout-trunk:4] ExecIf("PJSIP/400-00000015", "0?Set(CALLERID(num)=400)") in new stack
    -- Executing [s@macro-dialout-trunk:5] GotoIf("PJSIP/400-00000015", "0?disabletrunk,1") in new stack
    -- Executing [s@macro-dialout-trunk:6] Set("PJSIP/400-00000015", "DIAL_NUMBER=16503252100") in new stack
    -- Executing [s@macro-dialout-trunk:7] Set("PJSIP/400-00000015", "DIAL_TRUNK_OPTIONS=HhTtr") in new stack
    -- Executing [s@macro-dialout-trunk:8] Set("PJSIP/400-00000015", "OUTBOUND_GROUP=OUT_1") in new stack
    -- Executing [s@macro-dialout-trunk:9] Set("PJSIP/400-00000015", "DIAL_TRUNK_OPTIONS=T") in new stack
    -- Executing [s@macro-dialout-trunk:10] GotoIf("PJSIP/400-00000015", "0?nomax") in new stack
    -- Executing [s@macro-dialout-trunk:11] GotoIf("PJSIP/400-00000015", "0?chanfull") in new stack
    -- Executing [s@macro-dialout-trunk:12] GotoIf("PJSIP/400-00000015", "0?skipoutcid") in new stack
    -- Executing [s@macro-dialout-trunk:13] Macro("PJSIP/400-00000015", "outbound-callerid,1") in new stack
    -- Executing [s@macro-outbound-callerid:1] NoOp("PJSIP/400-00000015", "400") in new stack
    -- Executing [s@macro-outbound-callerid:2] NoOp("PJSIP/400-00000015", "") in new stack
    -- Executing [s@macro-outbound-callerid:3] NoOp("PJSIP/400-00000015", "off") in new stack
    -- Executing [s@macro-outbound-callerid:4] ExecIf("PJSIP/400-00000015", "0?Set(CALLERPRES(name-pres)=)") in new stack
    -- Executing [s@macro-outbound-callerid:5] ExecIf("PJSIP/400-00000015", "0?Set(CALLERPRES(num-pres)=)") in new stack
    -- Executing [s@macro-outbound-callerid:6] ExecIf("PJSIP/400-00000015", "0?Set(REALCALLERIDNUM=400)") in new stack
    -- Executing [s@macro-outbound-callerid:7] ExecIf("PJSIP/400-00000015", "0?Set(AMPUSER=400)") in new stack
    -- Executing [s@macro-outbound-callerid:8] GotoIf("PJSIP/400-00000015", "1?normcid") in new stack
    -- Goto (macro-outbound-callerid,s,12)
    -- Executing [s@macro-outbound-callerid:12] Set("PJSIP/400-00000015", "USEROUTCID=") in new stack
    -- Executing [s@macro-outbound-callerid:13] Set("PJSIP/400-00000015", "EMERGENCYCID=") in new stack
    -- Executing [s@macro-outbound-callerid:14] Set("PJSIP/400-00000015", "TRUNKOUTCID=Gerald<6507031724>") in new stack
    -- Executing [s@macro-outbound-callerid:15] GotoIf("PJSIP/400-00000015", "1?trunkcid") in new stack
    -- Goto (macro-outbound-callerid,s,20)
    -- Executing [s@macro-outbound-callerid:20] ExecIf("PJSIP/400-00000015", "1?Set(CALLERID(all)=Gerald<6507031724>)") in new stack
    -- Executing [s@macro-outbound-callerid:21] ExecIf("PJSIP/400-00000015", "0?Set(CALLERID(all)=)") in new stack
    -- Executing [s@macro-outbound-callerid:22] ExecIf("PJSIP/400-00000015", "0?Set(CALLERID(all)=)") in new stack
    -- Executing [s@macro-outbound-callerid:23] ExecIf("PJSIP/400-00000015", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:24] ExecIf("PJSIP/400-00000015", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:25] Set("PJSIP/400-00000015", "CDR(outbound_cnum)=6507031724") in new stack
    -- Executing [s@macro-outbound-callerid:26] Set("PJSIP/400-00000015", "CDR(outbound_cnam)=Gerald") in new stack
    -- Executing [s@macro-dialout-trunk:14] GosubIf("PJSIP/400-00000015", "0?sub-flp-1,s,1()") in new stack
    -- Executing [s@macro-dialout-trunk:15] Set("PJSIP/400-00000015", "OUTNUM=16503252100") in new stack
    -- Executing [s@macro-dialout-trunk:16] Set("PJSIP/400-00000015", "custom=SIP/vitel-outbound") in new stack
    -- Executing [s@macro-dialout-trunk:17] ExecIf("PJSIP/400-00000015", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)") in new stack
    -- Executing [s@macro-dialout-trunk:18] ExecIf("PJSIP/400-00000015", "0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))") in new stack
    -- Executing [s@macro-dialout-trunk:19] Macro("PJSIP/400-00000015", "dialout-trunk-predial-hook,") in new stack
    -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("PJSIP/400-00000015", "") in new stack
    -- Executing [s@macro-dialout-trunk:20] GotoIf("PJSIP/400-00000015", "0?skipcrm") in new stack
    -- Executing [s@macro-dialout-trunk:21] Set("PJSIP/400-00000015", "__CRM_DIRECTION=OUTBOUND") in new stack
    -- Executing [s@macro-dialout-trunk:22] Set("PJSIP/400-00000015", "__CRM_DESTINATION=16503252100") in new stack
    -- Executing [s@macro-dialout-trunk:23] Set("PJSIP/400-00000015", "__CRM_SOURCE=400") in new stack
    -- Executing [s@macro-dialout-trunk:24] AGI("PJSIP/400-00000015", "sangomacrm.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
    -- <PJSIP/400-00000015>AGI Script sangomacrm.agi completed, returning 0
    -- Executing [s@macro-dialout-trunk:25] Set("PJSIP/400-00000015", "CHANNEL(hangup_handler_push)=crm-hangup,s,1") in new stack
    -- Executing [s@macro-dialout-trunk:26] NoOp("PJSIP/400-00000015", "CRM Finished") in new stack
    -- Executing [s@macro-dialout-trunk:27] GotoIf("PJSIP/400-00000015", "0?bypass,1") in new stack
    -- Executing [s@macro-dialout-trunk:28] ExecIf("PJSIP/400-00000015", "1?Set(CONNECTEDLINE(num,i)=16503252100)") in new stack
    -- Executing [s@macro-dialout-trunk:29] ExecIf("PJSIP/400-00000015", "1?Set(CONNECTEDLINE(name,i)=CID:6507031724)") in new stack
    -- Executing [s@macro-dialout-trunk:30] ExecIf("PJSIP/400-00000015", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)6507031724)") in new stack
    -- Executing [s@macro-dialout-trunk:31] GotoIf("PJSIP/400-00000015", "0?customtrunk") in new stack
    -- Executing [s@macro-dialout-trunk:32] Dial("PJSIP/400-00000015", "SIP/vitel-outbound/16503252100,300,Tb(func-apply-sipheaders^s^1)") in new stack
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- SIP/vitel-outbound-00000012 Internal Gosub(func-apply-sipheaders,s,1) start
    -- Executing [s@func-apply-sipheaders:1] ExecIf("SIP/vitel-outbound-00000012", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
    -- Executing [s@func-apply-sipheaders:2] NoOp("SIP/vitel-outbound-00000012", "Applying SIP Headers to channel") in new stack
    -- Executing [s@func-apply-sipheaders:3] Set("SIP/vitel-outbound-00000012", "SIPHEADERKEYS=") in new stack
    -- Executing [s@func-apply-sipheaders:4] ExecIf("SIP/vitel-outbound-00000012", "0?Set(Rheader=1)") in new stack
    -- Executing [s@func-apply-sipheaders:5] While("SIP/vitel-outbound-00000012", "0") in new stack
    -- Jumping to priority 9
    -- Executing [s@func-apply-sipheaders:10] ExecIf("SIP/vitel-outbound-00000012", "0?SIPRemoveHeader(Alert-Info:)") in new stack
    -- Executing [s@func-apply-sipheaders:11] ExecIf("SIP/vitel-outbound-00000012", "0?Set(PJSIP_HEADER(remove,Alert-Info)=)") in new stack
    -- Executing [s@func-apply-sipheaders:12] Return("SIP/vitel-outbound-00000012", "") in new stack
  == Spawn extension (from-trunk-sip-vitel-outbound, 3252100, 1) exited non-zero on 'SIP/vitel-outbound-00000012'
    -- SIP/vitel-outbound-00000012 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
    -- Called SIP/vitel-outbound/16503252100
<--- Received SIP request (897 bytes) from UDP:66.241.99.27:5060 --->
INVITE sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 66.241.99.27:5060;branch=z9hG4bK670cdb85;rport
From: "6503252100" <sip:[email protected]>;tag=as4e1c0bd6
To: <sip:[email protected]:5060>
Contact: <sip:[email protected]>
Call-ID: [email protected]
CSeq: 102 INVITE
User-Agent: packetrino
Max-Forwards: 70
Date: Tue, 10 Jul 2018 21:59:26 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Type: application/sdp
Content-Length: 334

v=0
o=root 15378 15378 IN IP4 66.241.99.27
s=session
c=IN IP4 66.241.99.27
t=0 0
m=audio 17160 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

[2018-07-10 14:59:26] NOTICE[14481]: res_pjsip/pjsip_distributor.c:649 log_failed_request: Request 'INVITE' from '"6503252100" <sip:[email protected]>' failed for '66.241.99.27:5060' (callid: [email protected]) - No matching endpoint found

Calling 200 -> 400:

perk*CLI> pjsip set logger on
PJSIP Logging enabled
<--- Received SIP request (991 bytes) from UDP:192.168.71.5:5062 --->
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.71.5:5062;branch=z9hG4bK92a9de25630a9198
From: "Gerald Rosenberg" <sip:[email protected]>;tag=be635af7da959ee6
To: <sip:[email protected]>
Contact: <sip:[email protected]:5062;transport=udp>
Supported: replaces, timer, path
P-Early-Media: Supported
Call-ID: [email protected]
CSeq: 57889 INVITE
User-Agent: Grandstream GXP2000 1.2.5.3
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
Content-Type: application/sdp
Content-Length: 403

v=0
o=200 8000 8000 IN IP4 192.168.71.5
s=SIP Call
c=IN IP4 192.168.71.5
t=0 0
m=audio 5048 RTP/AVP 18 0 8 2 4 9 97 3 101
a=sendrecv
a=rtpmap:18 G729/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:9 G722/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=20
a=rtpmap:3 GSM/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11

<--- Transmitting SIP response (521 bytes) to UDP:192.168.71.5:5062 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.71.5:5062;rport=5062;received=192.168.71.5;branch=z9hG4bK92a9de25630a9198
Call-ID: [email protected]
From: "Gerald Rosenberg" <sip:[email protected]>;tag=be635af7da959ee6
To: <sip:[email protected]>;tag=z9hG4bK92a9de25630a9198
CSeq: 57889 INVITE
WWW-Authenticate: Digest  realm="asterisk",nonce="1531260599/4e8a92be6d87a693990f174f39cb130c",opaque="54438cf12a93bee4",algorithm=md5,qop="auth"
Server: FPBX-14.0.3.6(13.19.1)
Content-Length:  0


<--- Received SIP request (534 bytes) from UDP:192.168.71.5:5062 --->
ACK sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.71.5:5062;branch=z9hG4bK92a9de25630a9198
From: "Gerald Rosenberg" <sip:[email protected]>;tag=be635af7da959ee6
To: <sip:[email protected]>;tag=z9hG4bK92a9de25630a9198
Contact: <sip:[email protected]:5062;transport=udp>
Supported: path
Call-ID: [email protected]
CSeq: 57889 ACK
User-Agent: Grandstream GXP2000 1.2.5.3
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
Content-Length: 0


<--- Received SIP request (1271 bytes) from UDP:192.168.71.5:5062 --->
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.71.5:5062;branch=z9hG4bK367045d03b785681
From: "Gerald Rosenberg" <sip:[email protected]>;tag=be635af7da959ee6
To: <sip:[email protected]>
Contact: <sip:[email protected]:5062;transport=udp>
Supported: replaces, timer, path
P-Early-Media: Supported
Authorization: Digest username="200", realm="asterisk", algorithm=MD5, uri="sip:[email protected]", qop=auth, nc=00000001, cnonce="f0c123e8ef8aab66", opaque="54438cf12a93bee4", nonce="1531260599/4e8a92be6d87a693990f174f39cb130c", response="ac0bbe254b5f7a86f0a3296b26083b59"
Call-ID: [email protected]
CSeq: 57890 INVITE
User-Agent: Grandstream GXP2000 1.2.5.3
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
Content-Type: application/sdp
Content-Length: 403

v=0
o=200 8000 8001 IN IP4 192.168.71.5
s=SIP Call
c=IN IP4 192.168.71.5
t=0 0
m=audio 5048 RTP/AVP 18 0 8 2 4 9 97 3 101
a=sendrecv
a=rtpmap:18 G729/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:9 G722/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=20
a=rtpmap:3 GSM/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11

  == Setting global variable 'SIPDOMAIN' to '192.168.122.67'
<--- Transmitting SIP response (340 bytes) to UDP:192.168.71.5:5062 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.71.5:5062;rport=5062;received=192.168.71.5;branch=z9hG4bK367045d03b785681
Call-ID: [email protected]
From: "Gerald Rosenberg" <sip:[email protected]>;tag=be635af7da959ee6
To: <sip:[email protected]>
CSeq: 57890 INVITE
Server: FPBX-14.0.3.6(13.19.1)
Content-Length:  0


  == Using SIP RTP Audio TOS bits 184
  == Using SIP RTP Audio TOS bits 184 in TCLASS field.
  == Using SIP RTP Audio CoS mark 5
    -- Executing [3492330@from-internal:1] Macro("PJSIP/200-00000016", "user-callerid,LIMIT,EXTERNAL,") in new stack
    -- Executing [s@macro-user-callerid:1] Set("PJSIP/200-00000016", "TOUCH_MONITOR=1531260599.47") in new stack
    -- Executing [s@macro-user-callerid:2] Set("PJSIP/200-00000016", "AMPUSER=200") in new stack
    -- Executing [s@macro-user-callerid:3] GotoIf("PJSIP/200-00000016", "0?report") in new stack
    -- Executing [s@macro-user-callerid:4] ExecIf("PJSIP/200-00000016", "1?Set(REALCALLERIDNUM=200)") in new stack
    -- Executing [s@macro-user-callerid:5] Set("PJSIP/200-00000016", "AMPUSER=200") in new stack
    -- Executing [s@macro-user-callerid:6] GotoIf("PJSIP/200-00000016", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:7] Set("PJSIP/200-00000016", "AMPUSERCIDNAME=NewTechLaw") in new stack
    -- Executing [s@macro-user-callerid:8] ExecIf("PJSIP/200-00000016", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
    -- Executing [s@macro-user-callerid:9] GotoIf("PJSIP/200-00000016", "0?report") in new stack
    -- Executing [s@macro-user-callerid:10] Set("PJSIP/200-00000016", "AMPUSERCID=200") in new stack
    -- Executing [s@macro-user-callerid:11] Set("PJSIP/200-00000016", "__DIAL_OPTIONS=HhTtr") in new stack
    -- Executing [s@macro-user-callerid:12] Set("PJSIP/200-00000016", "CALLERID(all)="NewTechLaw" <200>") in new stack
    -- Executing [s@macro-user-callerid:13] GotoIf("PJSIP/200-00000016", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:14] ExecIf("PJSIP/200-00000016", "1?Set(GROUP(concurrency_limit)=200)") in new stack
    -- Executing [s@macro-user-callerid:15] ExecIf("PJSIP/200-00000016", "0?Set(CHANNEL(language)=)") in new stack
    -- Executing [s@macro-user-callerid:16] NoOp("PJSIP/200-00000016", "Macro Depth is 1") in new stack
    -- Executing [s@macro-user-callerid:17] GotoIf("PJSIP/200-00000016", "1?report2:macroerror") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] GotoIf("PJSIP/200-00000016", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,37)
    -- Executing [s@macro-user-callerid:37] Set("PJSIP/200-00000016", "CALLERID(number)=200") in new stack
    -- Executing [s@macro-user-callerid:38] Set("PJSIP/200-00000016", "CALLERID(name)=NewTechLaw") in new stack
    -- Executing [s@macro-user-callerid:39] GotoIf("PJSIP/200-00000016", "0?cnum") in new stack
    -- Executing [s@macro-user-callerid:40] Set("PJSIP/200-00000016", "CDR(cnam)=NewTechLaw") in new stack
    -- Executing [s@macro-user-callerid:41] Set("PJSIP/200-00000016", "CDR(cnum)=200") in new stack
    -- Executing [s@macro-user-callerid:42] Set("PJSIP/200-00000016", "CHANNEL(language)=en") in new stack
    -- Executing [3492330@from-internal:2] Gosub("PJSIP/200-00000016", "sub-record-check,s,1(out,3492330,dontcare)") in new stack
    -- Executing [s@sub-record-check:1] GotoIf("PJSIP/200-00000016", "0?initialized") in new stack
    -- Executing [s@sub-record-check:2] Set("PJSIP/200-00000016", "__REC_STATUS=INITIALIZED") in new stack
    -- Executing [s@sub-record-check:3] Set("PJSIP/200-00000016", "NOW=1531260599") in new stack
    -- Executing [s@sub-record-check:4] Set("PJSIP/200-00000016", "__DAY=10") in new stack
    -- Executing [s@sub-record-check:5] Set("PJSIP/200-00000016", "__MONTH=07") in new stack
    -- Executing [s@sub-record-check:6] Set("PJSIP/200-00000016", "__YEAR=2018") in new stack
    -- Executing [s@sub-record-check:7] Set("PJSIP/200-00000016", "__TIMESTR=20180710-150959") in new stack
    -- Executing [s@sub-record-check:8] Set("PJSIP/200-00000016", "__FROMEXTEN=200") in new stack
    -- Executing [s@sub-record-check:9] Set("PJSIP/200-00000016", "__MON_FMT=wav") in new stack
    -- Executing [s@sub-record-check:10] NoOp("PJSIP/200-00000016", "Recordings initialized") in new stack
    -- Executing [s@sub-record-check:11] ExecIf("PJSIP/200-00000016", "0?Set(ARG3=dontcare)") in new stack
    -- Executing [s@sub-record-check:12] Set("PJSIP/200-00000016", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [s@sub-record-check:13] ExecIf("PJSIP/200-00000016", "0?Set(REC_STATUS=NO)") in new stack
    -- Executing [s@sub-record-check:14] GotoIf("PJSIP/200-00000016", "3?checkaction") in new stack
    -- Goto (sub-record-check,s,17)
    -- Executing [s@sub-record-check:17] GotoIf("PJSIP/200-00000016", "1?sub-record-check,out,1") in new stack
    -- Goto (sub-record-check,out,1)
    -- Executing [out@sub-record-check:1] NoOp("PJSIP/200-00000016", "Outbound Recording Check from 200 to 3492330") in new stack
    -- Executing [out@sub-record-check:2] Set("PJSIP/200-00000016", "RECMODE=dontcare") in new stack
    -- Executing [out@sub-record-check:3] ExecIf("PJSIP/200-00000016", "1?Goto(routewins)") in new stack
    -- Goto (sub-record-check,out,7)
    -- Executing [out@sub-record-check:7] Gosub("PJSIP/200-00000016", "recordcheck,1(dontcare,out,3492330)") in new stack
    -- Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/200-00000016", "Starting recording check against dontcare") in new stack
    -- Executing [recordcheck@sub-record-check:2] Goto("PJSIP/200-00000016", "dontcare") in new stack
    -- Goto (sub-record-check,recordcheck,3)
    -- Executing [recordcheck@sub-record-check:3] Return("PJSIP/200-00000016", "") in new stack
    -- Executing [out@sub-record-check:8] Return("PJSIP/200-00000016", "") in new stack
    -- Executing [3492330@from-internal:3] ExecIf("PJSIP/200-00000016", "0 ?Set(CDR(accountcode)=)") in new stack
    -- Executing [3492330@from-internal:4] Set("PJSIP/200-00000016", "MOHCLASS=default") in new stack
    -- Executing [3492330@from-internal:5] Set("PJSIP/200-00000016", "_NODEST=") in new stack
    -- Executing [3492330@from-internal:6] Macro("PJSIP/200-00000016", "dialout-trunk,1,16503492330,,off") in new stack
    -- Executing [s@macro-dialout-trunk:1] Set("PJSIP/200-00000016", "DIAL_TRUNK=1") in new stack
    -- Executing [s@macro-dialout-trunk:2] ExecIf("PJSIP/200-00000016", "0?Set(DIAL_OPTIONS=Hhtr)") in new stack
    -- Executing [s@macro-dialout-trunk:3] GosubIf("PJSIP/200-00000016", "0?sub-pincheck,s,1()") in new stack
    -- Executing [s@macro-dialout-trunk:4] ExecIf("PJSIP/200-00000016", "0?Set(CALLERID(num)=200)") in new stack
    -- Executing [s@macro-dialout-trunk:5] GotoIf("PJSIP/200-00000016", "0?disabletrunk,1") in new stack
    -- Executing [s@macro-dialout-trunk:6] Set("PJSIP/200-00000016", "DIAL_NUMBER=16503492330") in new stack
    -- Executing [s@macro-dialout-trunk:7] Set("PJSIP/200-00000016", "DIAL_TRUNK_OPTIONS=HhTtr") in new stack
    -- Executing [s@macro-dialout-trunk:8] Set("PJSIP/200-00000016", "OUTBOUND_GROUP=OUT_1") in new stack
    -- Executing [s@macro-dialout-trunk:9] Set("PJSIP/200-00000016", "DIAL_TRUNK_OPTIONS=T") in new stack
    -- Executing [s@macro-dialout-trunk:10] GotoIf("PJSIP/200-00000016", "0?nomax") in new stack
    -- Executing [s@macro-dialout-trunk:11] GotoIf("PJSIP/200-00000016", "0?chanfull") in new stack
    -- Executing [s@macro-dialout-trunk:12] GotoIf("PJSIP/200-00000016", "0?skipoutcid") in new stack
    -- Executing [s@macro-dialout-trunk:13] Macro("PJSIP/200-00000016", "outbound-callerid,1") in new stack
    -- Executing [s@macro-outbound-callerid:1] NoOp("PJSIP/200-00000016", "200") in new stack
    -- Executing [s@macro-outbound-callerid:2] NoOp("PJSIP/200-00000016", "") in new stack
    -- Executing [s@macro-outbound-callerid:3] NoOp("PJSIP/200-00000016", "off") in new stack
    -- Executing [s@macro-outbound-callerid:4] ExecIf("PJSIP/200-00000016", "0?Set(CALLERPRES(name-pres)=)") in new stack
    -- Executing [s@macro-outbound-callerid:5] ExecIf("PJSIP/200-00000016", "0?Set(CALLERPRES(num-pres)=)") in new stack
    -- Executing [s@macro-outbound-callerid:6] ExecIf("PJSIP/200-00000016", "0?Set(REALCALLERIDNUM=200)") in new stack
    -- Executing [s@macro-outbound-callerid:7] ExecIf("PJSIP/200-00000016", "0?Set(AMPUSER=200)") in new stack
    -- Executing [s@macro-outbound-callerid:8] GotoIf("PJSIP/200-00000016", "1?normcid") in new stack
    -- Goto (macro-outbound-callerid,s,12)
    -- Executing [s@macro-outbound-callerid:12] Set("PJSIP/200-00000016", "USEROUTCID=") in new stack
    -- Executing [s@macro-outbound-callerid:13] Set("PJSIP/200-00000016", "EMERGENCYCID=") in new stack
    -- Executing [s@macro-outbound-callerid:14] Set("PJSIP/200-00000016", "TRUNKOUTCID=Gerald<6507031724>") in new stack
    -- Executing [s@macro-outbound-callerid:15] GotoIf("PJSIP/200-00000016", "1?trunkcid") in new stack
    -- Goto (macro-outbound-callerid,s,20)
    -- Executing [s@macro-outbound-callerid:20] ExecIf("PJSIP/200-00000016", "1?Set(CALLERID(all)=Gerald<6507031724>)") in new stack
    -- Executing [s@macro-outbound-callerid:21] ExecIf("PJSIP/200-00000016", "0?Set(CALLERID(all)=)") in new stack
    -- Executing [s@macro-outbound-callerid:22] ExecIf("PJSIP/200-00000016", "0?Set(CALLERID(all)=)") in new stack
    -- Executing [s@macro-outbound-callerid:23] ExecIf("PJSIP/200-00000016", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:24] ExecIf("PJSIP/200-00000016", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:25] Set("PJSIP/200-00000016", "CDR(outbound_cnum)=6507031724") in new stack
    -- Executing [s@macro-outbound-callerid:26] Set("PJSIP/200-00000016", "CDR(outbound_cnam)=Gerald") in new stack
    -- Executing [s@macro-dialout-trunk:14] GosubIf("PJSIP/200-00000016", "0?sub-flp-1,s,1()") in new stack
    -- Executing [s@macro-dialout-trunk:15] Set("PJSIP/200-00000016", "OUTNUM=16503492330") in new stack
    -- Executing [s@macro-dialout-trunk:16] Set("PJSIP/200-00000016", "custom=SIP/vitel-outbound") in new stack
    -- Executing [s@macro-dialout-trunk:17] ExecIf("PJSIP/200-00000016", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)") in new stack
    -- Executing [s@macro-dialout-trunk:18] ExecIf("PJSIP/200-00000016", "0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))") in new stack
    -- Executing [s@macro-dialout-trunk:19] Macro("PJSIP/200-00000016", "dialout-trunk-predial-hook,") in new stack
    -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("PJSIP/200-00000016", "") in new stack
    -- Executing [s@macro-dialout-trunk:20] GotoIf("PJSIP/200-00000016", "0?skipcrm") in new stack
    -- Executing [s@macro-dialout-trunk:21] Set("PJSIP/200-00000016", "__CRM_DIRECTION=OUTBOUND") in new stack
    -- Executing [s@macro-dialout-trunk:22] Set("PJSIP/200-00000016", "__CRM_DESTINATION=16503492330") in new stack
    -- Executing [s@macro-dialout-trunk:23] Set("PJSIP/200-00000016", "__CRM_SOURCE=200") in new stack
    -- Executing [s@macro-dialout-trunk:24] AGI("PJSIP/200-00000016", "sangomacrm.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
    -- <PJSIP/200-00000016>AGI Script sangomacrm.agi completed, returning 0
    -- Executing [s@macro-dialout-trunk:25] Set("PJSIP/200-00000016", "CHANNEL(hangup_handler_push)=crm-hangup,s,1") in new stack
    -- Executing [s@macro-dialout-trunk:26] NoOp("PJSIP/200-00000016", "CRM Finished") in new stack
    -- Executing [s@macro-dialout-trunk:27] GotoIf("PJSIP/200-00000016", "0?bypass,1") in new stack
    -- Executing [s@macro-dialout-trunk:28] ExecIf("PJSIP/200-00000016", "1?Set(CONNECTEDLINE(num,i)=16503492330)") in new stack
    -- Executing [s@macro-dialout-trunk:29] ExecIf("PJSIP/200-00000016", "1?Set(CONNECTEDLINE(name,i)=CID:6507031724)") in new stack
    -- Executing [s@macro-dialout-trunk:30] ExecIf("PJSIP/200-00000016", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)6507031724)") in new stack
    -- Executing [s@macro-dialout-trunk:31] GotoIf("PJSIP/200-00000016", "0?customtrunk") in new stack
    -- Executing [s@macro-dialout-trunk:32] Dial("PJSIP/200-00000016", "SIP/vitel-outbound/16503492330,300,Tb(func-apply-sipheaders^s^1)") in new stack
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- SIP/vitel-outbound-00000013 Internal Gosub(func-apply-sipheaders,s,1) start
    -- Executing [s@func-apply-sipheaders:1] ExecIf("SIP/vitel-outbound-00000013", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
    -- Executing [s@func-apply-sipheaders:2] NoOp("SIP/vitel-outbound-00000013", "Applying SIP Headers to channel") in new stack
    -- Executing [s@func-apply-sipheaders:3] Set("SIP/vitel-outbound-00000013", "SIPHEADERKEYS=") in new stack
    -- Executing [s@func-apply-sipheaders:4] ExecIf("SIP/vitel-outbound-00000013", "0?Set(Rheader=1)") in new stack
    -- Executing [s@func-apply-sipheaders:5] While("SIP/vitel-outbound-00000013", "0") in new stack
    -- Jumping to priority 9
    -- Executing [s@func-apply-sipheaders:10] ExecIf("SIP/vitel-outbound-00000013", "0?SIPRemoveHeader(Alert-Info:)") in new stack
    -- Executing [s@func-apply-sipheaders:11] ExecIf("SIP/vitel-outbound-00000013", "0?Set(PJSIP_HEADER(remove,Alert-Info)=)") in new stack
    -- Executing [s@func-apply-sipheaders:12] Return("SIP/vitel-outbound-00000013", "") in new stack
  == Spawn extension (from-trunk-sip-vitel-outbound, 3492330, 1) exited non-zero on 'SIP/vitel-outbound-00000013'
    -- SIP/vitel-outbound-00000013 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
    -- Called SIP/vitel-outbound/16503492330
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
       > 0x7fc53839c4e0 -- Strict RTP learning after remote address set to: 66.241.99.27:19916
    -- Executing [6503492330@from-trunk:1] Set("SIP/vitel-inbound-00000014", "__DIRECTION=INBOUND") in new stack
    -- Executing [6503492330@from-trunk:2] Gosub("SIP/vitel-inbound-00000014", "sub-record-check,s,1(in,6503492330,dontcare)") in new stack
    -- Executing [s@sub-record-check:1] GotoIf("SIP/vitel-inbound-00000014", "0?initialized") in new stack
    -- Executing [s@sub-record-check:2] Set("SIP/vitel-inbound-00000014", "__REC_STATUS=INITIALIZED") in new stack
    -- Executing [s@sub-record-check:3] Set("SIP/vitel-inbound-00000014", "NOW=1531260601") in new stack
    -- Executing [s@sub-record-check:4] Set("SIP/vitel-inbound-00000014", "__DAY=10") in new stack
    -- Executing [s@sub-record-check:5] Set("SIP/vitel-inbound-00000014", "__MONTH=07") in new stack
    -- Executing [s@sub-record-check:6] Set("SIP/vitel-inbound-00000014", "__YEAR=2018") in new stack
    -- Executing [s@sub-record-check:7] Set("SIP/vitel-inbound-00000014", "__TIMESTR=20180710-151001") in new stack
    -- Executing [s@sub-record-check:8] Set("SIP/vitel-inbound-00000014", "__FROMEXTEN=unknown") in new stack
    -- Executing [s@sub-record-check:9] Set("SIP/vitel-inbound-00000014", "__MON_FMT=wav") in new stack
    -- Executing [s@sub-record-check:10] NoOp("SIP/vitel-inbound-00000014", "Recordings initialized") in new stack
    -- Executing [s@sub-record-check:11] ExecIf("SIP/vitel-inbound-00000014", "0?Set(ARG3=dontcare)") in new stack
    -- Executing [s@sub-record-check:12] Set("SIP/vitel-inbound-00000014", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [s@sub-record-check:13] ExecIf("SIP/vitel-inbound-00000014", "0?Set(REC_STATUS=NO)") in new stack
    -- Executing [s@sub-record-check:14] GotoIf("SIP/vitel-inbound-00000014", "2?checkaction") in new stack
    -- Goto (sub-record-check,s,17)
    -- Executing [s@sub-record-check:17] GotoIf("SIP/vitel-inbound-00000014", "1?sub-record-check,in,1") in new stack
    -- Goto (sub-record-check,in,1)
    -- Executing [in@sub-record-check:1] NoOp("SIP/vitel-inbound-00000014", "Inbound Recording Check to 6503492330") in new stack
    -- Executing [in@sub-record-check:2] Set("SIP/vitel-inbound-00000014", "FROMEXTEN=unknown") in new stack
    -- Executing [in@sub-record-check:3] ExecIf("SIP/vitel-inbound-00000014", "10?Set(FROMEXTEN=6503252100)") in new stack
    -- Executing [in@sub-record-check:4] Gosub("SIP/vitel-inbound-00000014", "recordcheck,1(dontcare,in,6503492330)") in new stack
    -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/vitel-inbound-00000014", "Starting recording check against dontcare") in new stack
    -- Executing [recordcheck@sub-record-check:2] Goto("SIP/vitel-inbound-00000014", "dontcare") in new stack
    -- Goto (sub-record-check,recordcheck,3)
    -- Executing [recordcheck@sub-record-check:3] Return("SIP/vitel-inbound-00000014", "") in new stack
    -- Executing [in@sub-record-check:5] Return("SIP/vitel-inbound-00000014", "") in new stack
    -- Executing [6503492330@from-trunk:3] Set("SIP/vitel-inbound-00000014", "CHANNEL(tonezone)=us") in new stack
    -- Executing [6503492330@from-trunk:4] Set("SIP/vitel-inbound-00000014", "__FROM_DID=6503492330") in new stack
    -- Executing [6503492330@from-trunk:5] Set("SIP/vitel-inbound-00000014", "returnhere=1") in new stack
    -- Executing [6503492330@from-trunk:6] Gosub("SIP/vitel-inbound-00000014", "app-blacklist-check,s,1()") in new stack
    -- Executing [s@app-blacklist-check:1] GotoIf("SIP/vitel-inbound-00000014", "0?blacklisted") in new stack
    -- Executing [s@app-blacklist-check:2] Set("SIP/vitel-inbound-00000014", "CALLED_BLACKLIST=1") in new stack
    -- Executing [s@app-blacklist-check:3] Return("SIP/vitel-inbound-00000014", "") in new stack
    -- Executing [6503492330@from-trunk:7] Set("SIP/vitel-inbound-00000014", "CDR(did)=6503492330") in new stack
    -- Executing [6503492330@from-trunk:8] GotoIf("SIP/vitel-inbound-00000014", "0?") in new stack
    -- Executing [6503492330@from-trunk:9] ExecIf("SIP/vitel-inbound-00000014", "0 ?Set(CALLERID(name)=6503252100)") in new stack
    -- Executing [6503492330@from-trunk:10] Set("SIP/vitel-inbound-00000014", "__MOHCLASS=") in new stack
    -- Executing [6503492330@from-trunk:11] Set("SIP/vitel-inbound-00000014", "__REVERSAL_REJECT=TRUE") in new stack
    -- Executing [6503492330@from-trunk:12] GotoIf("SIP/vitel-inbound-00000014", "0?post-reverse-charge") in new stack
[2018-07-10 15:10:01] WARNING[29997][C-00000017]: func_channel.c:465 func_channel_read: Unknown or unavailable item requested: 'reversecharge'
    -- Executing [6503492330@from-trunk:13] GotoIf("SIP/vitel-inbound-00000014", "0?macro-hangupcall") in new stack
    -- Executing [6503492330@from-trunk:14] NoOp("SIP/vitel-inbound-00000014", "") in new stack
    -- Executing [6503492330@from-trunk:15] Set("SIP/vitel-inbound-00000014", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
    -- Executing [6503492330@from-trunk:16] Set("SIP/vitel-inbound-00000014", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
    -- Executing [6503492330@from-trunk:17] Set("SIP/vitel-inbound-00000014", "CALLERID(name-pres)=allowed_not_screened") in new stack
    -- Executing [6503492330@from-trunk:18] Set("SIP/vitel-inbound-00000014", "CALLERID(num-pres)=allowed_not_screened") in new stack
    -- Executing [6503492330@from-trunk:19] NoOp("SIP/vitel-inbound-00000014", "CallerID Entry Point") in new stack
    -- Executing [6503492330@from-trunk:20] Set("SIP/vitel-inbound-00000014", "__CRM_DIRECTION=INBOUND") in new stack
    -- Executing [6503492330@from-trunk:21] Set("SIP/vitel-inbound-00000014", "__CRM_SOURCE=6503252100") in new stack
    -- Executing [6503492330@from-trunk:22] Set("SIP/vitel-inbound-00000014", "__CRM_LINKEDID=1531260601.49") in new stack
    -- Executing [6503492330@from-trunk:23] ExecIf("SIP/vitel-inbound-00000014", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
    -- Executing [6503492330@from-trunk:24] Goto("SIP/vitel-inbound-00000014", "from-did-direct,400,1") in new stack
    -- Goto (from-did-direct,400,1)
    -- Executing [400@from-did-direct:1] GotoIf("SIP/vitel-inbound-00000014", "1?ext-local,400,1:followme-check,400,1") in new stack
    -- Goto (ext-local,400,1)
    -- Executing [400@ext-local:1] Set("SIP/vitel-inbound-00000014", "__RINGTIMER=15") in new stack
    -- Executing [400@ext-local:2] Macro("SIP/vitel-inbound-00000014", "exten-vm,400,400,0,0,0") in new stack
    -- Executing [s@macro-exten-vm:1] Macro("SIP/vitel-inbound-00000014", "user-callerid,") in new stack
    -- Executing [s@macro-user-callerid:1] Set("SIP/vitel-inbound-00000014", "TOUCH_MONITOR=1531260601.49") in new stack
    -- Executing [s@macro-user-callerid:2] Set("SIP/vitel-inbound-00000014", "AMPUSER=6503252100") in new stack
    -- Executing [s@macro-user-callerid:3] GotoIf("SIP/vitel-inbound-00000014", "0?report") in new stack
    -- Executing [s@macro-user-callerid:4] ExecIf("SIP/vitel-inbound-00000014", "1?Set(REALCALLERIDNUM=6503252100)") in new stack
    -- Executing [s@macro-user-callerid:5] Set("SIP/vitel-inbound-00000014", "AMPUSER=") in new stack
    -- Executing [s@macro-user-callerid:6] GotoIf("SIP/vitel-inbound-00000014", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:7] Set("SIP/vitel-inbound-00000014", "AMPUSERCIDNAME=") in new stack
    -- Executing [s@macro-user-callerid:8] ExecIf("SIP/vitel-inbound-00000014", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
    -- Executing [s@macro-user-callerid:9] GotoIf("SIP/vitel-inbound-00000014", "1?report") in new stack
    -- Goto (macro-user-callerid,s,16)
    -- Executing [s@macro-user-callerid:16] NoOp("SIP/vitel-inbound-00000014", "Macro Depth is 2") in new stack
    -- Executing [s@macro-user-callerid:17] GotoIf("SIP/vitel-inbound-00000014", "1?report2:macroerror") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] GotoIf("SIP/vitel-inbound-00000014", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:19] ExecIf("SIP/vitel-inbound-00000014", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
    -- Executing [s@macro-user-callerid:20] Set("SIP/vitel-inbound-00000014", "__TTL=64") in new stack
    -- Executing [s@macro-user-callerid:21] GotoIf("SIP/vitel-inbound-00000014", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,37)
    -- Executing [s@macro-user-callerid:37] Set("SIP/vitel-inbound-00000014", "CALLERID(number)=6503252100") in new stack
    -- Executing [s@macro-user-callerid:38] Set("SIP/vitel-inbound-00000014", "CALLERID(name)=6503252100") in new stack
    -- Executing [s@macro-user-callerid:39] GotoIf("SIP/vitel-inbound-00000014", "0?cnum") in new stack
    -- Executing [s@macro-user-callerid:40] Set("SIP/vitel-inbound-00000014", "CDR(cnam)=6503252100") in new stack
    -- Executing [s@macro-user-callerid:41] Set("SIP/vitel-inbound-00000014", "CDR(cnum)=6503252100") in new stack
    -- Executing [s@macro-user-callerid:42] Set("SIP/vitel-inbound-00000014", "CHANNEL(language)=en") in new stack
    -- Executing [s@macro-exten-vm:2] Set("SIP/vitel-inbound-00000014", "RingGroupMethod=none") in new stack
    -- Executing [s@macro-exten-vm:3] Set("SIP/vitel-inbound-00000014", "__EXTTOCALL=400") in new stack
    -- Executing [s@macro-exten-vm:4] Set("SIP/vitel-inbound-00000014", "__PICKUPMARK=400") in new stack
    -- Executing [s@macro-exten-vm:5] Set("SIP/vitel-inbound-00000014", "RT=15") in new stack
    -- Executing [s@macro-exten-vm:6] ExecIf("SIP/vitel-inbound-00000014", "0?Macro(vm,400,DIRECTDIAL,)") in new stack
    -- Executing [s@macro-exten-vm:7] ExecIf("SIP/vitel-inbound-00000014", "0?MacroExit()") in new stack
    -- Executing [s@macro-exten-vm:8] ExecIf("SIP/vitel-inbound-00000014", "0?Gosub(ext-intercom,*80400,1())") in new stack
    -- Executing [s@macro-exten-vm:9] ExecIf("SIP/vitel-inbound-00000014", "0?MacroExit()") in new stack
    -- Executing [s@macro-exten-vm:10] ExecIf("SIP/vitel-inbound-00000014", "0?ChanSpy(PJSIP/400,q)") in new stack
    -- Executing [s@macro-exten-vm:11] ExecIf("SIP/vitel-inbound-00000014", "0?MacroExit()") in new stack
[2018-07-10 15:10:01] ERROR[29997][C-00000017]: res_pjsip_header_funcs.c:461 func_read_header: This function requires a PJSIP channel.
    -- Executing [s@macro-exten-vm:12] ExecIf("SIP/vitel-inbound-00000014", "0?Macro(vm,400,DIRECTDIAL,)") in new stack
[2018-07-10 15:10:01] ERROR[29997][C-00000017]: res_pjsip_header_funcs.c:461 func_read_header: This function requires a PJSIP channel.
[2018-07-10 15:10:01] ERROR[29997][C-00000017]: res_pjsip_header_funcs.c:461 func_read_header: This function requires a PJSIP channel.
    -- Executing [s@macro-exten-vm:13] ExecIf("SIP/vitel-inbound-00000014", "0?MacroExit()") in new stack
[2018-07-10 15:10:01] ERROR[29997][C-00000017]: res_pjsip_header_funcs.c:461 func_read_header: This function requires a PJSIP channel.
[2018-07-10 15:10:01] ERROR[29997][C-00000017]: res_pjsip_header_funcs.c:461 func_read_header: This function requires a PJSIP channel.
    -- Executing [s@macro-exten-vm:14] ExecIf("SIP/vitel-inbound-00000014", "0?Gosub(ext-intercom,*80400,1())") in new stack
[2018-07-10 15:10:01] ERROR[29997][C-00000017]: res_pjsip_header_funcs.c:461 func_read_header: This function requires a PJSIP channel.
[2018-07-10 15:10:01] ERROR[29997][C-00000017]: res_pjsip_header_funcs.c:461 func_read_header: This function requires a PJSIP channel.
    -- Executing [s@macro-exten-vm:15] ExecIf("SIP/vitel-inbound-00000014", "0?MacroExit()") in new stack
[2018-07-10 15:10:01] ERROR[29997][C-00000017]: res_pjsip_header_funcs.c:461 func_read_header: This function requires a PJSIP channel.
[2018-07-10 15:10:01] ERROR[29997][C-00000017]: res_pjsip_header_funcs.c:461 func_read_header: This function requires a PJSIP channel.
    -- Executing [s@macro-exten-vm:16] ExecIf("SIP/vitel-inbound-00000014", "0?ChanSpy(PJSIP/400,q)") in new stack
[2018-07-10 15:10:01] ERROR[29997][C-00000017]: res_pjsip_header_funcs.c:461 func_read_header: This function requires a PJSIP channel.
[2018-07-10 15:10:01] ERROR[29997][C-00000017]: res_pjsip_header_funcs.c:461 func_read_header: This function requires a PJSIP channel.

Continued:

-- Executing [s@macro-exten-vm:17] ExecIf("SIP/vitel-inbound-00000014", "0?MacroExit()") in new stack

[2018-07-10 15:10:01] ERROR[29997][C-00000017]: res_pjsip_header_funcs.c:461 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:18] Gosub(“SIP/vitel-inbound-00000014”, “sub-record-check,s,1(exten,400,dontcare)”) in new stack
– Executing [s@sub-record-check:1] GotoIf(“SIP/vitel-inbound-00000014”, “10?initialized”) in new stack
– Goto (sub-record-check,s,10)
– Executing [s@sub-record-check:10] NoOp(“SIP/vitel-inbound-00000014”, “Recordings initialized”) in new stack
– Executing [s@sub-record-check:11] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [s@sub-record-check:12] Set(“SIP/vitel-inbound-00000014”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [s@sub-record-check:13] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [s@sub-record-check:14] GotoIf(“SIP/vitel-inbound-00000014”, “5?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [s@sub-record-check:17] GotoIf(“SIP/vitel-inbound-00000014”, “1?sub-record-check,exten,1”) in new stack
– Goto (sub-record-check,exten,1)
– Executing [exten@sub-record-check:1] NoOp(“SIP/vitel-inbound-00000014”, “Exten Recording Check between 6503252100 and 400”) in new stack
– Executing [exten@sub-record-check:2] Set(“SIP/vitel-inbound-00000014”, “CALLTYPE=external”) in new stack
– Executing [exten@sub-record-check:3] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(CALLTYPE=)”) in new stack
– Executing [exten@sub-record-check:4] Set(“SIP/vitel-inbound-00000014”, “CALLEE=dontcare”) in new stack
– Executing [exten@sub-record-check:5] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(CALLEE=dontcare)”) in new stack
– Executing [exten@sub-record-check:6] GotoIf(“SIP/vitel-inbound-00000014”, “1?callee”) in new stack
– Goto (sub-record-check,exten,11)
– Executing [exten@sub-record-check:11] Gosub(“SIP/vitel-inbound-00000014”, “recordcheck,1(dontcare,external,400)”) in new stack
– Executing [recordcheck@sub-record-check:1] NoOp(“SIP/vitel-inbound-00000014”, “Starting recording check against dontcare”) in new stack
– Executing [recordcheck@sub-record-check:2] Goto(“SIP/vitel-inbound-00000014”, “dontcare”) in new stack
– Goto (sub-record-check,recordcheck,3)
– Executing [recordcheck@sub-record-check:3] Return(“SIP/vitel-inbound-00000014”, “”) in new stack
– Executing [exten@sub-record-check:12] Return(“SIP/vitel-inbound-00000014”, “”) in new stack
– Executing [s@macro-exten-vm:19] GotoIf(“SIP/vitel-inbound-00000014”, “1?macrodial”) in new stack
– Goto (macro-exten-vm,s,25)
– Executing [s@macro-exten-vm:25] GosubIf(“SIP/vitel-inbound-00000014”, “0?clrheader,1()”) in new stack
– Executing [s@macro-exten-vm:26] Macro(“SIP/vitel-inbound-00000014”, “dial-one,15,HhTtr,400”) in new stack
– Executing [s@macro-dial-one:1] Set(“SIP/vitel-inbound-00000014”, “DEXTEN=400”) in new stack
– Executing [s@macro-dial-one:2] Set(“SIP/vitel-inbound-00000014”, “__CRM_SOURCE=6503252100”) in new stack
– Executing [s@macro-dial-one:3] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(__EXTTOCALL=400)”) in new stack
– Executing [s@macro-dial-one:4] Set(“SIP/vitel-inbound-00000014”, “DIALSTATUS_CW=”) in new stack
– Executing [s@macro-dial-one:5] GosubIf(“SIP/vitel-inbound-00000014”, “0?screen,1()”) in new stack
– Executing [s@macro-dial-one:6] GosubIf(“SIP/vitel-inbound-00000014”, “0?cf,1()”) in new stack
– Executing [s@macro-dial-one:7] GotoIf(“SIP/vitel-inbound-00000014”, “1?skip1”) in new stack
– Goto (macro-dial-one,s,10)
– Executing [s@macro-dial-one:10] GotoIf(“SIP/vitel-inbound-00000014”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:11] GotoIf(“SIP/vitel-inbound-00000014”, “0?continue”) in new stack
– Executing [s@macro-dial-one:12] Set(“SIP/vitel-inbound-00000014”, “EXTHASCW=ENABLED”) in new stack
– Executing [s@macro-dial-one:13] GotoIf(“SIP/vitel-inbound-00000014”, “0?next1:cwinusebusy”) in new stack
– Goto (macro-dial-one,s,25)
– Executing [s@macro-dial-one:25] GotoIf(“SIP/vitel-inbound-00000014”, “0?next3:continue”) in new stack
– Goto (macro-dial-one,s,27)
– Executing [s@macro-dial-one:27] GotoIf(“SIP/vitel-inbound-00000014”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:28] GosubIf(“SIP/vitel-inbound-00000014”, “1?dstring,1():dlocal,1()”) in new stack
– Executing [dstring@macro-dial-one:1] Set(“SIP/vitel-inbound-00000014”, “DSTRING=”) in new stack
– Executing [dstring@macro-dial-one:2] Set(“SIP/vitel-inbound-00000014”, “DEVICES=400”) in new stack
– Executing [dstring@macro-dial-one:3] ExecIf(“SIP/vitel-inbound-00000014”, “0?Return()”) in new stack
– Executing [dstring@macro-dial-one:4] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(DEVICES=00)”) in new stack
– Executing [dstring@macro-dial-one:5] Set(“SIP/vitel-inbound-00000014”, “LOOPCNT=1”) in new stack
– Executing [dstring@macro-dial-one:6] Set(“SIP/vitel-inbound-00000014”, “ITER=1”) in new stack
– Executing [dstring@macro-dial-one:7] Set(“SIP/vitel-inbound-00000014”, “THISDIAL=PJSIP/400”) in new stack
– Executing [dstring@macro-dial-one:8] GosubIf(“SIP/vitel-inbound-00000014”, “1?zap2dahdi,1()”) in new stack
– Executing [zap2dahdi@macro-dial-one:1] ExecIf(“SIP/vitel-inbound-00000014”, “0?Return()”) in new stack
– Executing [zap2dahdi@macro-dial-one:2] Set(“SIP/vitel-inbound-00000014”, “NEWDIAL=”) in new stack
– Executing [zap2dahdi@macro-dial-one:3] Set(“SIP/vitel-inbound-00000014”, “LOOPCNT2=1”) in new stack
– Executing [zap2dahdi@macro-dial-one:4] Set(“SIP/vitel-inbound-00000014”, “ITER2=1”) in new stack
– Executing [zap2dahdi@macro-dial-one:5] Set(“SIP/vitel-inbound-00000014”, “THISPART2=PJSIP/400”) in new stack
– Executing [zap2dahdi@macro-dial-one:6] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(THISPART2=DAHDIIP/400)”) in new stack
– Executing [zap2dahdi@macro-dial-one:7] Set(“SIP/vitel-inbound-00000014”, “NEWDIAL=PJSIP/400&”) in new stack
– Executing [zap2dahdi@macro-dial-one:8] Set(“SIP/vitel-inbound-00000014”, “ITER2=2”) in new stack
– Executing [zap2dahdi@macro-dial-one:9] GotoIf(“SIP/vitel-inbound-00000014”, “0?begin2”) in new stack
– Executing [zap2dahdi@macro-dial-one:10] Set(“SIP/vitel-inbound-00000014”, “THISDIAL=PJSIP/400”) in new stack
– Executing [zap2dahdi@macro-dial-one:11] Return(“SIP/vitel-inbound-00000014”, “”) in new stack
– Executing [dstring@macro-dial-one:9] GotoIf(“SIP/vitel-inbound-00000014”, “0?docheck”) in new stack
– Executing [dstring@macro-dial-one:10] NoOp(“SIP/vitel-inbound-00000014”, “Debug: Found PJSIP Destination PJSIP/400”) in new stack
– Executing [dstring@macro-dial-one:11] GotoIf(“SIP/vitel-inbound-00000014”, “0?doset”) in new stack
– Executing [dstring@macro-dial-one:12] NoOp(“SIP/vitel-inbound-00000014”, “Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS”) in new stack
– Executing [dstring@macro-dial-one:13] Set(“SIP/vitel-inbound-00000014”, “THISDIAL=PJSIP/400/sip:[email protected]:5064”) in new stack
– Executing [dstring@macro-dial-one:14] GotoIf(“SIP/vitel-inbound-00000014”, “0?skipset”) in new stack
– Executing [dstring@macro-dial-one:15] Set(“SIP/vitel-inbound-00000014”, “DSTRING=PJSIP/400/sip:[email protected]:5064&”) in new stack
– Executing [dstring@macro-dial-one:16] Set(“SIP/vitel-inbound-00000014”, “ITER=2”) in new stack
– Executing [dstring@macro-dial-one:17] GotoIf(“SIP/vitel-inbound-00000014”, “0?begin”) in new stack
– Executing [dstring@macro-dial-one:18] ExecIf(“SIP/vitel-inbound-00000014”, “0?Return()”) in new stack
– Executing [dstring@macro-dial-one:19] Set(“SIP/vitel-inbound-00000014”, “DSTRING=PJSIP/400/sip:[email protected]:5064”) in new stack
– Executing [dstring@macro-dial-one:20] Return(“SIP/vitel-inbound-00000014”, “”) in new stack
– Executing [s@macro-dial-one:29] GotoIf(“SIP/vitel-inbound-00000014”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:30] GotoIf(“SIP/vitel-inbound-00000014”, “0?skiptrace”) in new stack
– Executing [s@macro-dial-one:31] GosubIf(“SIP/vitel-inbound-00000014”, “1?ctset,1():ctclear,1()”) in new stack
– Executing [ctset@macro-dial-one:1] Set(“SIP/vitel-inbound-00000014”, “DB(CALLTRACE/400)=6503252100”) in new stack
– Executing [ctset@macro-dial-one:2] Return(“SIP/vitel-inbound-00000014”, “”) in new stack
– Executing [s@macro-dial-one:32] Set(“SIP/vitel-inbound-00000014”, “D_OPTIONS=HhTtr”) in new stack
– Executing [s@macro-dial-one:33] GosubIf(“SIP/vitel-inbound-00000014”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
– Executing [s@macro-dial-one:34] NoOp(“SIP/vitel-inbound-00000014”, "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
– Executing [s@macro-dial-one:35] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [s@macro-dial-one:36] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [s@macro-dial-one:37] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [s@macro-dial-one:38] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
– Executing [s@macro-dial-one:39] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
– Executing [s@macro-dial-one:40] GosubIf(“SIP/vitel-inbound-00000014”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
– Executing [s@macro-dial-one:41] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(CHANNEL(musicclass)=)”) in new stack
– Executing [s@macro-dial-one:42] GosubIf(“SIP/vitel-inbound-00000014”, “0?qwait,1()”) in new stack
– Executing [s@macro-dial-one:43] Set(“SIP/vitel-inbound-00000014”, “__CWIGNORE=”) in new stack
– Executing [s@macro-dial-one:44] Set(“SIP/vitel-inbound-00000014”, “__KEEPCID=TRUE”) in new stack
– Executing [s@macro-dial-one:45] GotoIf(“SIP/vitel-inbound-00000014”, “0?usegoto,1”) in new stack
– Executing [s@macro-dial-one:46] GotoIf(“SIP/vitel-inbound-00000014”, “1?godial”) in new stack
– Goto (macro-dial-one,s,51)
– Executing [s@macro-dial-one:51] Macro(“SIP/vitel-inbound-00000014”, “dialout-one-predial-hook,”) in new stack
– Executing [s@macro-dialout-one-predial-hook:1] MacroExit(“SIP/vitel-inbound-00000014”, “”) in new stack
– Executing [s@macro-dial-one:52] ExecIf(“SIP/vitel-inbound-00000014”, “1?Set(D_OPTIONS=HhtrI)”) in new stack
– Executing [s@macro-dial-one:53] NoOp(“SIP/vitel-inbound-00000014”, “”) in new stack
– Executing [s@macro-dial-one:54] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(D_OPTIONS=HhtrIg)”) in new stack
– Executing [s@macro-dial-one:55] Dial(“SIP/vitel-inbound-00000014”, “PJSIP/400/sip:[email protected]:5064,15,HhtrIb(func-apply-sipheaders^s^1)”) in new stack
– PJSIP/400-00000017 Internal Gosub(func-apply-sipheaders,s,1) start
– Executing [s@func-apply-sipheaders:1] ExecIf(“PJSIP/400-00000017”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
– Executing [s@func-apply-sipheaders:2] NoOp(“PJSIP/400-00000017”, “Applying SIP Headers to channel”) in new stack
– Executing [s@func-apply-sipheaders:3] Set(“PJSIP/400-00000017”, “SIPHEADERKEYS=”) in new stack
– Executing [s@func-apply-sipheaders:4] ExecIf(“PJSIP/400-00000017”, “0?Set(Rheader=1)”) in new stack
– Executing [s@func-apply-sipheaders:5] While(“PJSIP/400-00000017”, “0”) in new stack
– Jumping to priority 9
– Executing [s@func-apply-sipheaders:10] ExecIf(“PJSIP/400-00000017”, “0?SIPRemoveHeader(Alert-Info:)”) in new stack
– Executing [s@func-apply-sipheaders:11] ExecIf(“PJSIP/400-00000017”, “0?Set(PJSIP_HEADER(remove,Alert-Info)=)”) in new stack
– Executing [s@func-apply-sipheaders:12] Return(“PJSIP/400-00000017”, “”) in new stack
== Spawn extension (from-internal, 400, 1) exited non-zero on ‘PJSIP/400-00000017’
– PJSIP/400-00000017 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
– Called PJSIP/400/sip:[email protected]:5064
== Using SIP RTP Audio TOS bits 184
== Using SIP RTP Audio TOS bits 184 in TCLASS field.
== Using SIP RTP Audio CoS mark 5
<— Transmitting SIP request (1162 bytes) to UDP:192.168.71.5:5064 —>
INVITE sip:[email protected]:5064 SIP/2.0
Via: SIP/2.0/UDP 192.168.122.67:5060;rport;branch=z9hG4bKPjcd653e32-22a6-4254-98e7-446be1b30430
From: “6503252100” sip:[email protected];tag=ba292a5e-d7ee-4798-bfe5-cd3e662fc157
To: sip:[email protected]
Contact: sip:[email protected]:5060
Call-ID: f3a30d0e-eba0-4356-879e-4c664fbcae3f
CSeq: 23825 INVITE
Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, MESSAGE, REFER
Supported: 100rel, timer, replaces, norefersub
Session-Expires: 1800
Min-SE: 90
P-Asserted-Identity: “6503252100” sip:[email protected]
Max-Forwards: 70
User-Agent: FPBX-14.0.3.6(13.19.1)
Content-Type: application/sdp
Content-Length: 419

v=0
o=- 1367580655 1367580655 IN IP4 192.168.122.67
s=Asterisk
c=IN IP4 192.168.122.67
t=0 0
m=audio 16770 RTP/AVP 18 0 8 111 4 9 116 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:111 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:9 G722/8000
a=rtpmap:116 G719/48000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:80
a=sendrecv

-- Connected line update to SIP/vitel-inbound-00000014 prevented.

<— Received SIP response (367 bytes) from UDP:192.168.71.5:5064 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.122.67:5060;rport;branch=z9hG4bKPjcd653e32-22a6-4254-98e7-446be1b30430
From: “6503252100” sip:[email protected];tag=ba292a5e-d7ee-4798-bfe5-cd3e662fc157
To: sip:[email protected]
Call-ID: f3a30d0e-eba0-4356-879e-4c664fbcae3f
CSeq: 23825 INVITE
User-Agent: Grandstream GXP2000 1.2.5.3
Content-Length: 0

-- SIP/vitel-outbound-00000013 is ringing

<— Transmitting SIP response (601 bytes) to UDP:192.168.71.5:5062 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.71.5:5062;rport=5062;received=192.168.71.5;branch=z9hG4bK367045d03b785681
Call-ID: [email protected]
From: “Gerald Rosenberg” sip:[email protected];tag=be635af7da959ee6
To: sip:[email protected];tag=32356824-ecbb-4a83-892c-1abf31b967ca
CSeq: 57890 INVITE
Server: FPBX-14.0.3.6(13.19.1)
Contact: sip:192.168.122.67:5060
Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, MESSAGE, REFER
P-Asserted-Identity: “CID:6507031724” sip:[email protected]
Content-Length: 0

<— Received SIP response (528 bytes) from UDP:192.168.71.5:5064 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.122.67:5060;rport;branch=z9hG4bKPjcd653e32-22a6-4254-98e7-446be1b30430
From: “6503252100” sip:[email protected];tag=ba292a5e-d7ee-4798-bfe5-cd3e662fc157
To: sip:[email protected];tag=09c076b72533e164
Call-ID: f3a30d0e-eba0-4356-879e-4c664fbcae3f
CSeq: 23825 INVITE
User-Agent: Grandstream GXP2000 1.2.5.3
Contact: sip:[email protected]:5064;transport=udp
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
Content-Length: 0

-- PJSIP/400-00000017 is ringing

<— Received SIP request (460 bytes) from UDP:192.168.71.5:5062 —>
CANCEL sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.71.5:5062;branch=z9hG4bK367045d03b785681
From: “Gerald Rosenberg” sip:[email protected];tag=be635af7da959ee6
To: sip:[email protected]
Supported: path
Call-ID: [email protected]
CSeq: 57890 CANCEL
User-Agent: Grandstream GXP2000 1.2.5.3
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
Content-Length: 0

<— Transmitting SIP response (377 bytes) to UDP:192.168.71.5:5062 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.71.5:5062;rport=5062;received=192.168.71.5;branch=z9hG4bK367045d03b785681
Call-ID: [email protected]
From: “Gerald Rosenberg” sip:[email protected];tag=be635af7da959ee6
To: sip:[email protected];tag=32356824-ecbb-4a83-892c-1abf31b967ca
CSeq: 57890 CANCEL
Server: FPBX-14.0.3.6(13.19.1)
Content-Length: 0

<— Transmitting SIP response (576 bytes) to UDP:192.168.71.5:5062 —>
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 192.168.71.5:5062;rport=5062;received=192.168.71.5;branch=z9hG4bK367045d03b785681
Call-ID: [email protected]
From: “Gerald Rosenberg” sip:[email protected];tag=be635af7da959ee6
To: sip:[email protected];tag=32356824-ecbb-4a83-892c-1abf31b967ca
CSeq: 57890 INVITE
Server: FPBX-14.0.3.6(13.19.1)
Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, MESSAGE, REFER
P-Asserted-Identity: “CID:6507031724” sip:[email protected]
Content-Length: 0

== Spawn extension (macro-dialout-trunk, s, 32) exited non-zero on ‘PJSIP/200-00000016’ in macro ‘dialout-trunk’
== Spawn extension (from-internal, 3492330, 6) exited non-zero on ‘PJSIP/200-00000016’
– Executing [h@from-internal:1] Macro(“PJSIP/200-00000016”, “hangupcall”) in new stack
– Executing [s@macro-hangupcall:1] GotoIf(“PJSIP/200-00000016”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,3)
– Executing [s@macro-hangupcall:3] ExecIf(“PJSIP/200-00000016”, “0?Set(CDR(recordingfile)=)”) in new stack
– Executing [s@macro-hangupcall:4] NoOp(“PJSIP/200-00000016”, "SIP/vitel-outbound-00000013 monior file= “) in new stack
– Executing [s@macro-hangupcall:5] AGI(“PJSIP/200-00000016”, “attendedtransfer-rec-restart.php,SIP/vitel-outbound-00000013,”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
– PJSIP/400-00000017 Internal Gosub(crm-hangup,s,1) start
– Executing [s@crm-hangup:1] NoOp(“PJSIP/400-00000017”, “Sending Hangup to CRM”) in new stack
– Executing [s@crm-hangup:2] NoOp(“PJSIP/400-00000017”, “HANGUP CAUSE: 0”) in new stack
– Executing [s@crm-hangup:3] ExecIf(“PJSIP/400-00000017”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
– Executing [s@crm-hangup:4] NoOp(“PJSIP/400-00000017”, “MASTER CHANNEL: 1531260601.50 = 1531260601.49”) in new stack
– Executing [s@crm-hangup:5] GotoIf(“PJSIP/400-00000017”, “1?return”) in new stack
– Goto (crm-hangup,s,8)
– Executing [s@crm-hangup:8] Return(“PJSIP/400-00000017”, “”) in new stack
== Spawn extension (from-internal, 400, 1) exited non-zero on ‘PJSIP/400-00000017’
– PJSIP/400-00000017 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
== Spawn extension (macro-dial-one, s, 55) exited non-zero on ‘SIP/vitel-inbound-00000014’ in macro ‘dial-one’
== Spawn extension (macro-exten-vm, s, 26) exited non-zero on ‘SIP/vitel-inbound-00000014’ in macro ‘exten-vm’
== Spawn extension (ext-local, 400, 2) exited non-zero on ‘SIP/vitel-inbound-00000014’
– Executing [h@ext-local:1] Macro(“SIP/vitel-inbound-00000014”, “hangupcall,”) in new stack
<— Received SIP request (827 bytes) from UDP:192.168.71.5:5062 —>
ACK sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.71.5:5062;branch=z9hG4bK367045d03b785681
From: “Gerald Rosenberg” sip:[email protected];tag=be635af7da959ee6
To: sip:[email protected];tag=32356824-ecbb-4a83-892c-1abf31b967ca
Contact: sip:[email protected]:5062;transport=udp
Supported: path
Authorization: Digest username=“200”, realm=“asterisk”, algorithm=MD5, uri="sip:[email protected]”, qop=auth, nc=00000001, cnonce=“f0c123e8ef8aab66”, opaque=“54438cf12a93bee4”, nonce=“1531260599/4e8a92be6d87a693990f174f39cb130c”, response=“ac0bbe254b5f7a86f0a3296b26083b59”
Call-ID: [email protected]
CSeq: 57890 ACK
User-Agent: Grandstream GXP2000 1.2.5.3
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
Content-Length: 0

<— Transmitting SIP request (426 bytes) to UDP:192.168.71.5:5064 —>
CANCEL sip:[email protected]:5064 SIP/2.0
Via: SIP/2.0/UDP 192.168.122.67:5060;rport;branch=z9hG4bKPjcd653e32-22a6-4254-98e7-446be1b30430
From: “6503252100” sip:[email protected];tag=ba292a5e-d7ee-4798-bfe5-cd3e662fc157
To: sip:[email protected]
Call-ID: f3a30d0e-eba0-4356-879e-4c664fbcae3f
CSeq: 23825 CANCEL
Reason: Q.850;cause=0
Max-Forwards: 70
User-Agent: FPBX-14.0.3.6(13.19.1)
Content-Length: 0

<— Received SIP response (412 bytes) from UDP:192.168.71.5:5064 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.122.67:5060;rport;branch=z9hG4bKPjcd653e32-22a6-4254-98e7-446be1b30430
From: “6503252100” sip:[email protected];tag=ba292a5e-d7ee-4798-bfe5-cd3e662fc157
To: sip:[email protected];tag=09c076b72533e164
Call-ID: f3a30d0e-eba0-4356-879e-4c664fbcae3f
CSeq: 23825 CANCEL
User-Agent: Grandstream GXP2000 1.2.5.3
Supported: replaces, timer
Content-Length: 0

-- Executing [s@macro-hangupcall:1] GotoIf("SIP/vitel-inbound-00000014", "1?theend") in new stack
-- Goto (macro-hangupcall,s,3)
-- Executing [s@macro-hangupcall:3] ExecIf("SIP/vitel-inbound-00000014", "0?Set(CDR(recordingfile)=)") in new stack
-- Executing [s@macro-hangupcall:4] NoOp("SIP/vitel-inbound-00000014", "PJSIP/400-00000017 monior file= ") in new stack

<— Received SIP response (399 bytes) from UDP:192.168.71.5:5064 —>
SIP/2.0 487 Request Cancelled
Via: SIP/2.0/UDP 192.168.122.67:5060;rport;branch=z9hG4bKPjcd653e32-22a6-4254-98e7-446be1b30430
From: “6503252100” sip:[email protected];tag=ba292a5e-d7ee-4798-bfe5-cd3e662fc157
To: sip:[email protected];tag=09c076b72533e164
Call-ID: f3a30d0e-eba0-4356-879e-4c664fbcae3f
CSeq: 23825 INVITE
User-Agent: Grandstream GXP2000 1.2.5.3
Content-Length: 0

<— Transmitting SIP request (418 bytes) to UDP:192.168.71.5:5064 —>
ACK sip:[email protected]:5064 SIP/2.0
Via: SIP/2.0/UDP 192.168.122.67:5060;rport;branch=z9hG4bKPjcd653e32-22a6-4254-98e7-446be1b30430
From: “6503252100” sip:[email protected];tag=ba292a5e-d7ee-4798-bfe5-cd3e662fc157
To: sip:[email protected];tag=09c076b72533e164
Call-ID: f3a30d0e-eba0-4356-879e-4c664fbcae3f
CSeq: 23825 ACK
Max-Forwards: 70
User-Agent: FPBX-14.0.3.6(13.19.1)
Content-Length: 0

-- Executing [s@macro-hangupcall:5] AGI("SIP/vitel-inbound-00000014", "attendedtransfer-rec-restart.php,PJSIP/400-00000017,") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
-- <PJSIP/200-00000016>AGI Script attendedtransfer-rec-restart.php completed, returning 0
-- Executing [s@macro-hangupcall:6] Hangup("PJSIP/200-00000016", "") in new stack

== Spawn extension (macro-hangupcall, s, 6) exited non-zero on ‘PJSIP/200-00000016’ in macro ‘hangupcall’
== Spawn extension (from-internal, h, 1) exited non-zero on ‘PJSIP/200-00000016’
– PJSIP/200-00000016 Internal Gosub(crm-hangup,s,1) start
– Executing [s@crm-hangup:1] NoOp(“PJSIP/200-00000016”, “Sending Hangup to CRM”) in new stack
– Executing [s@crm-hangup:2] NoOp(“PJSIP/200-00000016”, “HANGUP CAUSE: 127”) in new stack
– Executing [s@crm-hangup:3] ExecIf(“PJSIP/200-00000016”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
– Executing [s@crm-hangup:4] NoOp(“PJSIP/200-00000016”, “MASTER CHANNEL: 1531260599.47 = 1531260599.47”) in new stack
– Executing [s@crm-hangup:5] GotoIf(“PJSIP/200-00000016”, “0?return”) in new stack
– Executing [s@crm-hangup:6] Set(“PJSIP/200-00000016”, “__CRM_HANGUP=1”) in new stack
– Executing [s@crm-hangup:7] AGI(“PJSIP/200-00000016”, “sangomacrm.agi”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
– <SIP/vitel-inbound-00000014>AGI Script attendedtransfer-rec-restart.php completed, returning 0
– Executing [s@macro-hangupcall:6] Hangup(“SIP/vitel-inbound-00000014”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 6) exited non-zero on ‘SIP/vitel-inbound-00000014’ in macro ‘hangupcall’
== Spawn extension (ext-local, h, 1) exited non-zero on ‘SIP/vitel-inbound-00000014’
– SIP/vitel-inbound-00000014 Internal Gosub(crm-hangup,s,1) start
– Executing [s@crm-hangup:1] NoOp(“SIP/vitel-inbound-00000014”, “Sending Hangup to CRM”) in new stack
– Executing [s@crm-hangup:2] NoOp(“SIP/vitel-inbound-00000014”, “HANGUP CAUSE: 16”) in new stack
– Executing [s@crm-hangup:3] ExecIf(“SIP/vitel-inbound-00000014”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
– Executing [s@crm-hangup:4] NoOp(“SIP/vitel-inbound-00000014”, “MASTER CHANNEL: 1531260601.49 = 1531260601.49”) in new stack
– Executing [s@crm-hangup:5] GotoIf(“SIP/vitel-inbound-00000014”, “0?return”) in new stack
– Executing [s@crm-hangup:6] Set(“SIP/vitel-inbound-00000014”, “__CRM_HANGUP=1”) in new stack
– Executing [s@crm-hangup:7] AGI(“SIP/vitel-inbound-00000014”, “sangomacrm.agi”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
<— Transmitting SIP request (425 bytes) to UDP:192.168.71.5:5064 —>
OPTIONS sip:[email protected]:5064 SIP/2.0
Via: SIP/2.0/UDP 192.168.122.67:5060;rport;branch=z9hG4bKPj605f685f-9095-47c0-af93-9819df0561c6
From: sip:[email protected];tag=7820aa30-a079-48b6-a5a4-5650278fccc2
To: sip:[email protected]
Contact: sip:[email protected]:5060
Call-ID: 88442cf2-7cf6-4473-bb26-0b680983775b
CSeq: 23912 OPTIONS
Max-Forwards: 70
User-Agent: FPBX-14.0.3.6(13.19.1)
Content-Length: 0

<— Received SIP response (532 bytes) from UDP:192.168.71.5:5064 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.122.67:5060;rport;branch=z9hG4bKPj605f685f-9095-47c0-af93-9819df0561c6
From: sip:[email protected];tag=7820aa30-a079-48b6-a5a4-5650278fccc2
To: sip:[email protected];tag=d79a9f7da715ed17
Call-ID: 88442cf2-7cf6-4473-bb26-0b680983775b
CSeq: 23912 OPTIONS
User-Agent: Grandstream GXP2000 1.2.5.3
Contact: sip:[email protected]:5064;transport=udp
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
Supported: replaces, timer
Content-Length: 0

-- <SIP/vitel-inbound-00000014>AGI Script sangomacrm.agi completed, returning 0
-- <PJSIP/200-00000016>AGI Script sangomacrm.agi completed, returning 0
-- Executing [s@crm-hangup:8] Return("PJSIP/200-00000016", "") in new stack

== Spawn extension (from-internal, h, 1) exited non-zero on ‘PJSIP/200-00000016’
– PJSIP/200-00000016 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
– Executing [s@crm-hangup:8] Return(“SIP/vitel-inbound-00000014”, “”) in new stack
== Spawn extension (ext-local, h, 1) exited non-zero on ‘SIP/vitel-inbound-00000014’
– SIP/vitel-inbound-00000014 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
<— Transmitting SIP request (425 bytes) to UDP:192.168.71.5:5062 —>
OPTIONS sip:[email protected]:5062 SIP/2.0
Via: SIP/2.0/UDP 192.168.122.67:5060;rport;branch=z9hG4bKPj15ae7690-7126-44b2-bdf1-7f983ba8f570
From: sip:[email protected];tag=c98ca6df-9811-4c86-8b21-05d31b6cd58a
To: sip:[email protected]
Contact: sip:[email protected]:5060
Call-ID: 59a07352-dacf-4267-8ecd-2177f8121202
CSeq: 33476 OPTIONS
Max-Forwards: 70
User-Agent: FPBX-14.0.3.6(13.19.1)
Content-Length: 0

perk*CLI>

What is the number 3492330, aren’t you calling 400?

That is the public phone number that corresponds to extension 400. Hmm, never tried calling directly to the extension.

Ok, directly calling the extension numbers 200 -> 400 and 400 -> 200 work.

What does not work is calling (from outside) the public phone number that connects to extension 200.