FreePBX 13 to 15 migration-DAHDI analog call issues

Hi everyone,

I’m working on migrating a small office from FreePBX 13 to FreePBX 15 (Asterisk 16). The office has 4 MiTel IP phones with two POTS lines from the PSTN provider (each assigned a DID). The current system runs on a Dell OptiPlex 755 tower with a single TDM400P+/TDM410 PCI card, with 4 x X100M FXO modules for PSTN connectivity. (This is an older tower, hence the PCI support; the replacement hardware/tower is a Lenovo M83 desktop.) Calls inbound can be handled by either POTS line (depending on the called number) but calls outbound use only a single of these POTS lines.

I’ve generated a full backup on the version 13 system and restored it on version 15 system. Because of the newer Lenovo hardware I’m moving to, I had to use a PCIe-to-PCI bridge to permit the transfer of the TDM400P+ POTS card. This appears to work fine, but without successful calls in/out, it’s hard to say for sure (more on that shortly). With the new system up, backup restored, and the same IP address used, the existing IP phones can register and place/receive calls between them on the LAN. Unfortunately, calls in/out with the PSTN are not working.

Calls placed outbound result in one of two behaviors: (1) I immediately hear a message stating “all circuits are busy now,” or (2) as soon as the call rings the called device (mobile phone, for instance), the call disconnects when attempting to answer. This is true regardless of number type (landline/mobile/toll-free, etc.).

Calls placed inbound to either of the DIDs ring the desk phones (as configured), but when the call is answered, I only hear one-way audio: I can hear the external/PSTN caller, but they cannot hear me. When the desk phone (called party) hangs up, the caller stays connected to the call until manually hanging up as well.

Both issues seem codec-related to me (e.g., failure to negotiate codec when RTP stream attempts to nail up/one-way audio), but I can’t determine how that could be. We’re in the United States, so I have configured ulaw under the module settings for the TDM card (under Applications > DAHDI Config).

Rolling the environment back to the old system (FreePBX 13, Dell hardware, physically moving the TDM card once again) results in everything working flawlessly, so there would seem to be a configuration issue somewhere that I’m missing.

I’m very new to Asterisk/FreePBX, so please excuse any obvious oversights or missing information. (My vocational background is in Cisco VoIP.)

I’m attaching outputs from the Asterisk CLI, captured while I was troubleshooting today. Thank you very much in advance for your help on this.

Call from extension 102 (using 717XXX2700 as outbound caller ID) to 717XXX8007 (mobile); call disconnects as soon as it’s answered (note the SIP retransmit messages toward the end):

[root@pbx ~]# asterisk -rx "sip show peers"
Name/username             Host                                    Dyn Forcerport Comedia    ACL Port     Status      Description
101/101                   192.168.1.154                            D  No         No          A  5060     OK (31 ms)
102/102                   192.168.1.247                            D  No         No          A  5060     OK (9 ms)
103/103                   192.168.1.115                            D  No         No          A  5060     OK (30 ms)
104/104                   192.168.1.116                            D  No         No          A  5060     OK (31 ms)
199/199                   192.168.1.6                              D  No         No          A  5060     OK (14 ms)
5 sip peers [Monitored: 5 online, 0 offline Unmonitored: 0 online, 0 offline]

pbx*CLI>
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
       > 0x7f43c005a460 -- Strict RTP learning after remote address set to: 192.168.1.247:3000
  == Extension Changed 102[ext-local] new state InUse for Notify User 102
  == Extension Changed 102[ext-local] new state InUse for Notify User 103
  == Extension Changed 102[ext-local] new state InUse for Notify User 104
    -- Executing [717XXX8007@from-internal:1] Macro("SIP/102-00000000", "user-callerid,LIMIT,EXTERNAL,") in new stack
[2020-12-31 14:42:09] WARNING[4330][C-00000001]: app_macro.c:274 _macro_exec: Macro() is deprecated and will be removed from a future version of Asterisk.
[2020-12-31 14:42:09] WARNING[4330][C-00000001]: app_macro.c:275 _macro_exec: Dialplan should be updated to use Gosub instead.
  == Extension Changed 102[ext-local] new state InUse for Notify User 101
    -- Executing [s@macro-user-callerid:1] Set("SIP/102-00000000", "TOUCH_MONITOR=1609443729.0") in new stack
    -- Executing [s@macro-user-callerid:2] Set("SIP/102-00000000", "AMPUSER=102") in new stack
    -- Executing [s@macro-user-callerid:3] Set("SIP/102-00000000", "HOTDESCKCHAN=102-00000000") in new stack
    -- Executing [s@macro-user-callerid:4] Set("SIP/102-00000000", "HOTDESKEXTEN=102") in new stack
    -- Executing [s@macro-user-callerid:5] Set("SIP/102-00000000", "HOTDESKCALL=0") in new stack
    -- Executing [s@macro-user-callerid:6] ExecIf("SIP/102-00000000", "0?Set(HOTDESKCALL=1)") in new stack
    -- Executing [s@macro-user-callerid:7] ExecIf("SIP/102-00000000", "0?Set(CALLERID(name)=)") in new stack
    -- Executing [s@macro-user-callerid:8] GotoIf("SIP/102-00000000", "0?report") in new stack
    -- Executing [s@macro-user-callerid:9] ExecIf("SIP/102-00000000", "1?Set(REALCALLERIDNUM=102)") in new stack
    -- Executing [s@macro-user-callerid:10] Set("SIP/102-00000000", "AMPUSER=102") in new stack
    -- Executing [s@macro-user-callerid:11] GotoIf("SIP/102-00000000", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:12] Set("SIP/102-00000000", "AMPUSERCIDNAME=Emily") in new stack
    -- Executing [s@macro-user-callerid:13] ExecIf("SIP/102-00000000", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
    -- Executing [s@macro-user-callerid:14] GotoIf("SIP/102-00000000", "0?report") in new stack
    -- Executing [s@macro-user-callerid:15] Set("SIP/102-00000000", "AMPUSERCID=102") in new stack
    -- Executing [s@macro-user-callerid:16] Set("SIP/102-00000000", "__DIAL_OPTIONS=Ttr") in new stack
    -- Executing [s@macro-user-callerid:17] Set("SIP/102-00000000", "CALLERID(all)="Emily" <102>") in new stack
    -- Executing [s@macro-user-callerid:18] ExecIf("SIP/102-00000000", "0?Set(CUSDIAL=)") in new stack
    -- Executing [s@macro-user-callerid:19] ExecIf("SIP/102-00000000", "0?Set(CALLERID(all)="Emily" <102>)") in new stack
    -- Executing [s@macro-user-callerid:20] GotoIf("SIP/102-00000000", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:21] ExecIf("SIP/102-00000000", "1?Set(GROUP(concurrency_limit)=102)") in new stack
    -- Executing [s@macro-user-callerid:22] ExecIf("SIP/102-00000000", "0?Set(CHANNEL(language)=)") in new stack
    -- Executing [s@macro-user-callerid:23] NoOp("SIP/102-00000000", "Macro Depth is 1") in new stack
    -- Executing [s@macro-user-callerid:24] GotoIf("SIP/102-00000000", "1?report2:macroerror") in new stack
    -- Goto (macro-user-callerid,s,25)
    -- Executing [s@macro-user-callerid:25] GotoIf("SIP/102-00000000", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,44)
    -- Executing [s@macro-user-callerid:44] Set("SIP/102-00000000", "CALLERID(number)=102") in new stack
    -- Executing [s@macro-user-callerid:45] Set("SIP/102-00000000", "CALLERID(name)=Emily") in new stack
    -- Executing [s@macro-user-callerid:46] GotoIf("SIP/102-00000000", "0?cnum") in new stack
    -- Executing [s@macro-user-callerid:47] Set("SIP/102-00000000", "CDR(cnam)=Emily") in new stack
    -- Executing [s@macro-user-callerid:48] Set("SIP/102-00000000", "CDR(cnum)=102") in new stack
    -- Executing [s@macro-user-callerid:49] Set("SIP/102-00000000", "CHANNEL(language)=en") in new stack
    -- Executing [717XXX8007@from-internal:2] Gosub("SIP/102-00000000", "sub-record-check,s,1(out,717XXX8007,dontcare)") in new stack
    -- Executing [s@sub-record-check:1] GotoIf("SIP/102-00000000", "0?initialized") in new stack
    -- Executing [s@sub-record-check:2] Set("SIP/102-00000000", "__REC_STATUS=INITIALIZED") in new stack
    -- Executing [s@sub-record-check:3] Set("SIP/102-00000000", "NOW=1609443729") in new stack
    -- Executing [s@sub-record-check:4] Set("SIP/102-00000000", "__DAY=31") in new stack
    -- Executing [s@sub-record-check:5] Set("SIP/102-00000000", "__MONTH=12") in new stack
    -- Executing [s@sub-record-check:6] Set("SIP/102-00000000", "__YEAR=2020") in new stack
    -- Executing [s@sub-record-check:7] Set("SIP/102-00000000", "__TIMESTR=20201231-144209") in new stack
    -- Executing [s@sub-record-check:8] Set("SIP/102-00000000", "__FROMEXTEN=102") in new stack
    -- Executing [s@sub-record-check:9] Set("SIP/102-00000000", "__MON_FMT=wav") in new stack
    -- Executing [s@sub-record-check:10] NoOp("SIP/102-00000000", "Recordings initialized") in new stack
    -- Executing [s@sub-record-check:11] ExecIf("SIP/102-00000000", "0?Set(ARG3=dontcare)") in new stack
    -- Executing [s@sub-record-check:12] Set("SIP/102-00000000", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [s@sub-record-check:13] ExecIf("SIP/102-00000000", "0?Set(REC_STATUS=NO)") in new stack
    -- Executing [s@sub-record-check:14] GotoIf("SIP/102-00000000", "3?checkaction") in new stack
    -- Goto (sub-record-check,s,17)
    -- Executing [s@sub-record-check:17] GotoIf("SIP/102-00000000", "1?sub-record-check,out,1") in new stack
    -- Goto (sub-record-check,out,1)
    -- Executing [out@sub-record-check:1] NoOp("SIP/102-00000000", "Outbound Recording Check from 102 to 717XXX8007") in new stack
    -- Executing [out@sub-record-check:2] Set("SIP/102-00000000", "RECMODE=dontcare") in new stack
    -- Executing [out@sub-record-check:3] ExecIf("SIP/102-00000000", "1?Goto(routewins)") in new stack
    -- Goto (sub-record-check,out,7)
    -- Executing [out@sub-record-check:7] Gosub("SIP/102-00000000", "recordcheck,1(dontcare,out,717XXX8007)") in new stack
    -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/102-00000000", "Starting recording check against dontcare") in new stack
    -- Executing [recordcheck@sub-record-check:2] Goto("SIP/102-00000000", "dontcare") in new stack
    -- Goto (sub-record-check,recordcheck,3)
    -- Executing [recordcheck@sub-record-check:3] Return("SIP/102-00000000", "") in new stack
    -- Executing [out@sub-record-check:8] Return("SIP/102-00000000", "") in new stack
    -- Executing [717XXX8007@from-internal:3] ExecIf("SIP/102-00000000", "0 ?Set(CDR(accountcode)=)") in new stack
    -- Executing [717XXX8007@from-internal:4] Set("SIP/102-00000000", "_ROUTEID=1") in new stack
    -- Executing [717XXX8007@from-internal:5] Set("SIP/102-00000000", "_ROUTENAME=Outgoing") in new stack
    -- Executing [717XXX8007@from-internal:6] Set("SIP/102-00000000", "MOHCLASS=default") in new stack
    -- Executing [717XXX8007@from-internal:7] Set("SIP/102-00000000", "_CALLERIDNAMEINTERNAL=Emily") in new stack
    -- Executing [717XXX8007@from-internal:8] Set("SIP/102-00000000", "_CALLERIDNUMINTERNAL=102") in new stack
    -- Executing [717XXX8007@from-internal:9] Set("SIP/102-00000000", "_EMAILNOTIFICATION=FALSE") in new stack
    -- Executing [717XXX8007@from-internal:10] Set("SIP/102-00000000", "_NODEST=") in new stack
    -- Executing [717XXX8007@from-internal:11] Macro("SIP/102-00000000", "dialout-trunk,1,717XXX8007,,off") in new stack
    -- Executing [s@macro-dialout-trunk:1] Set("SIP/102-00000000", "DIAL_TRUNK=1") in new stack
    -- Executing [s@macro-dialout-trunk:2] ExecIf("SIP/102-00000000", "0?Set(DIAL_OPTIONS=tr)") in new stack
    -- Executing [s@macro-dialout-trunk:3] GosubIf("SIP/102-00000000", "0?sub-pincheck,s,1()") in new stack
    -- Executing [s@macro-dialout-trunk:4] ExecIf("SIP/102-00000000", "0?Set(CALLERID(num)=102)") in new stack
    -- Executing [s@macro-dialout-trunk:5] GotoIf("SIP/102-00000000", "0?disabletrunk,1") in new stack
    -- Executing [s@macro-dialout-trunk:6] Set("SIP/102-00000000", "DIAL_NUMBER=717XXX8007") in new stack
    -- Executing [s@macro-dialout-trunk:7] Set("SIP/102-00000000", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
    -- Executing [s@macro-dialout-trunk:8] Set("SIP/102-00000000", "OUTBOUND_GROUP=OUT_1") in new stack
    -- Executing [s@macro-dialout-trunk:9] Set("SIP/102-00000000", "DIAL_TRUNK_OPTIONS=T") in new stack
    -- Executing [s@macro-dialout-trunk:10] GotoIf("SIP/102-00000000", "1?nomax") in new stack
    -- Goto (macro-dialout-trunk,s,12)
    -- Executing [s@macro-dialout-trunk:12] GotoIf("SIP/102-00000000", "0?skipoutcid") in new stack
    -- Executing [s@macro-dialout-trunk:13] Macro("SIP/102-00000000", "outbound-callerid,1") in new stack
    -- Executing [s@macro-outbound-callerid:1] NoOp("SIP/102-00000000", "102") in new stack
    -- Executing [s@macro-outbound-callerid:2] NoOp("SIP/102-00000000", "") in new stack
    -- Executing [s@macro-outbound-callerid:3] NoOp("SIP/102-00000000", "") in new stack
    -- Executing [s@macro-outbound-callerid:4] ExecIf("SIP/102-00000000", "0?Set(CALLERPRES(name-pres)=)") in new stack
    -- Executing [s@macro-outbound-callerid:5] ExecIf("SIP/102-00000000", "0?Set(CALLERPRES(num-pres)=)") in new stack
    -- Executing [s@macro-outbound-callerid:6] Set("SIP/102-00000000", "HOTDESCKCHAN=102-00000000") in new stack
    -- Executing [s@macro-outbound-callerid:7] Set("SIP/102-00000000", "HOTDESKEXTEN=102") in new stack
    -- Executing [s@macro-outbound-callerid:8] Set("SIP/102-00000000", "HOTDESKCALL=0") in new stack
    -- Executing [s@macro-outbound-callerid:9] ExecIf("SIP/102-00000000", "0?Set(HOTDESKCALL=1)") in new stack
    -- Executing [s@macro-outbound-callerid:10] ExecIf("SIP/102-00000000", "0?Set(CALLERID(name)=)") in new stack
    -- Executing [s@macro-outbound-callerid:11] Set("SIP/102-00000000", "ALLOWTHISROUTE=NO") in new stack
    -- Executing [s@macro-outbound-callerid:12] ExecIf("SIP/102-00000000", "0?Set(ALLOWTHISROUTE=YES)") in new stack
    -- Executing [s@macro-outbound-callerid:13] ExecIf("SIP/102-00000000", "0?Hangup()") in new stack
    -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/102-00000000", "0?Set(REALCALLERIDNUM=102)") in new stack
    -- Executing [s@macro-outbound-callerid:15] ExecIf("SIP/102-00000000", "0?Set(AMPUSER=102)") in new stack
    -- Executing [s@macro-outbound-callerid:16] GotoIf("SIP/102-00000000", "1?normcid") in new stack
    -- Goto (macro-outbound-callerid,s,20)
    -- Executing [s@macro-outbound-callerid:20] Set("SIP/102-00000000", "USEROUTCID=") in new stack
    -- Executing [s@macro-outbound-callerid:21] Set("SIP/102-00000000", "EMERGENCYCID=") in new stack
    -- Executing [s@macro-outbound-callerid:22] ExecIf("SIP/102-00000000", "0?Set(EMERGENCYCID=)") in new stack
    -- Executing [s@macro-outbound-callerid:23] Set("SIP/102-00000000", "TRUNKOUTCID=") in new stack
    -- Executing [s@macro-outbound-callerid:24] GotoIf("SIP/102-00000000", "1?trunkcid") in new stack
    -- Goto (macro-outbound-callerid,s,30)
    -- Executing [s@macro-outbound-callerid:30] ExecIf("SIP/102-00000000", "0?Set(CALLERID(all)=)") in new stack
    -- Executing [s@macro-outbound-callerid:31] ExecIf("SIP/102-00000000", "0?Set(CALLERID(all)=)") in new stack
    -- Executing [s@macro-outbound-callerid:32] ExecIf("SIP/102-00000000", "0?Set(CALLERID(all)=)") in new stack
    -- Executing [s@macro-outbound-callerid:33] ExecIf("SIP/102-00000000", "0?Set(CALLERID(all)=102)") in new stack
    -- Executing [s@macro-outbound-callerid:34] Set("SIP/102-00000000", "TIOHIDE=no") in new stack
    -- Executing [s@macro-outbound-callerid:35] ExecIf("SIP/102-00000000", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:36] ExecIf("SIP/102-00000000", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:37] ExecIf("SIP/102-00000000", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:38] ExecIf("SIP/102-00000000", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:39] Set("SIP/102-00000000", "CDR(outbound_cnum)=102") in new stack
    -- Executing [s@macro-outbound-callerid:40] Set("SIP/102-00000000", "CDR(outbound_cnam)=Emily") in new stack
    -- Executing [s@macro-dialout-trunk:14] GosubIf("SIP/102-00000000", "0?sub-flp-1,s,1()") in new stack
    -- Executing [s@macro-dialout-trunk:15] Set("SIP/102-00000000", "OUTNUM=717XXX8007") in new stack
    -- Executing [s@macro-dialout-trunk:16] Set("SIP/102-00000000", "custom=DAHDI/g0") in new stack
    -- Executing [s@macro-dialout-trunk:17] ExecIf("SIP/102-00000000", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)") in new stack
    -- Executing [s@macro-dialout-trunk:18] ExecIf("SIP/102-00000000", "0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))") in new stack
    -- Executing [s@macro-dialout-trunk:19] Macro("SIP/102-00000000", "dialout-trunk-predial-hook,") in new stack
    -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/102-00000000", "") in new stack
    -- Executing [s@macro-dialout-trunk:20] GotoIf("SIP/102-00000000", "0?skipcrm") in new stack
    -- Executing [s@macro-dialout-trunk:21] Set("SIP/102-00000000", "__CRM_DIRECTION=OUTBOUND") in new stack
    -- Executing [s@macro-dialout-trunk:22] Set("SIP/102-00000000", "__CRM_DESTINATION=717XXX8007") in new stack
    -- Executing [s@macro-dialout-trunk:23] Set("SIP/102-00000000", "__CRM_SOURCE=102") in new stack
    -- Executing [s@macro-dialout-trunk:24] AGI("SIP/102-00000000", "agi://127.0.0.1/sangomacrm.agi") in new stack
    -- <SIP/102-00000000>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
    -- Executing [s@macro-dialout-trunk:25] Set("SIP/102-00000000", "CHANNEL(hangup_handler_push)=crm-hangup,s,1") in new stack
    -- Executing [s@macro-dialout-trunk:26] NoOp("SIP/102-00000000", "CRM Finished") in new stack
    -- Executing [s@macro-dialout-trunk:27] GotoIf("SIP/102-00000000", "0?bypass,1") in new stack
    -- Executing [s@macro-dialout-trunk:28] ExecIf("SIP/102-00000000", "1?Set(CONNECTEDLINE(num,i)=717XXX8007)") in new stack
    -- Executing [s@macro-dialout-trunk:29] ExecIf("SIP/102-00000000", "1?Set(CONNECTEDLINE(name,i)=CID:102)") in new stack
    -- Executing [s@macro-dialout-trunk:30] ExecIf("SIP/102-00000000", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)102)") in new stack
    -- Executing [s@macro-dialout-trunk:31] GotoIf("SIP/102-00000000", "0?customtrunk") in new stack
    -- Executing [s@macro-dialout-trunk:32] ExecIf("SIP/102-00000000", "0?Set(DIAL_TRUNK_OPTIONS=)") in new stack
    -- Executing [s@macro-dialout-trunk:33] Set("SIP/102-00000000", "HASH(__SIPHEADERS,Alert-Info)=unset") in new stack
    -- Executing [s@macro-dialout-trunk:34] Dial("SIP/102-00000000", "DAHDI/g0/717XXX8007,300,Tb(func-apply-sipheaders^s^1,(1))U(sub-send-obroute-email^717XXX8007^717XXX8007^1^1609443729^Emily^102)") in new stack
    -- DAHDI/1-1 Internal Gosub(func-apply-sipheaders,s,1(1)) start
    -- Executing [s@func-apply-sipheaders:1] ExecIf("DAHDI/1-1", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
    -- Executing [s@func-apply-sipheaders:2] NoOp("DAHDI/1-1", "Applying SIP Headers to channel DAHDI/1-1") in new stack
    -- Executing [s@func-apply-sipheaders:3] Set("DAHDI/1-1", "TECH=DAHDI") in new stack
    -- Executing [s@func-apply-sipheaders:4] Set("DAHDI/1-1", "SIPHEADERKEYS=Alert-Info") in new stack
    -- Executing [s@func-apply-sipheaders:5] While("DAHDI/1-1", "1") in new stack
    -- Executing [s@func-apply-sipheaders:6] Set("DAHDI/1-1", "sipheader=unset") in new stack
    -- Executing [s@func-apply-sipheaders:7] ExecIf("DAHDI/1-1", "0?SIPRemoveHeader(Alert-Info:)") in new stack
    -- Executing [s@func-apply-sipheaders:8] ExecIf("DAHDI/1-1", "0?Set(sipheader=<http://127.0.0.1>;info=unset)") in new stack
    -- Executing [s@func-apply-sipheaders:9] ExecIf("DAHDI/1-1", "0?Set(sipheader=<http://127.0.0.1>unset)") in new stack
    -- Executing [s@func-apply-sipheaders:10] ExecIf("DAHDI/1-1", "0?SIPAddHeader(Alert-Info:unset)") in new stack
    -- Executing [s@func-apply-sipheaders:11] EndWhile("DAHDI/1-1", "") in new stack
    -- Executing [s@func-apply-sipheaders:5] While("DAHDI/1-1", "0") in new stack
    -- Executing [s@func-apply-sipheaders:12] Return("DAHDI/1-1", "") in new stack
  == Spawn extension (from-analog, 717XXX8007, 1) exited non-zero on 'DAHDI/1-1'
    -- DAHDI/1-1 Internal Gosub(func-apply-sipheaders,s,1(1)) complete GOSUB_RETVAL=
    -- Called DAHDI/g0/717XXX8007
    -- DAHDI/1-1 answered SIP/102-00000000
    -- DAHDI/1-1 Internal Gosub(sub-send-obroute-email,s,1(717XXX8007,717XXX8007,1,1609443729,Emily,102)) start
    -- Executing [s@sub-send-obroute-email:1] GotoIf("DAHDI/1-1", "0?sendEmail") in new stack
    -- Executing [s@sub-send-obroute-email:2] NoOp("DAHDI/1-1", "email notifications disabled..exiting.") in new stack
    -- Executing [s@sub-send-obroute-email:3] Return("DAHDI/1-1", "") in new stack
  == Spawn extension (from-analog, , 1) exited non-zero on 'DAHDI/1-1'
    -- DAHDI/1-1 Internal Gosub(sub-send-obroute-email,s,1(717XXX8007,717XXX8007,1,1609443729,Emily,102)) complete GOSUB_RETVAL=
    -- Channel DAHDI/1-1 joined 'simple_bridge' basic-bridge <0e62d4f8-b422-4142-ac8d-7434280b3df0>
    -- Channel SIP/102-00000000 joined 'simple_bridge' basic-bridge <0e62d4f8-b422-4142-ac8d-7434280b3df0>
[2020-12-31 14:42:19] WARNING[2783]: chan_sip.c:4142 retrans_pkt: Retransmission timeout reached on transmission 1ef35e1a7f719b85 for seqno 28841 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6399ms with no response
[2020-12-31 14:42:19] WARNING[2783]: chan_sip.c:4166 retrans_pkt: Hanging up call 1ef35e1a7f719b85 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
    -- Channel SIP/102-00000000 left 'simple_bridge' basic-bridge <0e62d4f8-b422-4142-ac8d-7434280b3df0>
    -- Channel DAHDI/1-1 left 'simple_bridge' basic-bridge <0e62d4f8-b422-4142-ac8d-7434280b3df0>
  == Spawn extension (macro-dialout-trunk, s, 34) exited non-zero on 'SIP/102-00000000' in macro 'dialout-trunk'
    -- Hanging up on 'DAHDI/1-1'
    -- Hungup 'DAHDI/1-1'
  == Spawn extension (from-internal, 717XXX8007, 11) exited non-zero on 'SIP/102-00000000'
    -- Executing [h@from-internal:1] Macro("SIP/102-00000000", "hangupcall") in new stack
    -- Executing [s@macro-hangupcall:1] GotoIf("SIP/102-00000000", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,3)
    -- Executing [s@macro-hangupcall:3] ExecIf("SIP/102-00000000", "0?Set(CDR(recordingfile)=)") in new stack
    -- Executing [s@macro-hangupcall:4] NoOp("SIP/102-00000000", "DAHDI/1-1 montior file= ") in new stack
    -- Executing [s@macro-hangupcall:5] GotoIf("SIP/102-00000000", "1?skipagi") in new stack
    -- Goto (macro-hangupcall,s,7)
    -- Executing [s@macro-hangupcall:7] Hangup("SIP/102-00000000", "") in new stack
  == Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'SIP/102-00000000' in macro 'hangupcall'
  == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/102-00000000'
    -- SIP/102-00000000 Internal Gosub(crm-hangup,s,1) start
    -- Executing [s@crm-hangup:1] NoOp("SIP/102-00000000", "Sending Hangup to CRM") in new stack
    -- Executing [s@crm-hangup:2] NoOp("SIP/102-00000000", "HANGUP CAUSE: 18") in new stack
    -- Executing [s@crm-hangup:3] ExecIf("SIP/102-00000000", "0?Set(__CRM_VOICEMAIL=)") in new stack
    -- Executing [s@crm-hangup:4] NoOp("SIP/102-00000000", "MASTER CHANNEL: 1609443729.0 = 1609443729.0") in new stack
    -- Executing [s@crm-hangup:5] GotoIf("SIP/102-00000000", "0?return") in new stack
    -- Executing [s@crm-hangup:6] Set("SIP/102-00000000", "__CRM_HANGUP=1") in new stack
    -- Executing [s@crm-hangup:7] AGI("SIP/102-00000000", "agi://127.0.0.1/sangomacrm.agi") in new stack
    -- <SIP/102-00000000>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
    -- Executing [s@crm-hangup:8] Return("SIP/102-00000000", "") in new stack
  == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/102-00000000'
    -- SIP/102-00000000 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
  == Extension Changed 102[ext-local] new state Idle for Notify User 102
  == Extension Changed 102[ext-local] new state Idle for Notify User 103
  == Extension Changed 102[ext-local] new state Idle for Notify User 104
  == Extension Changed 102[ext-local] new state Idle for Notify User 101
pbx*CLI>

Additional logs below:

Call placed to 717XXX2700 (rings all extensions–101 through 104) from 717XXX8007 (mobile); one-way audio when answered–ext. 102 (called party) can hear caller (8007), but not vice versa:

[root@pbx ~]# asterisk -Rvvvvvvvvvv
Asterisk 16.13.0, Copyright (C) 1999 - 2018, Digium, Inc. and others.
Created by Mark Spencer <[email protected]>
Asterisk comes with ABSOLUTELY NO WARRANTY; type 'core show warranty' for details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type 'core show license' for details.
=========================================================================
Connected to Asterisk 16.13.0 currently running on pbx (pid = 2666)
    -- Starting simple switch on 'DAHDI/1-1'
    -- Executing [s@from-analog:1] NoOp("DAHDI/1-1", "Entering from-dahdi with DID == ") in new stack
    -- Executing [s@from-analog:2] Ringing("DAHDI/1-1", "") in new stack
    -- Executing [s@from-analog:3] Set("DAHDI/1-1", "DID=s") in new stack
    -- Executing [s@from-analog:4] NoOp("DAHDI/1-1", "DID is now s") in new stack
    -- Executing [s@from-analog:5] GotoIf("DAHDI/1-1", "1?dahdiok:checkzap") in new stack
    -- Goto (from-analog,s,9)
    -- Executing [s@from-analog:9] NoOp("DAHDI/1-1", "Is a DAHDi Channel") in new stack
    -- Executing [s@from-analog:10] Set("DAHDI/1-1", "CHAN=1-1") in new stack
    -- Executing [s@from-analog:11] Set("DAHDI/1-1", "CHAN=1") in new stack
    -- Executing [s@from-analog:12] Macro("DAHDI/1-1", "from-dahdi-1,s,1") in new stack
    -- Executing [s@macro-from-dahdi-1:1] NoOp("DAHDI/1-1", "Entering macro-from-dahdi-1 with DID = s and setting to: 717XXX2700") in new stack
    -- Executing [s@macro-from-dahdi-1:2] Set("DAHDI/1-1", "__FROM_DID=717XXX2700") in new stack
    -- Executing [s@macro-from-dahdi-1:3] Goto("DAHDI/1-1", "from-trunk,717XXX2700,1") in new stack
    -- Goto (from-trunk,717XXX2700,1)
  == Channel 'DAHDI/1-1' jumping out of macro 'from-dahdi-1'
    -- Executing [717XXX2700@from-trunk:1] NoOp("DAHDI/1-1", "Catch-All DID Match - Found 717XXX2700 - You probably want a DID for this.") in new stack
    -- Executing [717XXX2700@from-trunk:2] Set("DAHDI/1-1", "__FROM_DID=717XXX2700") in new stack
    -- Executing [717XXX2700@from-trunk:3] Goto("DAHDI/1-1", "ext-did,s,1") in new stack
    -- Goto (ext-did,s,1)
    -- Executing [s@ext-did:1] Set("DAHDI/1-1", "__DIRECTION=INBOUND") in new stack
    -- Executing [s@ext-did:2] Gosub("DAHDI/1-1", "sub-record-check,s,1(in,s,dontcare)") in new stack
    -- Executing [s@sub-record-check:1] GotoIf("DAHDI/1-1", "0?initialized") in new stack
    -- Executing [s@sub-record-check:2] Set("DAHDI/1-1", "__REC_STATUS=INITIALIZED") in new stack
    -- Executing [s@sub-record-check:3] Set("DAHDI/1-1", "NOW=1609443826") in new stack
    -- Executing [s@sub-record-check:4] Set("DAHDI/1-1", "__DAY=31") in new stack
    -- Executing [s@sub-record-check:5] Set("DAHDI/1-1", "__MONTH=12") in new stack
    -- Executing [s@sub-record-check:6] Set("DAHDI/1-1", "__YEAR=2020") in new stack
    -- Executing [s@sub-record-check:7] Set("DAHDI/1-1", "__TIMESTR=20201231-144346") in new stack
    -- Executing [s@sub-record-check:8] Set("DAHDI/1-1", "__FROMEXTEN=unknown") in new stack
    -- Executing [s@sub-record-check:9] Set("DAHDI/1-1", "__MON_FMT=wav") in new stack
    -- Executing [s@sub-record-check:10] NoOp("DAHDI/1-1", "Recordings initialized") in new stack
    -- Executing [s@sub-record-check:11] ExecIf("DAHDI/1-1", "0?Set(ARG3=dontcare)") in new stack
    -- Executing [s@sub-record-check:12] Set("DAHDI/1-1", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [s@sub-record-check:13] ExecIf("DAHDI/1-1", "0?Set(REC_STATUS=NO)") in new stack
    -- Executing [s@sub-record-check:14] GotoIf("DAHDI/1-1", "2?checkaction") in new stack
    -- Goto (sub-record-check,s,17)
    -- Executing [s@sub-record-check:17] GotoIf("DAHDI/1-1", "1?sub-record-check,in,1") in new stack
    -- Goto (sub-record-check,in,1)
    -- Executing [in@sub-record-check:1] NoOp("DAHDI/1-1", "Inbound Recording Check to s") in new stack
    -- Executing [in@sub-record-check:2] Set("DAHDI/1-1", "FROMEXTEN=unknown") in new stack
    -- Executing [in@sub-record-check:3] ExecIf("DAHDI/1-1", "11?Set(FROMEXTEN=1717XXX8007)") in new stack
    -- Executing [in@sub-record-check:4] Gosub("DAHDI/1-1", "recordcheck,1(dontcare,in,s)") in new stack
    -- Executing [recordcheck@sub-record-check:1] NoOp("DAHDI/1-1", "Starting recording check against dontcare") in new stack
    -- Executing [recordcheck@sub-record-check:2] Goto("DAHDI/1-1", "dontcare") in new stack
    -- Goto (sub-record-check,recordcheck,3)
    -- Executing [recordcheck@sub-record-check:3] Return("DAHDI/1-1", "") in new stack
    -- Executing [in@sub-record-check:5] Return("DAHDI/1-1", "") in new stack
    -- Executing [s@ext-did:3] Set("DAHDI/1-1", "CHANNEL(tonezone)=us") in new stack
    -- Executing [s@ext-did:4] ExecIf("DAHDI/1-1", "0?Set(__FROM_DID=s)") in new stack
    -- Executing [s@ext-did:5] Set("DAHDI/1-1", "returnhere=1") in new stack
    -- Executing [s@ext-did:6] Gosub("DAHDI/1-1", "app-blacklist-check,s,1()") in new stack
    -- Executing [s@app-blacklist-check:1] GotoIf("DAHDI/1-1", "0?blacklisted") in new stack
    -- Executing [s@app-blacklist-check:2] Set("DAHDI/1-1", "CALLED_BLACKLIST=1") in new stack
    -- Executing [s@app-blacklist-check:3] Return("DAHDI/1-1", "") in new stack
    -- Executing [s@ext-did:7] Set("DAHDI/1-1", "CDR(did)=717XXX2700") in new stack
    -- Executing [s@ext-did:8] GotoIf("DAHDI/1-1", "0?") in new stack
    -- Executing [s@ext-did:9] ExecIf("DAHDI/1-1", "0 ?Set(CALLERID(name)=1717XXX8007)") in new stack
    -- Executing [s@ext-did:10] Set("DAHDI/1-1", "__MOHCLASS=") in new stack
    -- Executing [s@ext-did:11] Set("DAHDI/1-1", "__REVERSAL_REJECT=FALSE") in new stack
    -- Executing [s@ext-did:12] GotoIf("DAHDI/1-1", "1?post-reverse-charge") in new stack
    -- Goto (ext-did,s,14)
    -- Executing [s@ext-did:14] NoOp("DAHDI/1-1", "") in new stack
    -- Executing [s@ext-did:15] Set("DAHDI/1-1", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
    -- Executing [s@ext-did:16] Set("DAHDI/1-1", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
    -- Executing [s@ext-did:17] Set("DAHDI/1-1", "CALLERID(name-pres)=allowed_not_screened") in new stack
    -- Executing [s@ext-did:18] Set("DAHDI/1-1", "CALLERID(num-pres)=allowed_not_screened") in new stack
    -- Executing [s@ext-did:19] NoOp("DAHDI/1-1", "CallerID Entry Point") in new stack
    -- Executing [s@ext-did:20] Set("DAHDI/1-1", "__CRM_DIRECTION=INBOUND") in new stack
    -- Executing [s@ext-did:21] Set("DAHDI/1-1", "__CRM_SOURCE=1717XXX8007") in new stack
    -- Executing [s@ext-did:22] Set("DAHDI/1-1", "__CRM_LINKEDID=1609443824.2") in new stack
    -- Executing [s@ext-did:23] AGI("DAHDI/1-1", "agi://127.0.0.1/sangomacrm.agi,true") in new stack
    -- <DAHDI/1-1>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
    -- Executing [s@ext-did:24] ExecIf("DAHDI/1-1", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
    -- Executing [s@ext-did:25] Goto("DAHDI/1-1", "app-daynight,0,1") in new stack
    -- Goto (app-daynight,0,1)
    -- Executing [0@app-daynight:1] GotoIf("DAHDI/1-1", "0?ivr-3,s,1:timeconditions,1,1") in new stack
    -- Goto (timeconditions,1,1)
    -- Executing [1@timeconditions:1] Set("DAHDI/1-1", "DB(TC/1/INUSESTATE)=INUSE") in new stack
    -- Executing [1@timeconditions:2] Set("DAHDI/1-1", "DB(TC/1/NOT_INUSESTATE)=NOT_INUSE") in new stack
    -- Executing [1@timeconditions:3] NoOp("DAHDI/1-1", "TIMENOW: 14:43,Thu,31,Dec") in new stack
    -- Executing [1@timeconditions:4] NoOp("DAHDI/1-1", "TIMEMATCHED: TRUE") in new stack
    -- Executing [1@timeconditions:5] GotoIfTime("DAHDI/1-1", "08:00-03:00,mon-fri,*,*?truestate") in new stack
    -- Goto (timeconditions,1,14)
    -- Executing [1@timeconditions:14] GotoIf("DAHDI/1-1", "0?falsegoto") in new stack
    -- Executing [1@timeconditions:15] ExecIf("DAHDI/1-1", "0?Set(DB(TC/1)=)") in new stack
    -- Executing [1@timeconditions:16] Set("DAHDI/1-1", "DEVICE_STATE(Custom:TC1)=NOT_INUSE") in new stack
    -- Executing [1@timeconditions:17] ExecIf("DAHDI/1-1", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack
    -- Executing [1@timeconditions:18] GotoIf("DAHDI/1-1", "1?ext-group,150,1") in new stack
    -- Goto (ext-group,150,1)
    -- Executing [150@ext-group:1] GotoIf("DAHDI/1-1", "0?cid") in new stack
    -- Executing [150@ext-group:2] PlayTones("DAHDI/1-1", "ring") in new stack
    -- Executing [150@ext-group:3] Progress("DAHDI/1-1", "") in new stack
    -- Executing [150@ext-group:4] Macro("DAHDI/1-1", "user-callerid,") in new stack
    -- Executing [s@macro-user-callerid:1] Set("DAHDI/1-1", "TOUCH_MONITOR=1609443824.2") in new stack
    -- Executing [s@macro-user-callerid:2] Set("DAHDI/1-1", "AMPUSER=1717XXX8007") in new stack
    -- Executing [s@macro-user-callerid:3] Set("DAHDI/1-1", "HOTDESCKCHAN=1-1") in new stack
    -- Executing [s@macro-user-callerid:4] Set("DAHDI/1-1", "HOTDESKEXTEN=1") in new stack
    -- Executing [s@macro-user-callerid:5] Set("DAHDI/1-1", "HOTDESKCALL=0") in new stack
    -- Executing [s@macro-user-callerid:6] ExecIf("DAHDI/1-1", "0?Set(HOTDESKCALL=1)") in new stack
    -- Executing [s@macro-user-callerid:7] ExecIf("DAHDI/1-1", "0?Set(CALLERID(name)=)") in new stack
    -- Executing [s@macro-user-callerid:8] GotoIf("DAHDI/1-1", "0?report") in new stack
    -- Executing [s@macro-user-callerid:9] ExecIf("DAHDI/1-1", "1?Set(REALCALLERIDNUM=1717XXX8007)") in new stack
    -- Executing [s@macro-user-callerid:10] Set("DAHDI/1-1", "AMPUSER=") in new stack
    -- Executing [s@macro-user-callerid:11] GotoIf("DAHDI/1-1", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:12] Set("DAHDI/1-1", "AMPUSERCIDNAME=") in new stack
    -- Executing [s@macro-user-callerid:13] ExecIf("DAHDI/1-1", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
    -- Executing [s@macro-user-callerid:14] GotoIf("DAHDI/1-1", "1?report") in new stack
    -- Goto (macro-user-callerid,s,23)
    -- Executing [s@macro-user-callerid:23] NoOp("DAHDI/1-1", "Macro Depth is 1") in new stack
    -- Executing [s@macro-user-callerid:24] GotoIf("DAHDI/1-1", "1?report2:macroerror") in new stack
    -- Goto (macro-user-callerid,s,25)
    -- Executing [s@macro-user-callerid:25] GotoIf("DAHDI/1-1", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:26] ExecIf("DAHDI/1-1", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
    -- Executing [s@macro-user-callerid:27] Set("DAHDI/1-1", "__TTL=64") in new stack
    -- Executing [s@macro-user-callerid:28] GotoIf("DAHDI/1-1", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,44)
    -- Executing [s@macro-user-callerid:44] Set("DAHDI/1-1", "CALLERID(number)=1717XXX8007") in new stack
    -- Executing [s@macro-user-callerid:45] Set("DAHDI/1-1", "CALLERID(name)=WIRELESS CALLER") in new stack
    -- Executing [s@macro-user-callerid:46] GotoIf("DAHDI/1-1", "0?cnum") in new stack
    -- Executing [s@macro-user-callerid:47] Set("DAHDI/1-1", "CDR(cnam)=WIRELESS CALLER") in new stack
    -- Executing [s@macro-user-callerid:48] Set("DAHDI/1-1", "CDR(cnum)=1717XXX8007") in new stack
    -- Executing [s@macro-user-callerid:49] Set("DAHDI/1-1", "CHANNEL(language)=en") in new stack
    -- Executing [150@ext-group:5] Macro("DAHDI/1-1", "blkvm-setifempty,") in new stack
    -- Executing [s@macro-blkvm-setifempty:1] GotoIf("DAHDI/1-1", "1?init") in new stack
    -- Goto (macro-blkvm-setifempty,s,4)
    -- Executing [s@macro-blkvm-setifempty:4] Set("DAHDI/1-1", "__BLKVM_CHANNEL=DAHDI/1-1") in new stack
    -- Executing [s@macro-blkvm-setifempty:5] Set("DAHDI/1-1", "SHARED(BLKVM,DAHDI/1-1)=TRUE") in new stack
    -- Executing [s@macro-blkvm-setifempty:6] Set("DAHDI/1-1", "GOSUB_RETVAL=TRUE") in new stack
    -- Executing [s@macro-blkvm-setifempty:7] MacroExit("DAHDI/1-1", "") in new stack
    -- Executing [150@ext-group:6] GotoIf("DAHDI/1-1", "1?skipov") in new stack
    -- Goto (ext-group,150,9)
    -- Executing [150@ext-group:9] Set("DAHDI/1-1", "RRNODEST=") in new stack
    -- Executing [150@ext-group:10] Set("DAHDI/1-1", "__NODEST=150") in new stack
    -- Executing [150@ext-group:11] GosubIf("DAHDI/1-1", "0?sub-rgsetcid,s,1()") in new stack
    -- Executing [150@ext-group:12] Gosub("DAHDI/1-1", "sub-record-check,s,1(rg,150,dontcare)") in new stack
    -- Executing [s@sub-record-check:1] GotoIf("DAHDI/1-1", "11?initialized") in new stack
    -- Goto (sub-record-check,s,10)
    -- Executing [s@sub-record-check:10] NoOp("DAHDI/1-1", "Recordings initialized") in new stack
    -- Executing [s@sub-record-check:11] ExecIf("DAHDI/1-1", "0?Set(ARG3=dontcare)") in new stack
    -- Executing [s@sub-record-check:12] Set("DAHDI/1-1", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [s@sub-record-check:13] ExecIf("DAHDI/1-1", "0?Set(REC_STATUS=NO)") in new stack
    -- Executing [s@sub-record-check:14] GotoIf("DAHDI/1-1", "2?checkaction") in new stack
    -- Goto (sub-record-check,s,17)
    -- Executing [s@sub-record-check:17] GotoIf("DAHDI/1-1", "0?sub-record-check,rg,1") in new stack
    -- Executing [s@sub-record-check:18] NoOp("DAHDI/1-1", "Generic rg Recording Check - 1717XXX8007 150") in new stack
    -- Executing [s@sub-record-check:19] Gosub("DAHDI/1-1", "recordcheck,1(dontcare,rg,150)") in new stack
    -- Executing [recordcheck@sub-record-check:1] NoOp("DAHDI/1-1", "Starting recording check against dontcare") in new stack
    -- Executing [recordcheck@sub-record-check:2] Goto("DAHDI/1-1", "dontcare") in new stack
    -- Goto (sub-record-check,recordcheck,3)
    -- Executing [recordcheck@sub-record-check:3] Return("DAHDI/1-1", "") in new stack
    -- Executing [s@sub-record-check:20] Return("DAHDI/1-1", "") in new stack
    -- Executing [150@ext-group:13] Set("DAHDI/1-1", "RingGroupMethod=ringall") in new stack
    -- Executing [150@ext-group:14] Set("DAHDI/1-1", "__ALT_CONFIRM_MSG=") in new stack
    -- Executing [150@ext-group:15] GotoIf("DAHDI/1-1", "0?RGVQANNOUNCE:NORGVQANNOUNCE") in new stack
    -- Goto (ext-group,150,18)
    -- Executing [150@ext-group:18] Macro("DAHDI/1-1", "dial,14,TtrQ(NO_ANSWER),101-102-103-104") in new stack
    -- Executing [s@macro-dial:1] NoOp("DAHDI/1-1", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
    -- Executing [s@macro-dial:2] Set("DAHDI/1-1", "__CRM_SOURCE=1717XXX8007") in new stack
    -- Executing [s@macro-dial:3] ExecIf("DAHDI/1-1", "0?Set(ALERT_INFO=)") in new stack
    -- Executing [s@macro-dial:4] ExecIf("DAHDI/1-1", "0?Set(ALERT_INFO=)") in new stack
    -- Executing [s@macro-dial:5] ExecIf("DAHDI/1-1", "0?Set(ALERT_INFO=)") in new stack
    -- Executing [s@macro-dial:6] ExecIf("DAHDI/1-1", "0?Set(CHANNEL(musicclass)=)") in new stack
    -- Executing [s@macro-dial:7] AGI("DAHDI/1-1", "agi://127.0.0.1/dialparties.agi") in new stack
 agi://127.0.0.1/dialparties.agi: Starting New Dialparties.agi
 agi://127.0.0.1/dialparties.agi: Caller ID name is 'WIRELESS CALLER' number is '1717XXX8007'
 agi://127.0.0.1/dialparties.agi: CW Ignore is:
 agi://127.0.0.1/dialparties.agi: CF Ignore is:
 agi://127.0.0.1/dialparties.agi: CW IN_USE/BUSY is: 1
       > agi://127.0.0.1/dialparties.agi: USE_CONFIRMATION:  'FALSE'
       > agi://127.0.0.1/dialparties.agi: RINGGROUP_INDEX:   ''
 agi://127.0.0.1/dialparties.agi: Methodology of ring is  'ringall'
    -- agi://127.0.0.1/dialparties.agi: Added extension 101 to extension map
    -- agi://127.0.0.1/dialparties.agi: Added extension 102 to extension map
    -- agi://127.0.0.1/dialparties.agi: Added extension 103 to extension map
    -- agi://127.0.0.1/dialparties.agi: Added extension 104 to extension map
    -- agi://127.0.0.1/dialparties.agi: Extension 101 cf is disabled
    -- agi://127.0.0.1/dialparties.agi: Extension 102 cf is disabled
    -- agi://127.0.0.1/dialparties.agi: Extension 103 cf is disabled
    -- agi://127.0.0.1/dialparties.agi: Extension 104 cf is disabled
    -- agi://127.0.0.1/dialparties.agi: Extension 101 do not disturb is disabled
    -- agi://127.0.0.1/dialparties.agi: Extension 102 do not disturb is disabled
    -- agi://127.0.0.1/dialparties.agi: Extension 103 do not disturb is disabled
    -- agi://127.0.0.1/dialparties.agi: Extension 104 do not disturb is disabled
       > agi://127.0.0.1/dialparties.agi: extnum 101 has:  cw: 1; hascfb: 0 [] hascfu: 0 []
    -- agi://127.0.0.1/dialparties.agi: dbset CALLTRACE/101 to 1717XXX8007
       > agi://127.0.0.1/dialparties.agi: extnum 102 has:  cw: 1; hascfb: 0 [] hascfu: 0 []
    -- agi://127.0.0.1/dialparties.agi: dbset CALLTRACE/102 to 1717XXX8007
       > agi://127.0.0.1/dialparties.agi: extnum 103 has:  cw: 1; hascfb: 0 [] hascfu: 0 []
    -- agi://127.0.0.1/dialparties.agi: dbset CALLTRACE/103 to 1717XXX8007
       > agi://127.0.0.1/dialparties.agi: extnum 104 has:  cw: 1; hascfb: 0 [] hascfu: 0 []
    -- agi://127.0.0.1/dialparties.agi: dbset CALLTRACE/104 to 1717XXX8007
    -- agi://127.0.0.1/dialparties.agi: Filtered ARG3: 101-102-103-104
       > agi://127.0.0.1/dialparties.agi: NODEST: 150 adding M(auto-blkvm) to dialopts: TtrQ(NO_ANSWER)M(auto-blkvm)
       > agi://127.0.0.1/dialparties.agi: NODEST: 150 blkvm enabled macro already in dialopts: TtrQ(NO_ANSWER)M(auto-blkvm)
 agi://127.0.0.1/dialparties.agi: RVOL_MODE ''
 agi://127.0.0.1/dialparties.agi: RVOL is:
 agi://127.0.0.1/dialparties.agi: RVOLPARENT is:
    -- <DAHDI/1-1>AGI Script agi://127.0.0.1/dialparties.agi completed, returning 0
    -- Executing [s@macro-dial:8] GotoIf("DAHDI/1-1", "1?normdial") in new stack
    -- Goto (macro-dial,s,11)
    -- Executing [s@macro-dial:11] NoOp("DAHDI/1-1", "Returned from dialparties with groups to dial") in new stack
    -- Executing [s@macro-dial:12] NoOp("DAHDI/1-1", "ringall array  ") in new stack
    -- Executing [s@macro-dial:13] Set("DAHDI/1-1", "__FMGL_DIAL=") in new stack
    -- Executing [s@macro-dial:14] Set("DAHDI/1-1", "LOOPCNT=4") in new stack
    -- Executing [s@macro-dial:15] Set("DAHDI/1-1", "ITER=1") in new stack
    -- Executing [s@macro-dial:16] Set("DAHDI/1-1", "__EXTTOCALL=101") in new stack
    -- Executing [s@macro-dial:17] NoOp("DAHDI/1-1", "Working with 101") in new stack
    -- Executing [s@macro-dial:18] ExecIf("DAHDI/1-1", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
    -- Executing [s@macro-dial:19] ExecIf("DAHDI/1-1", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
    -- Executing [s@macro-dial:20] Set("DAHDI/1-1", "ITER=2") in new stack
    -- Executing [s@macro-dial:21] GotoIf("DAHDI/1-1", "1?ndloopbegin") in new stack
    -- Goto (macro-dial,s,16)
    -- Executing [s@macro-dial:16] Set("DAHDI/1-1", "__EXTTOCALL=102") in new stack
    -- Executing [s@macro-dial:17] NoOp("DAHDI/1-1", "Working with 102") in new stack
    -- Executing [s@macro-dial:18] ExecIf("DAHDI/1-1", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
    -- Executing [s@macro-dial:19] ExecIf("DAHDI/1-1", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
    -- Executing [s@macro-dial:20] Set("DAHDI/1-1", "ITER=3") in new stack
    -- Executing [s@macro-dial:21] GotoIf("DAHDI/1-1", "1?ndloopbegin") in new stack
    -- Goto (macro-dial,s,16)
    -- Executing [s@macro-dial:16] Set("DAHDI/1-1", "__EXTTOCALL=103") in new stack
    -- Executing [s@macro-dial:17] NoOp("DAHDI/1-1", "Working with 103") in new stack
    -- Executing [s@macro-dial:18] ExecIf("DAHDI/1-1", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
    -- Executing [s@macro-dial:19] ExecIf("DAHDI/1-1", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
    -- Executing [s@macro-dial:20] Set("DAHDI/1-1", "ITER=4") in new stack
    -- Executing [s@macro-dial:21] GotoIf("DAHDI/1-1", "1?ndloopbegin") in new stack
    -- Goto (macro-dial,s,16)
    -- Executing [s@macro-dial:16] Set("DAHDI/1-1", "__EXTTOCALL=104") in new stack
    -- Executing [s@macro-dial:17] NoOp("DAHDI/1-1", "Working with 104") in new stack
    -- Executing [s@macro-dial:18] ExecIf("DAHDI/1-1", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
    -- Executing [s@macro-dial:19] ExecIf("DAHDI/1-1", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
    -- Executing [s@macro-dial:20] Set("DAHDI/1-1", "ITER=5") in new stack
    -- Executing [s@macro-dial:21] GotoIf("DAHDI/1-1", "0?ndloopbegin") in new stack
    -- Executing [s@macro-dial:22] Macro("DAHDI/1-1", "dial-ringall-predial-hook,") in new stack
    -- Executing [s@macro-dial-ringall-predial-hook:1] MacroExit("DAHDI/1-1", "") in new stack
    -- Executing [s@macro-dial:23] ExecIf("DAHDI/1-1", "0?Set(CWRING=r(callwaiting)):Set(CWRING=)") in new stack
    -- Executing [s@macro-dial:24] ExecIf("DAHDI/1-1", "0?Set(ds=SIP/101&SIP/102&SIP/103&SIP/104,14,trQ(NO_ANSWER)M(auto-blkvm)g)") in new stack
    -- Executing [s@macro-dial:25] Dial("DAHDI/1-1", "SIP/101&SIP/102&SIP/103&SIP/104,14,trQ(NO_ANSWER)M(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- SIP/101-00000001 Internal Gosub(func-apply-sipheaders,s,1) start
    -- Executing [s@func-apply-sipheaders:1] ExecIf("SIP/101-00000001", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
    -- Executing [s@func-apply-sipheaders:2] NoOp("SIP/101-00000001", "Applying SIP Headers to channel SIP/101-00000001") in new stack
    -- Executing [s@func-apply-sipheaders:3] Set("SIP/101-00000001", "TECH=SIP") in new stack
    -- Executing [s@func-apply-sipheaders:4] Set("SIP/101-00000001", "SIPHEADERKEYS=") in new stack
    -- Executing [s@func-apply-sipheaders:5] While("SIP/101-00000001", "0") in new stack
    -- Jumping to priority 11
    -- Executing [s@func-apply-sipheaders:12] Return("SIP/101-00000001", "") in new stack
  == Spawn extension (from-internal, 150, 1) exited non-zero on 'SIP/101-00000001'
    -- SIP/101-00000001 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
    -- SIP/102-00000002 Internal Gosub(func-apply-sipheaders,s,1) start
    -- Executing [s@func-apply-sipheaders:1] ExecIf("SIP/102-00000002", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
    -- Executing [s@func-apply-sipheaders:2] NoOp("SIP/102-00000002", "Applying SIP Headers to channel SIP/102-00000002") in new stack
    -- Executing [s@func-apply-sipheaders:3] Set("SIP/102-00000002", "TECH=SIP") in new stack
    -- Executing [s@func-apply-sipheaders:4] Set("SIP/102-00000002", "SIPHEADERKEYS=") in new stack
    -- Executing [s@func-apply-sipheaders:5] While("SIP/102-00000002", "0") in new stack
    -- Jumping to priority 11
    -- Executing [s@func-apply-sipheaders:12] Return("SIP/102-00000002", "") in new stack
  == Spawn extension (from-internal, 150, 1) exited non-zero on 'SIP/102-00000002'
    -- SIP/102-00000002 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
    -- SIP/103-00000003 Internal Gosub(func-apply-sipheaders,s,1) start
    -- Executing [s@func-apply-sipheaders:1] ExecIf("SIP/103-00000003", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
    -- Executing [s@func-apply-sipheaders:2] NoOp("SIP/103-00000003", "Applying SIP Headers to channel SIP/103-00000003") in new stack
    -- Executing [s@func-apply-sipheaders:3] Set("SIP/103-00000003", "TECH=SIP") in new stack
    -- Executing [s@func-apply-sipheaders:4] Set("SIP/103-00000003", "SIPHEADERKEYS=") in new stack
    -- Executing [s@func-apply-sipheaders:5] While("SIP/103-00000003", "0") in new stack
    -- Jumping to priority 11
    -- Executing [s@func-apply-sipheaders:12] Return("SIP/103-00000003", "") in new stack
  == Spawn extension (from-internal, 150, 1) exited non-zero on 'SIP/103-00000003'
    -- SIP/103-00000003 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
    -- SIP/104-00000004 Internal Gosub(func-apply-sipheaders,s,1) start
    -- Executing [s@func-apply-sipheaders:1] ExecIf("SIP/104-00000004", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
    -- Executing [s@func-apply-sipheaders:2] NoOp("SIP/104-00000004", "Applying SIP Headers to channel SIP/104-00000004") in new stack
    -- Executing [s@func-apply-sipheaders:3] Set("SIP/104-00000004", "TECH=SIP") in new stack
    -- Executing [s@func-apply-sipheaders:4] Set("SIP/104-00000004", "SIPHEADERKEYS=") in new stack
    -- Executing [s@func-apply-sipheaders:5] While("SIP/104-00000004", "0") in new stack
    -- Jumping to priority 11
    -- Executing [s@func-apply-sipheaders:12] Return("SIP/104-00000004", "") in new stack
  == Spawn extension (from-internal, 150, 1) exited non-zero on 'SIP/104-00000004'
    -- SIP/104-00000004 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
    -- Called SIP/101
  == Extension Changed 101[ext-local] new state Ringing for Notify User 102
    -- Called SIP/102
  == Extension Changed 101[ext-local] new state Ringing for Notify User 103
    -- Called SIP/103
  == Extension Changed 101[ext-local] new state Ringing for Notify User 104
  == Extension Changed 101[ext-local] new state Ringing for Notify User 101
    -- Called SIP/104
    -- SIP/104-00000004 connected line has changed. Saving it until answer for DAHDI/1-1
    -- SIP/103-00000003 connected line has changed. Saving it until answer for DAHDI/1-1
    -- SIP/102-00000002 connected line has changed. Saving it until answer for DAHDI/1-1
    -- SIP/101-00000001 connected line has changed. Saving it until answer for DAHDI/1-1

(Continued below.)

(Continued from above.)

  == Extension Changed 102[ext-local] new state Ringing for Notify User 102
  == Extension Changed 102[ext-local] new state Ringing for Notify User 103
  == Extension Changed 102[ext-local] new state Ringing for Notify User 104
  == Extension Changed 102[ext-local] new state Ringing for Notify User 101
  == Extension Changed 103[ext-local] new state Ringing for Notify User 102
  == Extension Changed 103[ext-local] new state Ringing for Notify User 103
  == Extension Changed 103[ext-local] new state Ringing for Notify User 104
  == Extension Changed 103[ext-local] new state Ringing for Notify User 101
  == Extension Changed 104[ext-local] new state Ringing for Notify User 102
  == Extension Changed 104[ext-local] new state Ringing for Notify User 103
  == Extension Changed 104[ext-local] new state Ringing for Notify User 104
  == Extension Changed 104[ext-local] new state Ringing for Notify User 101
    -- SIP/102-00000002 is ringing
  == Extension Changed 102[ext-local] new state Ringing for Notify User 102
  == Extension Changed 102[ext-local] new state Ringing for Notify User 103
  == Extension Changed 102[ext-local] new state Ringing for Notify User 104
  == Extension Changed 102[ext-local] new state Ringing for Notify User 101
    -- SIP/104-00000004 is ringing
  == Extension Changed 104[ext-local] new state Ringing for Notify User 102
  == Extension Changed 104[ext-local] new state Ringing for Notify User 103
  == Extension Changed 104[ext-local] new state Ringing for Notify User 104
  == Extension Changed 104[ext-local] new state Ringing for Notify User 101
    -- SIP/102-00000002 is ringing
    -- SIP/101-00000001 is ringing
  == Extension Changed 101[ext-local] new state Ringing for Notify User 102
  == Extension Changed 101[ext-local] new state Ringing for Notify User 103
  == Extension Changed 101[ext-local] new state Ringing for Notify User 104
  == Extension Changed 101[ext-local] new state Ringing for Notify User 101
    -- SIP/103-00000003 is ringing
  == Extension Changed 103[ext-local] new state Ringing for Notify User 102
  == Extension Changed 103[ext-local] new state Ringing for Notify User 103
  == Extension Changed 103[ext-local] new state Ringing for Notify User 104
  == Extension Changed 103[ext-local] new state Ringing for Notify User 101
    -- SIP/104-00000004 is ringing
    -- SIP/101-00000001 is ringing
    -- SIP/103-00000003 is ringing
       > 0x7f44b0040890 -- Strict RTP learning after remote address set to: 192.168.1.247:3000
    -- SIP/102-00000002 connected line has changed. Saving it until answer for DAHDI/1-1
    -- SIP/102-00000002 answered DAHDI/1-1
    -- SIP/101-00000001 Internal Gosub(crm-hangup,s,1) start
    -- Executing [s@crm-hangup:1] NoOp("SIP/101-00000001", "Sending Hangup to CRM") in new stack
  == Extension Changed 102[ext-local] new state InUse for Notify User 102
    -- Executing [s@crm-hangup:2] NoOp("SIP/101-00000001", "HANGUP CAUSE: 19") in new stack
  == Extension Changed 102[ext-local] new state InUse for Notify User 103
    -- Executing [s@crm-hangup:3] ExecIf("SIP/101-00000001", "0?Set(__CRM_VOICEMAIL=)") in new stack
  == Extension Changed 102[ext-local] new state InUse for Notify User 104
    -- Executing [s@crm-hangup:4] NoOp("SIP/101-00000001", "MASTER CHANNEL: 1609443826.3 = 1609443824.2") in new stack
  == Extension Changed 102[ext-local] new state InUse for Notify User 101
    -- Executing [s@crm-hangup:5] GotoIf("SIP/101-00000001", "1?return") in new stack
    -- Goto (crm-hangup,s,8)
    -- Executing [s@crm-hangup:8] Return("SIP/101-00000001", "") in new stack
  == Spawn extension (from-internal, 150, 1) exited non-zero on 'SIP/101-00000001'
    -- SIP/101-00000001 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
    -- SIP/103-00000003 Internal Gosub(crm-hangup,s,1) start
    -- Executing [s@crm-hangup:1] NoOp("SIP/103-00000003", "Sending Hangup to CRM") in new stack
  == Extension Changed 101[ext-local] new state Idle for Notify User 102
    -- Executing [s@crm-hangup:2] NoOp("SIP/103-00000003", "HANGUP CAUSE: 19") in new stack
    -- Executing [s@crm-hangup:3] ExecIf("SIP/103-00000003", "0?Set(__CRM_VOICEMAIL=)") in new stack
  == Extension Changed 101[ext-local] new state Idle for Notify User 103
    -- Executing [s@crm-hangup:4] NoOp("SIP/103-00000003", "MASTER CHANNEL: 1609443826.5 = 1609443824.2") in new stack
  == Extension Changed 101[ext-local] new state Idle for Notify User 104
    -- Executing [s@crm-hangup:5] GotoIf("SIP/103-00000003", "1?return") in new stack
    -- Goto (crm-hangup,s,8)
    -- Executing [s@crm-hangup:8] Return("SIP/103-00000003", "") in new stack
  == Extension Changed 101[ext-local] new state Idle for Notify User 101
  == Spawn extension (from-internal, 150, 1) exited non-zero on 'SIP/103-00000003'
    -- SIP/103-00000003 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
    -- SIP/104-00000004 Internal Gosub(crm-hangup,s,1) start
    -- Executing [s@crm-hangup:1] NoOp("SIP/104-00000004", "Sending Hangup to CRM") in new stack
  == Extension Changed 103[ext-local] new state Idle for Notify User 102
    -- Executing [s@crm-hangup:2] NoOp("SIP/104-00000004", "HANGUP CAUSE: 19") in new stack
    -- Executing [s@crm-hangup:3] ExecIf("SIP/104-00000004", "0?Set(__CRM_VOICEMAIL=)") in new stack
  == Extension Changed 103[ext-local] new state Idle for Notify User 103
    -- Executing [s@crm-hangup:4] NoOp("SIP/104-00000004", "MASTER CHANNEL: 1609443826.6 = 1609443824.2") in new stack
  == Extension Changed 103[ext-local] new state Idle for Notify User 104
    -- Executing [s@crm-hangup:5] GotoIf("SIP/104-00000004", "1?return") in new stack
    -- Goto (crm-hangup,s,8)
    -- Executing [s@crm-hangup:8] Return("SIP/104-00000004", "") in new stack
  == Extension Changed 103[ext-local] new state Idle for Notify User 101
  == Spawn extension (from-internal, 150, 1) exited non-zero on 'SIP/104-00000004'
    -- SIP/104-00000004 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
  == Extension Changed 104[ext-local] new state Idle for Notify User 102
    -- Executing [s@macro-auto-blkvm:1] Set("SIP/102-00000002", "__MACRO_RESULT=") in new stack
    -- Executing [s@macro-auto-blkvm:2] Set("SIP/102-00000002", "CFIGNORE=") in new stack
  == Extension Changed 104[ext-local] new state Idle for Notify User 103
    -- Executing [s@macro-auto-blkvm:3] Set("SIP/102-00000002", "MASTER_CHANNEL(CFIGNORE)=") in new stack
  == Extension Changed 104[ext-local] new state Idle for Notify User 104
    -- Executing [s@macro-auto-blkvm:4] Set("SIP/102-00000002", "FORWARD_CONTEXT=from-internal") in new stack
  == Extension Changed 104[ext-local] new state Idle for Notify User 101
    -- Executing [s@macro-auto-blkvm:5] Set("SIP/102-00000002", "MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal") in new stack
    -- Executing [s@macro-auto-blkvm:6] Macro("SIP/102-00000002", "blkvm-clr,") in new stack
    -- Executing [s@macro-blkvm-clr:1] Set("SIP/102-00000002", "SHARED(BLKVM,DAHDI/1-1)=") in new stack
    -- Executing [s@macro-blkvm-clr:2] Set("SIP/102-00000002", "GOSUB_RETVAL=") in new stack
    -- Executing [s@macro-blkvm-clr:3] MacroExit("SIP/102-00000002", "") in new stack
    -- Executing [s@macro-auto-blkvm:7] ExecIf("SIP/102-00000002", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=102)") in new stack
    -- Executing [s@macro-auto-blkvm:8] ExecIf("SIP/102-00000002", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=Emily)") in new stack
    -- Channel SIP/102-00000002 joined 'simple_bridge' basic-bridge <1b9cc7ec-5d1e-475d-b777-242c64739d02>
    -- Channel DAHDI/1-1 joined 'simple_bridge' basic-bridge <1b9cc7ec-5d1e-475d-b777-242c64739d02>
[2020-12-31 14:44:18] NOTICE[2783]: chan_sip.c:29982 check_rtp_timeout: Disconnecting call 'SIP/102-00000002' for lack of RTP activity in 31 seconds
    -- Channel SIP/102-00000002 left 'simple_bridge' basic-bridge <1b9cc7ec-5d1e-475d-b777-242c64739d02>
    -- SIP/102-00000002 Internal Gosub(crm-hangup,s,1) start
    -- Executing [s@crm-hangup:1] NoOp("SIP/102-00000002", "Sending Hangup to CRM") in new stack
    -- Executing [s@crm-hangup:2] NoOp("SIP/102-00000002", "HANGUP CAUSE: 44") in new stack
    -- Executing [s@crm-hangup:3] ExecIf("SIP/102-00000002", "0?Set(__CRM_VOICEMAIL=)") in new stack
    -- Executing [s@crm-hangup:4] NoOp("SIP/102-00000002", "MASTER CHANNEL: 1609443826.4 = 1609443824.2") in new stack
    -- Executing [s@crm-hangup:5] GotoIf("SIP/102-00000002", "1?return") in new stack
    -- Goto (crm-hangup,s,8)
    -- Executing [s@crm-hangup:8] Return("SIP/102-00000002", "") in new stack
  == Spawn extension (macro-dial, s, 1) exited non-zero on 'SIP/102-00000002'
    -- SIP/102-00000002 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
    -- Channel DAHDI/1-1 left 'simple_bridge' basic-bridge <1b9cc7ec-5d1e-475d-b777-242c64739d02>
  == Extension Changed 102[ext-local] new state Idle for Notify User 102
  == Spawn extension (macro-dial, s, 25) exited non-zero on 'DAHDI/1-1' in macro 'dial'
  == Extension Changed 102[ext-local] new state Idle for Notify User 103
  == Spawn extension (ext-group, 150, 18) exited non-zero on 'DAHDI/1-1'
  == Extension Changed 102[ext-local] new state Idle for Notify User 104
  == Extension Changed 102[ext-local] new state Idle for Notify User 101
    -- Executing [h@ext-group:1] Macro("DAHDI/1-1", "hangupcall,") in new stack
    -- Executing [s@macro-hangupcall:1] GotoIf("DAHDI/1-1", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,3)
    -- Executing [s@macro-hangupcall:3] ExecIf("DAHDI/1-1", "0?Set(CDR(recordingfile)=)") in new stack
    -- Executing [s@macro-hangupcall:4] NoOp("DAHDI/1-1", "SIP/104-00000004 montior file= ") in new stack
    -- Executing [s@macro-hangupcall:5] GotoIf("DAHDI/1-1", "1?skipagi") in new stack
    -- Goto (macro-hangupcall,s,7)
    -- Executing [s@macro-hangupcall:7] Hangup("DAHDI/1-1", "") in new stack
  == Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'DAHDI/1-1' in macro 'hangupcall'
  == Spawn extension (ext-group, h, 1) exited non-zero on 'DAHDI/1-1'
    -- DAHDI/1-1 Internal Gosub(crm-hangup,s,1) start
    -- Executing [s@crm-hangup:1] NoOp("DAHDI/1-1", "Sending Hangup to CRM") in new stack
    -- Executing [s@crm-hangup:2] NoOp("DAHDI/1-1", "HANGUP CAUSE: 44") in new stack
    -- Executing [s@crm-hangup:3] ExecIf("DAHDI/1-1", "0?Set(__CRM_VOICEMAIL=)") in new stack
    -- Executing [s@crm-hangup:4] NoOp("DAHDI/1-1", "MASTER CHANNEL: 1609443824.2 = 1609443824.2") in new stack
    -- Executing [s@crm-hangup:5] GotoIf("DAHDI/1-1", "0?return") in new stack
    -- Executing [s@crm-hangup:6] Set("DAHDI/1-1", "__CRM_HANGUP=1") in new stack
    -- Executing [s@crm-hangup:7] AGI("DAHDI/1-1", "agi://127.0.0.1/sangomacrm.agi") in new stack
    -- <DAHDI/1-1>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
    -- Executing [s@crm-hangup:8] Return("DAHDI/1-1", "") in new stack
  == Spawn extension (ext-group, h, 1) exited non-zero on 'DAHDI/1-1'
    -- DAHDI/1-1 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
    -- Hanging up on 'DAHDI/1-1'
    -- Hungup 'DAHDI/1-1'
pbx*CLI>

In Asterisk SIP Settings, confirm that External Address and Local Networks are correctly set. If you change these, restart Asterisk.

If no luck, at the Asterisk command prompt, type
sip set debug on
make new failing calls, paste the Asterisk log (not the console output; the Asterisk log file includes timestamps) for the calls (which will now include SIP traces) at pastebin.freepbx.org and post the link here.

Many thanks, @Stewart1. I’ll confirm this and post additional details. Will be a few days until I can schedule another maintenance window.

Thanks again and Happy New Year.

Sorry for the extreme delay here. Setting the networks properly under Asterisk SIP Settings didn’t make a difference, unfortunately. I was able to reproduce the issue and have uploaded the debug messages here:

https://pastebin.freepbx.org/view/9f2dcdc4

Please note this only covers outbound calls from an IP phone handset. Inbound calls just ring incessantly, with no log messages ever generated.

Thanks very much in advance for any help you can provide.

That does the Asterisk CLI say about

dahdi show version
dahdi show status
dahdi show channels

?

The version is 2.11.1. I’ll have to get you the status and channels output during the next maintenance window. (Each time I attempt this, I have to roll back and put the old system/hardware back in service. The new system is currently powered off.)

Thanks for your help, all the same.

Good about 2.11 because I don’t know whether dahdi 3+ (that I believe comes with FreePBX15 distro) supports your hardware, (but apparently neither does the manufacturer, https://wiki.asterisk.org/wiki/display/DAHDI/DAHDI+compatible+hardware :wink: )

Hi @dicko, thanks for your reply (sorry for not seeing it sooner).

I did reconfirm the DAHDi version on version 15; it is 2.11.1, just like on version 13 (see below, from the Asterisk CLI on the new system):

Connected to Asterisk 16.13.0 currently running on freepbx (pid = 1959)
freepbx*CLI> core show version
Asterisk 16.13.0 built by mockbuild @ jenkins7 on a x86_64 running Linux on 2020-09-10 17:59:26 UTC
freepbx*CLI> dahdi show version
DAHDI Version: 2.11.1 Echo Canceller: 

Here’s the card I’m using:

As you can see, this is the TDM410P card with 4 x X100M FXO modules. According to the hardware list you provided, this card was end-of-life in 2013 and replaced by the A4 series. If my issue is incompatible hardware, then I suppose the only choice is to replace the TDM410P with an A4B card (MSRP $240 USD). Looks like the X100M modules are compatible, but I would love not to have to replace the telephony card at all. The only other option would be some sort of SIP-to-FXO/PSTN gateway (I’ve seen a few recommended on these forums, e.g. Grandstream models, etc.). Again, I’d really like to avoid not using the existing telephony card if possible.

Is there any way to confirm that DAHDi 2.11.1 supports the older TDM410P and X100M modules? Any system messages or other logs I could view?

Thanks very much for your help on this.

Dahdi 2.11 will work just fine with that hardware

Thanks, @dicko. Hopefully that rules out hardware compatibility with DAHDi.

Hopefully someone will have some ideas on why these issues persist. Re-posting the debug output here (https://pastebin.freepbx.org/view/9f2dcdc4). Again, this covers outbound calls only. Inbound calls ring forever, without a single log message being generated.

Thanks again for your time.

Not sure if it helps but DAHDI never has any interaction with the network side of things (with a couple of tiny edge-case exceptions not pertinent to you) it is purely a hardware interface between the pairs of wire in the wall and Asterisk, look elsewhere

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