-
Type:
Bug
-
Status: Open
-
Priority:
Minor
-
Resolution: Unresolved
-
Affects Version/s: 13
-
Fix Version/s: None
-
Component/s: Ring Groups
-
Labels:None
-
Asterisk Version:13.23.1
-
Distro Version:10.13.66-22
-
Distro:FreePBX Distro
We have a ring group (13.0.23.4) with random strategy, 20 seconds of ring time and 5 extensions in it. If the first randomly selected extension does not answer for 20 seconds and during that time the second selected extension makes or receives a call and it has call waiting disabled, it wrongly receives the call.
Here are logs of an example call where 1732 is the first random extension and 1733 is the second one:
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [1498@ext-group:14] Set("IAX2/IED2-13232", "RingGroupMethod=random") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [1498@ext-group:15] Macro("IAX2/IED2-13232", "dial,20,trwW,1731-1732-1733-1735-1730") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:1] NoOp("IAX2/IED2-13232", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:2] Set("IAX2/IED2-13232", "__CRM_SOURCE=XXXXX") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:3] ExecIf("IAX2/IED2-13232", "0?Set(ALERT_INFO=)") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:4] ExecIf("IAX2/IED2-13232", "0?Set(ALERT_INFO=)") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:5] ExecIf("IAX2/IED2-13232", "0?Set(ALERT_INFO=)") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:6] ExecIf("IAX2/IED2-13232", "0?Set(CHANNEL(musicclass)=)") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:7] AGI("IAX2/IED2-13232", "dialparties.agi") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Caller ID name is 'XXXXX' number is 'XXXXX'
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: CW Ignore is: TRUE
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: CF Ignore is:
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: CW IN_USE/BUSY is: 1
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Methodology of ring is 'random'
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Added extension 1731 to extension map
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Added extension 1732 to extension map
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Added extension 1733 to extension map
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Added extension 1735 to extension map
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Added extension 1730 to extension map
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1731 cf is disabled
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1732 cf is disabled
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1733 cf is disabled
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1735 cf is disabled
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1730 cf is disabled
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1731 do not disturb is disabled
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1732 do not disturb is disabled
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1733 do not disturb is disabled
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1735 has do not disturb enabled, or followme pre-ring returned busy
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1730 do not disturb is disabled
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1731 has ExtensionState: 0
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 1731
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1732 has ExtensionState: 0
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 1732
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1733 has ExtensionState: 0
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 1733
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Extension 1730 has ExtensionState: 0
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 1730
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: dialparties.agi: Filtered ARG3: 1731-1732-1733-1730
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] res_agi.c: AGI Script dialparties.agi completed, returning 0
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:28] NoOp("IAX2/IED2-13232", "Returned from dialparties with 4 hunt members to dial") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:29] Set("IAX2/IED2-13232", "HuntLoop=0") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:30] ExecIf("IAX2/IED2-13232", "0?Set(HuntMembers=0)") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:31] GotoIf("IAX2/IED2-13232", "1?a30") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx_builtins.c: Goto (macro-dial,s,34)
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:34] Set("IAX2/IED2-13232", "HuntMember=HuntMember0") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:35] GotoIf("IAX2/IED2-13232", "0?a32:a35") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx_builtins.c: Goto (macro-dial,s,40)
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:40] GotoIf("IAX2/IED2-13232", "0?a36:a50") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx_builtins.c: Goto (macro-dial,s,60)
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:60] NoOp("IAX2/IED2-13232", "Deleting: CALLTRACE/ ") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:61] Goto("IAX2/IED2-13232", "s,huntstart") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx_builtins.c: Goto (macro-dial,s,48)
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:48] NoOp("IAX2/IED2-13232", "Hunt Dial Start") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:49] ExecIf("IAX2/IED2-13232", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:50] ExecIf("IAX2/IED2-13232", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:51] Macro("IAX2/IED2-13232", "dial-hunt-predial-hook,") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial-hunt-predial-hook:1] MacroExit("IAX2/IED2-13232", "") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:52] ExecIf("IAX2/IED2-13232", "0?Set(ds=,20,trwWM(auto-blkvm)g)") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:53] Dial("IAX2/IED2-13232", "SIP/1732,20,trwWM(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] netsock2.c: Using SIP RTP TOS bits 184
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] netsock2.c: Using SIP RTP CoS mark 5
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] app_stack.c: SIP/1732-000bfa43 Internal Gosub(func-apply-sipheaders,s,1) start
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("SIP/1732-000bfa43", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("SIP/1732-000bfa43", "Applying SIP Headers to channel SIP/1732-000bfa43") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@func-apply-sipheaders:3] Set("SIP/1732-000bfa43", "TECH=SIP") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@func-apply-sipheaders:4] Set("SIP/1732-000bfa43", "SIPHEADERKEYS=") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/1732-000bfa43", "0") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] app_while.c: Jumping to priority 13
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@func-apply-sipheaders:14] Return("SIP/1732-000bfa43", "") in new stack
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] app_stack.c: Spawn extension (from-internal, 1498, 1) exited non-zero on 'SIP/1732-000bfa43'
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] app_stack.c: SIP/1732-000bfa43 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] app_dial.c: Called SIP/1732
[2020-10-13 14:01:52] VERBOSE[23528][C-000d12bf] app_dial.c: SIP/1732-000bfa43 is ringing
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] app_dial.c: Nobody picked up in 20000 ms
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] app_stack.c: SIP/1732-000bfa43 Internal Gosub(crm-hangup,s,1) start
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@crm-hangup:1] NoOp("SIP/1732-000bfa43", "Sending Hangup to CRM") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@crm-hangup:2] NoOp("SIP/1732-000bfa43", " HANGUP CAUSE: 16") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@crm-hangup:3] ExecIf("SIP/1732-000bfa43", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@crm-hangup:4] NoOp("SIP/1732-000bfa43", "MASTER CHANNEL: 1602586912.16014647 = 1602586901.16014563") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@crm-hangup:5] GotoIf("SIP/1732-000bfa43", "1?return") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx_builtins.c: Goto (crm-hangup,s,8)
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@crm-hangup:8] Return("SIP/1732-000bfa43", "") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] app_stack.c: Spawn extension (from-internal, 1498, 1) exited non-zero on 'SIP/1732-000bfa43'
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] app_stack.c: SIP/1732-000bfa43 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:54] GotoIf("IAX2/IED2-13232", "0?ANSWER,1") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:55] Set("IAX2/IED2-13232", "HuntLoop=1") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:56] GotoIf("IAX2/IED2-13232", "0 & 1?huntreset:a46") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx_builtins.c: Goto (macro-dial,s,58)
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:58] Set("IAX2/IED2-13232", "HuntMembers=3") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:59] Goto("IAX2/IED2-13232", "s,a22") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx_builtins.c: Goto (macro-dial,s,31)
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:31] GotoIf("IAX2/IED2-13232", "1?a30") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx_builtins.c: Goto (macro-dial,s,34)
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:34] Set("IAX2/IED2-13232", "HuntMember=HuntMember1") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:35] GotoIf("IAX2/IED2-13232", "0?a32:a35") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx_builtins.c: Goto (macro-dial,s,40)
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:40] GotoIf("IAX2/IED2-13232", "0?a36:a50") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx_builtins.c: Goto (macro-dial,s,60)
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:60] NoOp("IAX2/IED2-13232", "Deleting: CALLTRACE/ ") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:61] Goto("IAX2/IED2-13232", "s,huntstart") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx_builtins.c: Goto (macro-dial,s,48)
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:48] NoOp("IAX2/IED2-13232", "Hunt Dial Start") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:49] ExecIf("IAX2/IED2-13232", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:50] ExecIf("IAX2/IED2-13232", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:51] Macro("IAX2/IED2-13232", "dial-hunt-predial-hook,") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial-hunt-predial-hook:1] MacroExit("IAX2/IED2-13232", "") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:52] ExecIf("IAX2/IED2-13232", "0?Set(ds=,20,trwWM(auto-blkvm)g)") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@macro-dial:53] Dial("IAX2/IED2-13232", "SIP/1733,20,trwWM(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] netsock2.c: Using SIP RTP TOS bits 184
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] netsock2.c: Using SIP RTP CoS mark 5
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] app_stack.c: SIP/1733-000bfa49 Internal Gosub(func-apply-sipheaders,s,1) start
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("SIP/1733-000bfa49", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("SIP/1733-000bfa49", "Applying SIP Headers to channel SIP/1733-000bfa49") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@func-apply-sipheaders:3] Set("SIP/1733-000bfa49", "TECH=SIP") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@func-apply-sipheaders:4] Set("SIP/1733-000bfa49", "SIPHEADERKEYS=") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/1733-000bfa49", "0") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] app_while.c: Jumping to priority 13
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] pbx.c: Executing [s@func-apply-sipheaders:14] Return("SIP/1733-000bfa49", "") in new stack
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] app_stack.c: Spawn extension (from-internal, 1498, 1) exited non-zero on 'SIP/1733-000bfa49'
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] app_stack.c: SIP/1733-000bfa49 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] app_dial.c: Called SIP/1733
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] app_dial.c: SIP/1733-000bfa49 is ringing
[2020-10-13 14:02:12] VERBOSE[23528][C-000d12bf] app_dial.c: SIP/1733-000bfa49 is ringing
[2020-10-13 14:02:25] VERBOSE[23528][C-000d12bf] app_stack.c: SIP/1733-000bfa49 Internal Gosub(crm-hangup,s,1) start
Between 14:01:51 and 14:02:12 the second extension 1733 received another call:
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [1498@ext-group:14] Set("SIP/BTC-primary-000bfa3f", "RingGroupMethod=random") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [1498@ext-group:15] Macro("SIP/BTC-primary-000bfa3f", "dial,20,trwW,1731-1732-1733-1735-1730") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:1] NoOp("SIP/BTC-primary-000bfa3f", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:2] Set("SIP/BTC-primary-000bfa3f", "__CRM_SOURCE=YYYYY") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:3] ExecIf("SIP/BTC-primary-000bfa3f", "0?Set(ALERT_INFO=)") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:4] ExecIf("SIP/BTC-primary-000bfa3f", "0?Set(ALERT_INFO=)") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:5] ExecIf("SIP/BTC-primary-000bfa3f", "0?Set(ALERT_INFO=)") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:6] ExecIf("SIP/BTC-primary-000bfa3f", "0?Set(CHANNEL(musicclass)=)") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:7] AGI("SIP/BTC-primary-000bfa3f", "dialparties.agi") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Caller ID name is 'YYYYY' number is 'YYYYY'
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: CW Ignore is: TRUE
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: CF Ignore is:
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: CW IN_USE/BUSY is: 1
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Methodology of ring is 'random'
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Added extension 1731 to extension map
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Added extension 1732 to extension map
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Added extension 1733 to extension map
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Added extension 1735 to extension map
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Added extension 1730 to extension map
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1731 cf is disabled
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1732 cf is disabled
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1733 cf is disabled
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1735 cf is disabled
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1730 cf is disabled
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1731 do not disturb is disabled
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1732 do not disturb is disabled
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1733 do not disturb is disabled
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1735 has do not disturb enabled, or followme pre-ring returned busy
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1730 do not disturb is disabled
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1731 has ExtensionState: 0
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 1731
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: EXTENSION_STATE: 8 (RINGING)
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1732 has ExtensionState: 8
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 1732
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1732 is not available to be called
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1732 has call waiting disabled
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1733 has ExtensionState: 0
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 1733
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Extension 1730 has ExtensionState: 0
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 1730
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: dialparties.agi: Filtered ARG3: 1731-1733-1730
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] res_agi.c: AGI Script dialparties.agi completed, returning 0
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:28] NoOp("SIP/BTC-primary-000bfa3f", "Returned from dialparties with 3 hunt members to dial") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:29] Set("SIP/BTC-primary-000bfa3f", "HuntLoop=0") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:30] ExecIf("SIP/BTC-primary-000bfa3f", "0?Set(HuntMembers=0)") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:31] GotoIf("SIP/BTC-primary-000bfa3f", "1?a30") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx_builtins.c: Goto (macro-dial,s,34)
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:34] Set("SIP/BTC-primary-000bfa3f", "HuntMember=HuntMember0") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:35] GotoIf("SIP/BTC-primary-000bfa3f", "0?a32:a35") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx_builtins.c: Goto (macro-dial,s,40)
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:40] GotoIf("SIP/BTC-primary-000bfa3f", "0?a36:a50") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx_builtins.c: Goto (macro-dial,s,60)
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:60] NoOp("SIP/BTC-primary-000bfa3f", "Deleting: CALLTRACE/ ") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:61] Goto("SIP/BTC-primary-000bfa3f", "s,huntstart") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx_builtins.c: Goto (macro-dial,s,48)
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:48] NoOp("SIP/BTC-primary-000bfa3f", "Hunt Dial Start") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:49] ExecIf("SIP/BTC-primary-000bfa3f", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:50] ExecIf("SIP/BTC-primary-000bfa3f", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:51] Macro("SIP/BTC-primary-000bfa3f", "dial-hunt-predial-hook,") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial-hunt-predial-hook:1] MacroExit("SIP/BTC-primary-000bfa3f", "") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:52] ExecIf("SIP/BTC-primary-000bfa3f", "0?Set(ds=,20,trwWM(auto-blkvm)g)") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-dial:53] Dial("SIP/BTC-primary-000bfa3f", "SIP/1733,20,trwWM(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] netsock2.c: Using SIP RTP TOS bits 184
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] netsock2.c: Using SIP RTP CoS mark 5
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] app_stack.c: SIP/1733-000bfa46 Internal Gosub(func-apply-sipheaders,s,1) start
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("SIP/1733-000bfa46", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("SIP/1733-000bfa46", "Applying SIP Headers to channel SIP/1733-000bfa46") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@func-apply-sipheaders:3] Set("SIP/1733-000bfa46", "TECH=SIP") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@func-apply-sipheaders:4] Set("SIP/1733-000bfa46", "SIPHEADERKEYS=") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/1733-000bfa46", "0") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] app_while.c: Jumping to priority 13
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@func-apply-sipheaders:14] Return("SIP/1733-000bfa46", "") in new stack
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] app_stack.c: Spawn extension (from-internal, 1498, 1) exited non-zero on 'SIP/1733-000bfa46'
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] app_stack.c: SIP/1733-000bfa46 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] app_dial.c: Called SIP/1733
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] app_dial.c: SIP/1733-000bfa46 is ringing
[2020-10-13 14:02:02] VERBOSE[23911][C-000d12c6] app_dial.c: SIP/1733-000bfa46 is ringing
[2020-10-13 14:02:07] VERBOSE[26986][C-000d12c6] netsock2.c: Using UDPTL TOS bits 184
[2020-10-13 14:02:07] VERBOSE[26986][C-000d12c6] netsock2.c: Using UDPTL CoS mark 5
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] app_dial.c: SIP/1733-000bfa46 answered SIP/BTC-primary-000bfa3f
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-auto-blkvm:1] ExecIf("SIP/1733-000bfa46", "0?Set(CDR(recordingfile)=.wav)") in new stack
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-auto-blkvm:2] Set("SIP/1733-000bfa46", "__MACRO_RESULT=") in new stack
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-auto-blkvm:3] Set("SIP/1733-000bfa46", "CFIGNORE=") in new stack
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-auto-blkvm:4] Set("SIP/1733-000bfa46", "MASTER_CHANNEL(CFIGNORE)=") in new stack
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-auto-blkvm:5] Set("SIP/1733-000bfa46", "FORWARD_CONTEXT=from-internal") in new stack
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-auto-blkvm:6] Set("SIP/1733-000bfa46", "MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal") in new stack
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-auto-blkvm:7] Macro("SIP/1733-000bfa46", "blkvm-clr,") in new stack
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-blkvm-clr:1] Set("SIP/1733-000bfa46", "SHARED(BLKVM,SIP/BTC-primary-000bfa3f)=") in new stack
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-blkvm-clr:2] Set("SIP/1733-000bfa46", "GOSUB_RETVAL=") in new stack
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit("SIP/1733-000bfa46", "") in new stack
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-auto-blkvm:8] ExecIf("SIP/1733-000bfa46", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=1733)") in new stack
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] pbx.c: Executing [s@macro-auto-blkvm:9] ExecIf("SIP/1733-000bfa46", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=1733)") in new stack
[2020-10-13 14:02:07] VERBOSE[25226][C-000d12c6] bridge_channel.c: Channel SIP/1733-000bfa46 joined 'simple_bridge' basic-bridge
[2020-10-13 14:02:07] VERBOSE[23911][C-000d12c6] bridge_channel.c: Channel SIP/BTC-primary-000bfa3f joined 'simple_bridge' basic-bridge
[2020-10-13 14:02:26] DTMF[25226][C-000d12c6] channel.c: DTMF begin '#' received on SIP/1733-000bfa46
This call did not finish until 14:02:12 but extension state of 1733 was not checked again at that time which should be done.