Hi everyone,
I am building my PBX with Asterisk 22 LTS using PJSIP with asterisk-realtime + FastAGI inside the Dialplan.
I am noticing a strange behaviour when one of the SIP phones is transfering the call (with a SIP REFER and NOT via DTMF) and I want to understand if it is expected or not.
Here is a snippet of the dialplan:
;AGI Checks
exten = _X.,1,Verbose(1, "User ${CALLERID(num)} dialed ${SAC_DIALED_EXTEN}.")
same = n,Set(SAC_DIALED_EXTEN=${EXTEN})
same = n,AGI(agi://X.X.X.X/agi)
same = n,Verbose("AGI RESPONSE: ${AGI_RESPONSE}, SAC_DIALED_EXTEN: ${SAC_DIALED_EXTEN}")
same = n,Gotoif($[${EXISTS(${AGI_RESPONSE})}]?:callUnauthorized,1); If AGI returned an invalid code, the call cannot be forwarded
same = n,Goto(${AGI_RESPONSE},1)
;Internal Call
exten = internalDial,1,Verbose(1, "AGI Authorized an internalDial call ${CALLERID(num)} to ${SAC_DIALED_EXTEN}")
same = n,Gotoif($[${DEVICE_STATE(PJSIP/${SAC_DIALED_EXTEN})} = BUSY]?dialed-BUSY,1:)
same = n,Dial(PJSIP/${SAC_DIALED_EXTEN}${INTERNAL_DIAL_OPT})
same = n,Verbose(1, "${DIALSTATUS}")
same = n,Goto(dialed-${DIALSTATUS},1)
The AGI server will perform some checks on the DB and then reply with the extension to jump to (it does not override variables inside the dialplan while being queried).
The test that I’m doing is the following:
- Phone 6002 Dials user 7001
- User 7001 answers.
- Phone 6002 then transfers the call with a SIP REFER towards extension 401
REFER sip:ASTERISK_IP:5060 SIP/2.0
Via: SIP/2.0/UDP PHONE_6002_IP:5060;branch=z9hG4bK83938f032ba67c8d
From: "6002" <sip:6002@ASTERISK_IP>;tag=ed93b5f54a95aa9d
To: <sip:7001@ASTERISK_IP>;tag=56024245-1b6d-4dd0-9a67-901d22b47c59
Contact: <sip:6002@PHONE_6002_IP:5060>
Supported: replaces
Refer-To: <sip:401@ASTERISK_IP>
Referred-By: <sip:6002@ASTERISK_IP>
Authorization: Digest username="6002", realm="asterisk" [...]
Call-ID: bfe6cc4e36f5ca9f@PHONE_6002_IP
CSeq: 10377 REFER
User-Agent: [...]
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK
Asterisk replies with 202 Accepted
The strange behaviour comes here. Inside the Dialplan user 6002 hangs up and then user 7001 enters the dialplan. The CALLERID inside that call becomes the special extension “internalDial” and not the channel “owner” 7001. Here the logs with DEBUG of res_pjsip_refer.so at 15.
[Aug 5 15:15:36] DEBUG[2151350]: res_pjsip_refer.c:407 refer_progress_alloc: Created progress monitor '0x7f4810fc5748' for transfer occurring from channel 'PJSIP/6002-0000000b' and endpoint '6002'
[Aug 5 15:15:36] DEBUG[2151350]: res_pjsip_refer.c:445 refer_progress_alloc: Accepting REFER request for progress monitor '0x7f480c071800'
-- Channel PJSIP/6002-0000000b left 'simple_bridge' basic-bridge <ee100224-ce9a-4ca5-bad6-17682455e7a2>
-- Stopped music on hold on PJSIP/7001-0000000c
-- Channel PJSIP/7001-0000000c left 'simple_bridge' basic-bridge <ee100224-ce9a-4ca5-bad6-17682455e7a2>
== Spawn extension (sip-context, internalDial, 3) exited non-zero on 'PJSIP/6002-0000000b'
-- Executing [h@sip-context:1] Hangup("PJSIP/6002-0000000b", "") in new stack
== Spawn extension (sip-context, h, 1) exited non-zero on 'PJSIP/6002-0000000b'
-- Executing [401@sip-context:1] Verbose("PJSIP/7001-0000000c", "1, "User internalDial dialed 401."") in new stack
"User internalDial dialed ."
-- Executing [401@sip-context:2] Set("PJSIP/7001-0000000c", "SAC_DIALED_EXTEN=401") in new stack
-- Executing [401@sip-context:3] AGI("PJSIP/7001-0000000c", "agi://X.X.X.X/agi") in new stack
-- <PJSIP/7001-0000000c>AGI Script agi://X.X.X.X/agi completed, returning 0
-- Executing [401@sip-context:4] Verbose("PJSIP/7001-0000000c", ""AGI RESPONSE: , SAC_DIALED_EXTEN: 401"") in new stack
AGI RESPONSE: , SAC_DIALED_EXTEN: 401
-- Executing [401@sip-context:5] GotoIf("PJSIP/7001-0000000c", "0?:callUnauthorized,1") in new stack
-- Goto (sip-context,callUnauthorized,1)
-- Executing [callUnauthorized@sip-context:1] NoOp("PJSIP/7001-0000000c", "") in new stack
-- Executing [callUnauthorized@sip-context:2] Playback("PJSIP/7001-0000000c", "pbx-invalid") in new stack
[Aug 5 15:15:36] DEBUG[2151704][C-0000000a]: res_pjsip_refer.c:288 refer_progress_framehook: Detaching REFER progress monitoring hook from 'PJSIP/7001-0000000c' as subscription is being terminated
[Aug 5 15:15:36] DEBUG[2151350]: res_pjsip_refer.c:165 refer_progress_notify: Sending initial 100 Trying NOTIFY for progress monitor '0x7f480c071800'
-- <PJSIP/7001-0000000c> Playing 'pbx-invalid.gsm' (language 'en')
[Aug 5 15:15:36] DEBUG[2151350]: res_pjsip_refer.c:173 refer_progress_notify: Sending NOTIFY with response '200' and state '5' on subscription '0x7f480c08b8d8' and progress monitor '0x7f480c071800'
[Aug 5 15:15:36] DEBUG[2151350]: res_pjsip_refer.c:155 refer_progress_notify: Not sending NOTIFY of response '503' and state '5' on progress monitor '0x7f480c071800' as subscription has been terminated
> 0x7f480c0c39e0 -- Strict RTP learning complete - Locking on source address PHONE_7001_IP:5112
-- Executing [callUnauthorized@sip-context:3] Hangup("PJSIP/7001-0000000c", "") in new stack
== Spawn extension (sip-context, callUnauthorized, 3) exited non-zero on 'PJSIP/7001-0000000c'
-- Executing [h@sip-context:1] Hangup("PJSIP/7001-0000000c", "") in new stack
This is the Channel dump of PJSIP/7001-0000000c. (I hanged the FastAGI server for a brief period to retrieve it from he CLI while the transfer was happening).
-- General --
Name: PJSIP/7001-0000000c
Type: PJSIP
UniqueID: 1754398742.19
LinkedID: 1754398739.18
Caller ID: internalDial
Caller ID Name: (N/A)
Connected Line ID: 6002
Connected Line ID Name: 6002
Eff. Connected Line ID: 6002
Eff. Connected Line ID Name: 6002
DNID Digits: (N/A)
Language: en
State: Up (6)
NativeFormats: (ulaw)
WriteFormat: ulaw
ReadFormat: ulaw
WriteTranscode: No
ReadTranscode: No
Time to Hangup: 0
Elapsed Time: 0h0m29s
Bridge ID: (Not bridged)
-- PBX --
Context: sip-context
Extension: sipCallHandler
Priority: 2
Call Group: 0
Pickup Group: 0
Application: AGI
Data: agi://X.X.X.X/agi
Call Identifer: [C-00000006]
Variables:
SAC_DIALED_EXTEN=401
SIPREFERTOHDR=sip:401@ASTERISK_IP
SIPREFERREDBYHDR=<sip:6002@ASTERISK_IP>
SIPREFERRINGCONTEXT=sip-context
SIPTRANSFER=yes
BLINDTRANSFER=PJSIP/6002-0000000b
DIALEDPEERNUMBER=7001
CDR Variables:
level 1: clid="" <internalDial>
level 1: src=internalDial
level 1: dst=401
level 1: dcontext=sip-context
level 1: channel=PJSIP/7001-0000000c
level 1: lastapp=AppDial
level 1: lastdata=(Outgoing Line)
level 1: start=1754398742.263203
level 1: answer=1754398744.160849
level 1: end=1754398744.162469
level 1: duration=1
level 1: billsec=0
level 1: disposition=8
level 1: amaflags=3
level 1: uniqueid=1754398742.19
level 1: linkedid=1754398739.18
level 1: sequence=14
level 2: clid="" <internalDial>
level 2: src=internalDial
level 2: dst=401
level 2: dcontext=sip-context
level 2: channel=PJSIP/7001-0000000c
level 2: lastapp=AGI
level 2: lastdata=agi://X.X.X.X/agi
level 2: start=1754398747.990201
level 2: answer=1754398747.990201
level 2: end=0.000000
level 2: duration=23
level 2: billsec=23
level 2: disposition=1
level 2: amaflags=3
level 2: uniqueid=1754398742.19
level 2: linkedid=1754398739.18
level 2: sequence=15
I can still retrieve the 7001 extension using the variable DIALEDPEERNUMBER, or via other channel info, but I’m not sure it’s fundamentally correct.
I am writing here to understand if I’m doing something wrong (like using internalDial to jump inside the dialplan before a Dial(), or if this is some sort of misconfiguration from my side or even a bug.
Thanks in advance for any reply.