FreePBX 17 dynroute sub-queue-answer partially broken

cortlandhrdwood · August 21, 2024, 1:40pm

On 16 I had set up a dynroute using @lgaetz wonderful instructions from https://community.freepbx.org/t/using-dynamic-routes-to-run-a-dialplan-sub-when-queue-agent-answers/78009

I’m now testing 17 and the same sub-queue-answer is no longer running.
Asterisk version change 16.30 > 21.4.1.

[sub-queue-answer]
exten => s,1,Verbose(2,Entering user defined context sub-queue-answer in extensions_custom.conf)
exten => s,n,DumpChan(2)	; uncomment for debug
same => n,Set(SendToMessagesQueue=${CURL(https://site.tld/Script.php?CallerID=${CONNECTEDLINE(num)}&Exten=${CUT(CUT(CHANNEL(name),/,2),@,1)}&from=pbx)})
same => n,Return()

Watching an incoming call with asterisk -vvvr I see


	-- Goto (timeconditions,4,14)
	-- Executing [4@timeconditions:14] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "0?falsegoto") in new stack
	-- Executing [4@timeconditions:15] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "0?Set(DB(TC/4)=)") in new stack
	-- Executing [4@timeconditions:16] Set("PJSIP/EZSS_PJSIP-0000007e", "DEVICE_STATE(Custom:TC4)=NOT_INUSE") in new stack
	-- Executing [4@timeconditions:17] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack
	-- Executing [4@timeconditions:18] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "1?dynroute-1,s,1") in new stack
	-- Goto (dynroute-1,s,1)
	-- Executing [s@dynroute-1:1] Set("PJSIP/EZSS_PJSIP-0000007e", "dynroute=") in new stack
	-- Executing [s@dynroute-1:2] Set("PJSIP/EZSS_PJSIP-0000007e", "dynroute=sub-queue-answer") in new stack
	-- Executing [s@dynroute-1:3] Set("PJSIP/EZSS_PJSIP-0000007e", "dynroute=sub-queue-answer") in new stack
	-- Executing [s@dynroute-1:4] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "0?dynroute-1,1,1") in new stack
	-- Executing [s@dynroute-1:5] Goto("PJSIP/EZSS_PJSIP-0000007e", "dynroute-1,1,1") in new stack
	-- Goto (dynroute-1,1,1)
	-- Executing [1@dynroute-1:1] Goto("PJSIP/EZSS_PJSIP-0000007e", "ext-queues,2000,1") in new stack
	-- Goto (ext-queues,2000,1)
	-- Executing [2000@ext-queues:1] Gosub("PJSIP/EZSS_PJSIP-0000007e", "macro-user-callerid,s,1()") in new stack
	-- Executing [s@macro-user-callerid:1] Set("PJSIP/EZSS_PJSIP-0000007e", "TOUCH_MONITOR=1724245274.468") in new stack
	-- Executing [s@macro-user-callerid:2] Set("PJSIP/EZSS_PJSIP-0000007e", "CHANCONTEXT=") in new stack
	-- Executing [s@macro-user-callerid:3] Set("PJSIP/EZSS_PJSIP-0000007e", "CHANCONTEXT=") in new stack
	-- Executing [s@macro-user-callerid:4] Set("PJSIP/EZSS_PJSIP-0000007e", "CHANEXTENCONTEXT=EZSS_PJSIP-0000007e") in new stack
	-- Executing [s@macro-user-callerid:5] Set("PJSIP/EZSS_PJSIP-0000007e", "CHANEXTEN=EZSS_PJSIP-0000007e") in new stack
	-- Executing [s@macro-user-callerid:6] Set("PJSIP/EZSS_PJSIP-0000007e", "CALLERID(number)=1235556789") in new stack
	-- Executing [s@macro-user-callerid:7] Set("PJSIP/EZSS_PJSIP-0000007e", "AMPUSER=1235556789") in new stack
	-- Executing [s@macro-user-callerid:8] Set("PJSIP/EZSS_PJSIP-0000007e", "HOTDESCKCHAN=EZSS_PJSIP-0000007e") in new stack
	-- Executing [s@macro-user-callerid:9] Set("PJSIP/EZSS_PJSIP-0000007e", "HOTDESKEXTEN=EZSS_PJSIP") in new stack
	-- Executing [s@macro-user-callerid:10] Set("PJSIP/EZSS_PJSIP-0000007e", "HOTDESKCALL=0") in new stack
	-- Executing [s@macro-user-callerid:11] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "0?Set(HOTDESKCALL=1)") in new stack
	-- Executing [s@macro-user-callerid:12] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "0?Set(CALLERID(name)=)") in new stack
	-- Executing [s@macro-user-callerid:13] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "0?report") in new stack
	-- Executing [s@macro-user-callerid:14] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "1?Set(REALCALLERIDNUM=1235556789)") in new stack
	-- Executing [s@macro-user-callerid:15] Set("PJSIP/EZSS_PJSIP-0000007e", "AMPUSER=") in new stack
	-- Executing [s@macro-user-callerid:16] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "0?limit") in new stack
	-- Executing [s@macro-user-callerid:17] Set("PJSIP/EZSS_PJSIP-0000007e", "AMPUSERCIDNAME=") in new stack
	-- Executing [s@macro-user-callerid:18] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
	-- Executing [s@macro-user-callerid:19] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "1?report") in new stack
	-- Goto (macro-user-callerid,s,28)
	-- Executing [s@macro-user-callerid:28] NoOp("PJSIP/EZSS_PJSIP-0000007e", "Macro depricated!! To keep the same line numbers") in new stack
	-- Executing [s@macro-user-callerid:29] NoOp("PJSIP/EZSS_PJSIP-0000007e", "Macro depricated !!  To keep the same line numbers") in new stack
	-- Executing [s@macro-user-callerid:30] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "0?continue") in new stack
	-- Executing [s@macro-user-callerid:31] Set("PJSIP/EZSS_PJSIP-0000007e", "__TTL=64") in new stack
	-- Executing [s@macro-user-callerid:32] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "1?continue") in new stack
	-- Goto (macro-user-callerid,s,48)
	-- Executing [s@macro-user-callerid:48] Set("PJSIP/EZSS_PJSIP-0000007e", "CALLERID(number)=1235556789") in new stack
	-- Executing [s@macro-user-callerid:49] Set("PJSIP/EZSS_PJSIP-0000007e", "CALLERID(name)=EZ:Caller Name") in new stack
	-- Executing [s@macro-user-callerid:50] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "0?cnum") in new stack
	-- Executing [s@macro-user-callerid:51] Set("PJSIP/EZSS_PJSIP-0000007e", "CDR(cnam)=EZ:Caller Name") in new stack
	-- Executing [s@macro-user-callerid:52] Set("PJSIP/EZSS_PJSIP-0000007e", "CDR(cnum)=1235556789") in new stack
	-- Executing [s@macro-user-callerid:53] Return("PJSIP/EZSS_PJSIP-0000007e", "") in new stack
	-- Executing [2000@ext-queues:2] Answer("PJSIP/EZSS_PJSIP-0000007e", "") in new stack
	-- Executing [2000@ext-queues:3] Set("PJSIP/EZSS_PJSIP-0000007e", "__FROMQUEUEEXTEN=1235556789") in new stack
	-- Executing [2000@ext-queues:4] Gosub("PJSIP/EZSS_PJSIP-0000007e", "macro-blkvm-set,s,1(reset)") in new stack
	-- Executing [s@macro-blkvm-set:1] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "1?Set(__BLKVM_CHANNEL=PJSIP/EZSS_PJSIP-0000007e)") in new stack
	-- Executing [s@macro-blkvm-set:2] Set("PJSIP/EZSS_PJSIP-0000007e", "SHARED(BLKVM,PJSIP/EZSS_PJSIP-0000007e)=TRUE") in new stack
	-- Executing [s@macro-blkvm-set:3] Set("PJSIP/EZSS_PJSIP-0000007e", "GOSUB_RETVAL=TRUE") in new stack
	-- Executing [s@macro-blkvm-set:4] Return("PJSIP/EZSS_PJSIP-0000007e", "") in new stack
	-- Executing [2000@ext-queues:5] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "1?Set(_DIAL_OPTIONS=TtrU(macro-auto-blkvm))") in new stack
	-- Executing [2000@ext-queues:6] Set("PJSIP/EZSS_PJSIP-0000007e", "__NODEST=2000") in new stack
	-- Executing [2000@ext-queues:7] Set("PJSIP/EZSS_PJSIP-0000007e", "__QCONTEXT=0") in new stack
	-- Executing [2000@ext-queues:8] Set("PJSIP/EZSS_PJSIP-0000007e", "QCIDPP=") in new stack
	-- Executing [2000@ext-queues:9] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_CIDPP=") in new stack
	-- Executing [2000@ext-queues:10] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "0?Gosub(macro-prepend-cid,s,1())") in new stack
	-- Executing [2000@ext-queues:11] Set("PJSIP/EZSS_PJSIP-0000007e", "QAINFO=<http://127.0.0.1>; info=ez-ring") in new stack
	-- Executing [2000@ext-queues:12] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_AINFO=") in new stack
	-- Executing [2000@ext-queues:13] Set("PJSIP/EZSS_PJSIP-0000007e", "__RVOL_MODE=no") in new stack
	-- Executing [2000@ext-queues:14] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "1?Set(__ALERT_INFO=<http://127.0.0.1>; info=ez-ring)") in new stack
	-- Executing [2000@ext-queues:15] Set("PJSIP/EZSS_PJSIP-0000007e", "QJOINMSG=") in new stack
	-- Executing [2000@ext-queues:16] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_JOINMSG=") in new stack
	-- Executing [2000@ext-queues:17] Set("PJSIP/EZSS_PJSIP-0000007e", "QCANCELMISSED=") in new stack
	-- Executing [2000@ext-queues:18] Set("PJSIP/EZSS_PJSIP-0000007e", "QRINGOPTS=r") in new stack
	-- Executing [2000@ext-queues:19] Set("PJSIP/EZSS_PJSIP-0000007e", "QRETRY=n") in new stack
	-- Executing [2000@ext-queues:20] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_RETRY=") in new stack
	-- Executing [2000@ext-queues:21] Set("PJSIP/EZSS_PJSIP-0000007e", "QOPTIONS=trn") in new stack
	-- Executing [2000@ext-queues:22] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_OPTIONS=") in new stack
	-- Executing [2000@ext-queues:23] Set("PJSIP/EZSS_PJSIP-0000007e", "QGOSUB=sub-queue-answer") in new stack
	-- Executing [2000@ext-queues:24] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_GOSUB=") in new stack
	-- Executing [2000@ext-queues:25] Set("PJSIP/EZSS_PJSIP-0000007e", "QAGI=") in new stack
	-- Executing [2000@ext-queues:26] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_AGI=") in new stack
	-- Executing [2000@ext-queues:27] Set("PJSIP/EZSS_PJSIP-0000007e", "QRULE=") in new stack
	-- Executing [2000@ext-queues:28] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_RULE=") in new stack
	-- Executing [2000@ext-queues:29] Set("PJSIP/EZSS_PJSIP-0000007e", "QPOSITION=") in new stack
	-- Executing [2000@ext-queues:30] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_POSITION=") in new stack
	-- Executing [2000@ext-queues:31] Gosub("PJSIP/EZSS_PJSIP-0000007e", "sub-record-check,s,1(q,2000,never)") in new stack
	-- Executing [s@sub-record-check:1] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "10?initialized") in new stack
	-- Goto (sub-record-check,s,10)
	-- Executing [s@sub-record-check:10] NoOp("PJSIP/EZSS_PJSIP-0000007e", "Recordings initialized") in new stack
	-- Executing [s@sub-record-check:11] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "0?Set(ARG3=dontcare)") in new stack
	-- Executing [s@sub-record-check:12] Set("PJSIP/EZSS_PJSIP-0000007e", "REC_POLICY_MODE_SAVE=NEVER") in new stack
	-- Executing [s@sub-record-check:13] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "0?Set(REC_STATUS=NO)") in new stack
	-- Executing [s@sub-record-check:14] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "1?checkaction") in new stack
	-- Goto (sub-record-check,s,17)
	-- Executing [s@sub-record-check:17] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "0?sub-record-check,q,1") in new stack
	-- Executing [s@sub-record-check:18] NoOp("PJSIP/EZSS_PJSIP-0000007e", "Generic q Recording Check - 1235556789 2000") in new stack
	-- Executing [s@sub-record-check:19] Gosub("PJSIP/EZSS_PJSIP-0000007e", "recordcheck,1(never,q,2000)") in new stack
	-- Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/EZSS_PJSIP-0000007e", "Starting recording check against never") in new stack
	-- Executing [recordcheck@sub-record-check:2] Goto("PJSIP/EZSS_PJSIP-0000007e", "never") in new stack
	-- Goto (sub-record-check,recordcheck,14)
	-- Executing [recordcheck@sub-record-check:14] Set("PJSIP/EZSS_PJSIP-0000007e", "__REC_POLICY_MODE=NEVER") in new stack
	-- Executing [recordcheck@sub-record-check:15] Goto("PJSIP/EZSS_PJSIP-0000007e", "stoprec") in new stack
	-- Goto (sub-record-check,recordcheck,27)
	-- Executing [recordcheck@sub-record-check:27] NoOp("PJSIP/EZSS_PJSIP-0000007e", "Stopping recording: q, 2000") in new stack
	-- Executing [recordcheck@sub-record-check:28] Set("PJSIP/EZSS_PJSIP-0000007e", "__REC_STATUS=STOPPED") in new stack
	-- Executing [recordcheck@sub-record-check:29] System("PJSIP/EZSS_PJSIP-0000007e", "/var/lib/asterisk/bin/stoprecording.php "PJSIP/EZSS_PJSIP-0000007e"") in new stack
	-- Executing [recordcheck@sub-record-check:30] Return("PJSIP/EZSS_PJSIP-0000007e", "") in new stack
	-- Executing [s@sub-record-check:20] Return("PJSIP/EZSS_PJSIP-0000007e", "") in new stack
	-- Executing [2000@ext-queues:32] Set("PJSIP/EZSS_PJSIP-0000007e", "__SIGNORE=TRUE") in new stack
	-- Executing [2000@ext-queues:33] Set("PJSIP/EZSS_PJSIP-0000007e", "__QC_CONFIRM=0") in new stack
	-- Executing [2000@ext-queues:34] GotoIf("PJSIP/EZSS_PJSIP-0000007e", "0?QVQANNOUNCE:NOQVQANNOUNCE") in new stack
	-- Goto (ext-queues,2000,39)
	-- Executing [2000@ext-queues:39] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_CONFIRMMSG=") in new stack
	-- Executing [2000@ext-queues:40] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "0?Playback(, )") in new stack
	-- Executing [2000@ext-queues:41] QueueLog("PJSIP/EZSS_PJSIP-0000007e", "2000,1724245274.468,NONE,DID,1235559876") in new stack
	-- Executing [2000@ext-queues:42] Set("PJSIP/EZSS_PJSIP-0000007e", "QAANNOUNCE=") in new stack
	-- Executing [2000@ext-queues:43] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_AANNOUNCE=") in new stack
	-- Executing [2000@ext-queues:44] Set("PJSIP/EZSS_PJSIP-0000007e", "QMOH=") in new stack
	-- Executing [2000@ext-queues:45] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_MOH=") in new stack
	-- Executing [2000@ext-queues:46] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "0?Set(__MOHCLASS=)") in new stack
	-- Executing [2000@ext-queues:47] ExecIf("PJSIP/EZSS_PJSIP-0000007e", "1?Set(CHANNEL(musicclass)=EZSS)") in new stack
	-- Executing [2000@ext-queues:48] Set("PJSIP/EZSS_PJSIP-0000007e", "QMAXWAIT=") in new stack
	-- Executing [2000@ext-queues:49] Set("PJSIP/EZSS_PJSIP-0000007e", "VQ_MAXWAIT=") in new stack
	-- Executing [2000@ext-queues:50] Set("PJSIP/EZSS_PJSIP-0000007e", "QUEUENUM=2000") in new stack
	-- Executing [2000@ext-queues:51] Set("PJSIP/EZSS_PJSIP-0000007e", "QUEUEJOINTIME=1724245275") in new stack
	-- Executing [2000@ext-queues:52] Queue("PJSIP/EZSS_PJSIP-0000007e", "2000,trn,,,,,,sub-queue-answer,,") in new stack

It seems to be calling the sub-queue-answer and is redirecting to the queue properly but never outputting the Verbose or DumpChan much less calling curl.

Does anyone have any idea what might have stopped it working?

cortlandhrdwood · August 21, 2024, 2:39pm

Just tried asterisk-version-switch to 18 and it is sending them again so definitely something changed with 21.

dicko · August 21, 2024, 2:52pm

‘macros’ have been removed from Asterisk 21

BlazeStudios · August 21, 2024, 3:00pm

Yes, something did change. Asterisk v21 saw the removal of app_macro which means other applications, like Queues, that had options to call on Marco’s no longer do.

This bit from your output: -- Executing [2000@ext-queues:52] Queue("PJSIP/EZSS_PJSIP-0000007e", "2000,trn,,,,,,sub-queue-answer,,") in new stack is using the v20 or lower Queue() options. Meaning there are 10 settings requiring 9 commas to delimit them.

If Asterisk v21, Queues only have 9 settings (as Macro calls are removed). The posted dialplan is showing 10 options and if that was taken with Asterisk v21 running it means the last option spot is ignored and your Gosub call is ending up in the rule options.

Basically this:
"2000,trn,,,,,,sub-queue-answer,,"

Needs to be this when Asterisk v21 is being used.
"2000,trn,,,,,sub-queue-answer,,"

Edit: I just tested on FreePBX v17 and Asterisk v21. It is indeed still writing out the Queue() command with v20 or lower settings. So this is 100% a bug.

@kgupta How are so many things like this getting passed QA?

BlazeStudios · August 21, 2024, 3:12pm

I opened a ticket for this bug: [bug]: Queue still using Asterisk v20 or lower settings when using Asterisk v21 which breaks functionality of settings. · Issue #386 · FreePBX/issue-tracker (github.com)

cortlandhrdwood · August 21, 2024, 3:18pm

Thank you @BlazeStudios

I will stick with v18 for now

kgupta · August 21, 2024, 3:59pm

Thanks for reporting this issue, will investigate asap.

system · August 28, 2024, 4:00pm

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.