No Caller ID information on inbound PSTN Call

Asterisk Asterisk Hardware
1

Hi,

I was using a 10 year+ old FreePBX version working perfectly with the Greek provider COSMOTE and an analog Digium TDM2400P card until I experienced motherboard failure. The MB was changed and the latest version of FreePBX (Asterisk 16.19.0) is now installed. Everything seems to work perfectly fine with the exception of inbound Caller ID that is not received anymore.

I followed the Digium guide for “Troubleshooting missing caller ID on Analog calls" and from the audio recording it is clear that I am receiving a short Dial-Up Modem sound between first and second ring (as expected since I was receiving CID with my old setup). I have added in following lines via the FreePBX GUI related to CID and FSK modulation:

  • Cidsignalling = v23 (also tried bell)
  • Cidstart = ring (also tried polarity and polarity_IN)
  • Callerid = asreceived

The complete chan_dahdi.conf is as follows:
[general]

; generated by module
#include chan_dahdi_general.conf

; for user additions not provided by module
#include chan_dahdi_general_custom.conf

[channels]
language=gr
busydetect=yes
busycount=10
usecallerid=yes
callwaiting=yes
usecallingpres=yes
threewaycalling=yes
transfer=yes
cancallforward=yes
callreturn=yes
echocancel=yes
echocancelwhenbridged=no
echotraining=no
immediate=no
faxdetect=no
rxgain=0.0
txgain=0.0
alawoverride=0
alawoverride_checkbox=0
boostringer=0
boostringer_checkbox=0
callerid=asreceived
cidsignalling=v23
cidstart=ring
echocan_nlp_max_supp=
echocan_nlp_threshold=
echocan_nlp_type=0
fastringer=0
fastringer_checkbox=0
fxs_honor_mode=0
fxs_honor_mode_checkbox=0
lowpower=0
lowpower_checkbox=0
module_name=wctdm24xxp
mwi=none
mwi_checkbox=0
neon_offlimit=
neon_voltage=
opermode=TBR21
opermode_checkbox=1
ringdetect=1
ringdetect_checkbox=1

; for user additions not provided by module
#include chan_dahdi_channels_custom.conf

; include dahdi groups defined by DAHDI module of FreePBX
#include chan_dahdi_groups.conf

; include dahdi extensions defined in FreePBX
#include chan_dahdi_additional.conf

And the log I am getting from the incoming call is:

– 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
[2021-08-20 14:13:39] WARNING[5181][C-00000001]: app_macro.c:274 _macro_exec: Macro() is deprecated and will be removed from a future version of Asterisk.
[2021-08-20 14:13:39] WARNING[5181][C-00000001]: app_macro.c:275 _macro_exec: Dialplan should be updated to use Gosub instead.
– Executing [s@macro-from-dahdi-1:1] NoOp(“DAHDI/1-1”, “Entering macro-from-dahdi-1 with DID = s and setting to: +302612345678”) in new stack
– Executing [s@macro-from-dahdi-1:2] Set(“DAHDI/1-1”, “__FROM_DID=+302612345678”) in new stack
– Executing [s@macro-from-dahdi-1:3] Goto(“DAHDI/1-1”, “from-trunk,+302612345678,1”) in new stack
– Goto (from-trunk,+302612345678,1)
== Channel ‘DAHDI/1-1’ jumping out of macro ‘from-dahdi-1’
– Executing [+302612345678@from-trunk:1] Set(“DAHDI/1-1”, “__DIRECTION=INBOUND”) in new stack
– Executing [+302612345678@from-trunk:2] Gosub(“DAHDI/1-1”, “sub-record-check,s,1(in,+302612345678,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=1629458019”) in new stack
– Executing [s@sub-record-check:4] Set(“DAHDI/1-1”, “__DAY=20”) in new stack
– Executing [s@sub-record-check:5] Set(“DAHDI/1-1”, “__MONTH=08”) in new stack
– Executing [s@sub-record-check:6] Set(“DAHDI/1-1”, “__YEAR=2021”) in new stack
– Executing [s@sub-record-check:7] Set(“DAHDI/1-1”, “__TIMESTR=20210820-141339”) 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 +302612345678”) 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”, “0?Set(FROMEXTEN=)”) in new stack
– Executing [in@sub-record-check:4] Gosub(“DAHDI/1-1”, “recordcheck,1(dontcare,in,+302612345678)”) 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 [+302612345678@from-trunk:3] Set(“DAHDI/1-1”, “CHANNEL(tonezone)=gr”) in new stack
– Executing [+302612345678@from-trunk:4] Set(“DAHDI/1-1”, “__FROM_DID=+302612345678”) in new stack
– Executing [+302612345678@from-trunk:5] Set(“DAHDI/1-1”, “returnhere=1”) in new stack
– Executing [+302612345678@from-trunk: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 [+302612345678@from-trunk:7] Set(“DAHDI/1-1”, “CDR(did)=+302612345678”) in new stack
– Executing [+302612345678@from-trunk:8] GotoIf(“DAHDI/1-1”, “0?”) in new stack
– Executing [+302612345678@from-trunk:9] ExecIf(“DAHDI/1-1”, “1 ?Set(CALLERID(name)=)”) in new stack
– Executing [+302612345678@from-trunk:10] Set(“DAHDI/1-1”, “__MOHCLASS=”) in new stack
– Executing [+302612345678@from-trunk:11] Set(“DAHDI/1-1”, “__REVERSAL_REJECT=FALSE”) in new stack
– Executing [+302612345678@from-trunk:12] GotoIf(“DAHDI/1-1”, “1?post-reverse-charge”) in new stack
– Goto (from-trunk,+302612345678,14)
– Executing [+302612345678@from-trunk:14] NoOp(“DAHDI/1-1”, “”) in new stack
– Executing [+302612345678@from-trunk:15] Set(“DAHDI/1-1”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
– Executing [+302612345678@from-trunk:16] Set(“DAHDI/1-1”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
– Executing [+302612345678@from-trunk:17] Set(“DAHDI/1-1”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
– Executing [+302612345678@from-trunk:18] Set(“DAHDI/1-1”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
– Executing [+302612345678@from-trunk:19] NoOp(“DAHDI/1-1”, “CallerID Entry Point”) in new stack
– Executing [+302612345678@from-trunk:20] Set(“DAHDI/1-1”, “__CRM_DIRECTION=INBOUND”) in new stack
– Executing [+302612345678@from-trunk:21] Set(“DAHDI/1-1”, “__CRM_SOURCE=”) in new stack
– Executing [+302612345678@from-trunk:22] Set(“DAHDI/1-1”, “__CRM_LINKEDID=1629458018.0”) in new stack
– Executing [+302612345678@from-trunk: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 [+302612345678@from-trunk:24] ExecIf(“DAHDI/1-1”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
– Executing [+302612345678@from-trunk:25] Goto(“DAHDI/1-1”, “from-did-direct,27,1”) in new stack
– Goto (from-did-direct,27,1)
– Executing [27@from-did-direct:1] GotoIf(“DAHDI/1-1”, “1?ext-local,27,1:followme-check,27,1”) in new stack
– Goto (ext-local,27,1)
– Executing [27@ext-local:1] Set(“DAHDI/1-1”, “__RINGTIMER=15”) in new stack
– Executing [27@ext-local:2] ExecIf(“DAHDI/1-1”, “0?Set(__CWIGNORE=)”) in new stack
– Executing [27@ext-local:3] Macro(“DAHDI/1-1”, “exten-vm,novm,27,0,0,0”) in new stack
– Executing [s@macro-exten-vm:1] Macro(“DAHDI/1-1”, “user-callerid,”) in new stack
– Executing [s@macro-user-callerid:1] Set(“DAHDI/1-1”, “TOUCH_MONITOR=1629458018.0”) in new stack
– Executing [s@macro-user-callerid:2] Set(“DAHDI/1-1”, “CHANCONTEXT=”) in new stack
– Executing [s@macro-user-callerid:3] Set(“DAHDI/1-1”, “CHANCONTEXT=”) in new stack
– Executing [s@macro-user-callerid:4] Set(“DAHDI/1-1”, “CHANEXTENCONTEXT=1-1”) in new stack
– Executing [s@macro-user-callerid:5] Set(“DAHDI/1-1”, “CHANEXTEN=1-1”) in new stack
– Executing [s@macro-user-callerid:6] Set(“DAHDI/1-1”, “CALLERID(number)=”) in new stack
– Executing [s@macro-user-callerid:7] Set(“DAHDI/1-1”, “AMPUSER=”) in new stack
– Executing [s@macro-user-callerid:8] Set(“DAHDI/1-1”, “HOTDESCKCHAN=1-1”) in new stack
– Executing [s@macro-user-callerid:9] Set(“DAHDI/1-1”, “HOTDESKEXTEN=1”) in new stack
– Executing [s@macro-user-callerid:10] Set(“DAHDI/1-1”, “HOTDESKCALL=0”) in new stack
– Executing [s@macro-user-callerid:11] ExecIf(“DAHDI/1-1”, “0?Set(HOTDESKCALL=1)”) in new stack
– Executing [s@macro-user-callerid:12] ExecIf(“DAHDI/1-1”, “0?Set(CALLERID(name)=)”) in new stack
– Executing [s@macro-user-callerid:13] GotoIf(“DAHDI/1-1”, “0?report”) in new stack
– Executing [s@macro-user-callerid:14] ExecIf(“DAHDI/1-1”, “1?Set(REALCALLERIDNUM=)”) in new stack
– Executing [s@macro-user-callerid:15] Set(“DAHDI/1-1”, “AMPUSER=”) in new stack
– Executing [s@macro-user-callerid:16] GotoIf(“DAHDI/1-1”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:17] Set(“DAHDI/1-1”, “AMPUSERCIDNAME=”) in new stack
– Executing [s@macro-user-callerid:18] ExecIf(“DAHDI/1-1”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
– Executing [s@macro-user-callerid:19] GotoIf(“DAHDI/1-1”, “1?report”) in new stack
– Goto (macro-user-callerid,s,28)
– Executing [s@macro-user-callerid:28] NoOp(“DAHDI/1-1”, “Macro Depth is 2”) in new stack
– Executing [s@macro-user-callerid:29] GotoIf(“DAHDI/1-1”, “1?report2:macroerror”) in new stack
– Goto (macro-user-callerid,s,30)
– Executing [s@macro-user-callerid:30] GotoIf(“DAHDI/1-1”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:31] ExecIf(“DAHDI/1-1”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
– Executing [s@macro-user-callerid:32] Set(“DAHDI/1-1”, “__TTL=64”) in new stack
– Executing [s@macro-user-callerid:33] GotoIf(“DAHDI/1-1”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,49)
– Executing [s@macro-user-callerid:49] Set(“DAHDI/1-1”, “CALLERID(number)=”) in new stack
– Executing [s@macro-user-callerid:50] Set(“DAHDI/1-1”, “CALLERID(name)=”) in new stack
– Executing [s@macro-user-callerid:51] GotoIf(“DAHDI/1-1”, “1?cnum”) in new stack
– Goto (macro-user-callerid,s,53)
– Executing [s@macro-user-callerid:53] Set(“DAHDI/1-1”, “CDR(cnum)=”) in new stack
– Executing [s@macro-user-callerid:54] Set(“DAHDI/1-1”, “CHANNEL(language)=gr”) in new stack
– Executing [s@macro-exten-vm:2] Set(“DAHDI/1-1”, “RingGroupMethod=none”) in new stack
– Executing [s@macro-exten-vm:3] Set(“DAHDI/1-1”, “__EXTTOCALL=27”) in new stack
– Executing [s@macro-exten-vm:4] Set(“DAHDI/1-1”, “__PICKUPMARK=27”) in new stack
– Executing [s@macro-exten-vm:5] Set(“DAHDI/1-1”, “RT=”) in new stack
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:6] ExecIf(“DAHDI/1-1”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:7] ExecIf(“DAHDI/1-1”, “0?MacroExit()”) in new stack
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:8] ExecIf(“DAHDI/1-1”, “0?Gosub(ext-intercom,*8027,1())”) in new stack
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:9] ExecIf(“DAHDI/1-1”, “0?MacroExit()”) in new stack
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:10] ExecIf(“DAHDI/1-1”, “0?ChanSpy(PJSIP/27,q)”) in new stack
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:11] ExecIf(“DAHDI/1-1”, “0?MacroExit()”) in new stack
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:12] ExecIf(“DAHDI/1-1”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:13] ExecIf(“DAHDI/1-1”, “0?MacroExit()”) in new stack
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:14] ExecIf(“DAHDI/1-1”, “0?Gosub(ext-intercom,*8027,1())”) in new stack
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:15] ExecIf(“DAHDI/1-1”, “0?MacroExit()”) in new stack
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:16] ExecIf(“DAHDI/1-1”, “0?ChanSpy(PJSIP/27,q)”) in new stack
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:17] ExecIf(“DAHDI/1-1”, “0?MacroExit()”) in new stack
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:18] ExecIf(“DAHDI/1-1”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:19] ExecIf(“DAHDI/1-1”, “0?MacroExit()”) in new stack
[2021-08-20 14:13:40] WARNING[5181][C-00000001]: chan_sip.c:23254 func_header_read: This function can only be used on SIP channels.
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:20] ExecIf(“DAHDI/1-1”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:21] ExecIf(“DAHDI/1-1”, “0?MacroExit()”) in new stack
[2021-08-20 14:13:40] ERROR[5181][C-00000001]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:22] Gosub(“DAHDI/1-1”, “sub-record-check,s,1(exten,27,dontcare)”) in new stack
– Executing [s@sub-record-check:1] GotoIf(“DAHDI/1-1”, “7?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”, “5?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [s@sub-record-check:17] GotoIf(“DAHDI/1-1”, “1?sub-record-check,exten,1”) in new stack
– Goto (sub-record-check,exten,1)
– Executing [exten@sub-record-check:1] NoOp(“DAHDI/1-1”, “Exten Recording Check between unknown and 27”) in new stack
– Executing [exten@sub-record-check:2] Set(“DAHDI/1-1”, “CALLTYPE=external”) in new stack
– Executing [exten@sub-record-check:3] ExecIf(“DAHDI/1-1”, “0?Set(CALLTYPE=)”) in new stack
– Executing [exten@sub-record-check:4] Set(“DAHDI/1-1”, “CALLEE=dontcare”) in new stack
– Executing [exten@sub-record-check:5] ExecIf(“DAHDI/1-1”, “0?Set(CALLEE=dontcare)”) in new stack
– Executing [exten@sub-record-check:6] GotoIf(“DAHDI/1-1”, “1?callee”) in new stack
– Goto (sub-record-check,exten,11)
– Executing [exten@sub-record-check:11] Gosub(“DAHDI/1-1”, “recordcheck,1(dontcare,external,27)”) 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 [exten@sub-record-check:12] Return(“DAHDI/1-1”, “”) in new stack
– Executing [s@macro-exten-vm:23] GotoIf(“DAHDI/1-1”, “1?macrodial”) in new stack
– Goto (macro-exten-vm,s,29)
– Executing [s@macro-exten-vm:29] GosubIf(“DAHDI/1-1”, “0?clrheader,1()”) in new stack
– Executing [s@macro-exten-vm:30] Macro(“DAHDI/1-1”, “dial-one,HhTtr,27”) in new stack
– Executing [s@macro-dial-one:1] Set(“DAHDI/1-1”, “DEXTEN=27”) in new stack
– Executing [s@macro-dial-one:2] Set(“DAHDI/1-1”, “__CRM_SOURCE=”) in new stack
– Executing [s@macro-dial-one:3] ExecIf(“DAHDI/1-1”, “0?Set(__EXTTOCALL=27)”) in new stack
– Executing [s@macro-dial-one:4] Set(“DAHDI/1-1”, “DIALSTATUS_CW=”) in new stack
– Executing [s@macro-dial-one:5] GosubIf(“DAHDI/1-1”, “0?screen,1()”) in new stack
– Executing [s@macro-dial-one:6] GosubIf(“DAHDI/1-1”, “0?cf,1()”) in new stack
– Executing [s@macro-dial-one:7] GotoIf(“DAHDI/1-1”, “1?skip1”) in new stack
– Goto (macro-dial-one,s,10)
– Executing [s@macro-dial-one:10] GotoIf(“DAHDI/1-1”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:11] GotoIf(“DAHDI/1-1”, “0?continue”) in new stack
– Executing [s@macro-dial-one:12] Set(“DAHDI/1-1”, “EXTHASCW=ENABLED”) in new stack
– Executing [s@macro-dial-one:13] GotoIf(“DAHDI/1-1”, “0?next1:cwinusebusy”) in new stack
– Goto (macro-dial-one,s,25)
– Executing [s@macro-dial-one:25] GotoIf(“DAHDI/1-1”, “0?next3:continue”) in new stack
– Goto (macro-dial-one,s,27)
– Executing [s@macro-dial-one:27] GotoIf(“DAHDI/1-1”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:28] GosubIf(“DAHDI/1-1”, “1?dstring,1():dlocal,1()”) in new stack
– Executing [dstring@macro-dial-one:1] Set(“DAHDI/1-1”, “DSTRING=”) in new stack
– Executing [dstring@macro-dial-one:2] Set(“DAHDI/1-1”, “DEVICES=27”) in new stack
– Executing [dstring@macro-dial-one:3] ExecIf(“DAHDI/1-1”, “0?Return()”) in new stack
– Executing [dstring@macro-dial-one:4] ExecIf(“DAHDI/1-1”, “0?Set(DEVICES=7)”) in new stack
– Executing [dstring@macro-dial-one:5] Set(“DAHDI/1-1”, “LOOPCNT=1”) in new stack
– Executing [dstring@macro-dial-one:6] Set(“DAHDI/1-1”, “ITER=1”) in new stack
– Executing [dstring@macro-dial-one:7] Set(“DAHDI/1-1”, “THISDIAL=PJSIP/27”) in new stack
– Executing [dstring@macro-dial-one:8] GotoIf(“DAHDI/1-1”, “0?docheck”) in new stack
– Executing [dstring@macro-dial-one:9] NoOp(“DAHDI/1-1”, “Debug: Found PJSIP Destination PJSIP/27”) in new stack
– Executing [dstring@macro-dial-one:10] GotoIf(“DAHDI/1-1”, “0?doset”) in new stack
– Executing [dstring@macro-dial-one:11] NoOp(“DAHDI/1-1”, “Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS”) in new stack
– Executing [dstring@macro-dial-one:12] Set(“DAHDI/1-1”, “THISDIAL=PJSIP/27/sip:27@50.100.150.200:49740;x-ast-orig-host=192.168.11.5:5060”) in new stack
– Executing [dstring@macro-dial-one:13] ExecIf(“DAHDI/1-1”, “0?Set(DIALSTATUS=CHANUNAVAIL)”) in new stack
– Executing [dstring@macro-dial-one:14] GotoIf(“DAHDI/1-1”, “0?skipset”) in new stack
– Executing [dstring@macro-dial-one:15] Set(“DAHDI/1-1”, “DSTRING=PJSIP/27/sip:27@50.100.150.200:49740;x-ast-orig-host=192.168.11.5:5060&”) in new stack
– Executing [dstring@macro-dial-one:16] Set(“DAHDI/1-1”, “ITER=2”) in new stack
– Executing [dstring@macro-dial-one:17] GotoIf(“DAHDI/1-1”, “0?begin”) in new stack
– Executing [dstring@macro-dial-one:18] ExecIf(“DAHDI/1-1”, “0?Return()”) in new stack
– Executing [dstring@macro-dial-one:19] Set(“DAHDI/1-1”, “DSTRING=PJSIP/27/sip:27@50.100.150.200:49740;x-ast-orig-host=192.168.11.5:5060”) in new stack
– Executing [dstring@macro-dial-one:20] Return(“DAHDI/1-1”, “”) in new stack
– Executing [s@macro-dial-one:29] GotoIf(“DAHDI/1-1”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:30] GotoIf(“DAHDI/1-1”, “0?skiptrace”) in new stack
– Executing [s@macro-dial-one:31] GosubIf(“DAHDI/1-1”, “0?ctset,1():ctclear,1()”) in new stack
– Executing [ctclear@macro-dial-one:1] NoOp(“DAHDI/1-1”, "Deleting: CALLTRACE/27 ") in new stack
– Executing [ctclear@macro-dial-one:2] Return(“DAHDI/1-1”, “”) in new stack
– Executing [s@macro-dial-one:32] Set(“DAHDI/1-1”, “D_OPTIONS=HhTtr”) in new stack
– Executing [s@macro-dial-one:33] GosubIf(“DAHDI/1-1”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
– Executing [s@macro-dial-one:34] NoOp(“DAHDI/1-1”, "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
– Executing [s@macro-dial-one:35] ExecIf(“DAHDI/1-1”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [s@macro-dial-one:36] ExecIf(“DAHDI/1-1”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [s@macro-dial-one:37] ExecIf(“DAHDI/1-1”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [s@macro-dial-one:38] ExecIf(“DAHDI/1-1”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
– Executing [s@macro-dial-one:39] ExecIf(“DAHDI/1-1”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
– Executing [s@macro-dial-one:40] GosubIf(“DAHDI/1-1”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
– Executing [s@macro-dial-one:41] ExecIf(“DAHDI/1-1”, “0?Set(CHANNEL(musicclass)=)”) in new stack
– Executing [s@macro-dial-one:42] GosubIf(“DAHDI/1-1”, “0?qwait,1()”) in new stack
– Executing [s@macro-dial-one:43] Set(“DAHDI/1-1”, “__CWIGNORE=”) in new stack
– Executing [s@macro-dial-one:44] Set(“DAHDI/1-1”, “__KEEPCID=TRUE”) in new stack
– Executing [s@macro-dial-one:45] GotoIf(“DAHDI/1-1”, “0?usegoto,1”) in new stack
– Executing [s@macro-dial-one:46] GotoIf(“DAHDI/1-1”, “1?godial”) in new stack
– Goto (macro-dial-one,s,51)
– Executing [s@macro-dial-one:51] Macro(“DAHDI/1-1”, “dialout-one-predial-hook,”) in new stack
– Executing [s@macro-dialout-one-predial-hook:1] MacroExit(“DAHDI/1-1”, “”) in new stack
– Executing [s@macro-dial-one:52] ExecIf(“DAHDI/1-1”, “1?Set(D_OPTIONS=HhtrI)”) in new stack
– Executing [s@macro-dial-one:53] ExecIf(“DAHDI/1-1”, “0?Set(CWRING=r(callwaiting)):Set(CWRING=)”) in new stack
– Executing [s@macro-dial-one:54] NoOp(“DAHDI/1-1”, “”) in new stack
– Executing [s@macro-dial-one:55] ExecIf(“DAHDI/1-1”, “0?Set(D_OPTIONS=HhtrIg)”) in new stack
– Executing [s@macro-dial-one:56] Dial(“DAHDI/1-1”, “PJSIP/27/sip:27@50.100.150.200:49740;x-ast-orig-host=192.168.11.5:5060,HhtrIb(func-apply-sipheaders^s^1)”) in new stack
– PJSIP/27-00000000 Internal Gosub(func-apply-sipheaders,s,1) start
.
.
.
.
.
.
– Hanging up on ‘DAHDI/1-1’
– Hungup ‘DAHDI/1-1’

Can anyone spot a mistake in my configuration or provide ideas on how to further troubleshoot this problem?

Observations:

  • The above log is generated immediately on the first ring and I have the feeling that the CID information has not been delivered yet to the DigiumTDM card at this time.
  • Setting the “Callerid” property to a specific number (e.g. callerid=123456) instead of “asreceived” has no effect. I was expecting that this will force the CID in the logs to be 123456 but instead there is no CID information again that makes me wonder if the chan_dahdi.conf is parsed properly.
2

My feeling is that this is a FreePBX problem, not allowing the caller ID to arrive before trying to use it, but you also seem to have screen scraped the log, rather than using the log files, so there is insufficient timing information.

Given the presumption that this is a FreePBX issue, you need to use http://community.freepbx.org/ for peer support.

3

Hi David,

Thank you for your response.
I have already seek assistance at the FreePBX community with no success (No Caller ID information on Inbound PSTN Call - Hardware - FreePBX Community Forums).

To my very shallow knowledge FreePBX is just a GUI seating on top of asterisk and affecting only the various configuration files.
I have taken another log with debug enabled for chan_dahdi including timestamps:

[2021-08-31 00:00:43] DEBUG[2476] chan_dahdi.c: Monitor doohicky got event Ring Begin on channel 1
[2021-08-31 00:00:43] DEBUG[2476] sig_analog.c: channel (1) - signaling (5) - event (ANALOG_EVENT_RINGBEGIN)
[2021-08-31 00:00:44] DEBUG[2476] chan_dahdi.c: Monitor doohicky got event Ring/Answered on channel 1
[2021-08-31 00:00:44] DEBUG[2476] sig_analog.c: channel (1) - signaling (5) - event (ANALOG_EVENT_RINGOFFHOOK)
[2021-08-31 00:00:44] DEBUG[4630] sig_analog.c: __analog_ss_thread 1
[2021-08-31 00:00:44] VERBOSE[4630][C-00000001] sig_analog.c: Starting simple switch on ‘DAHDI/1-1’
[2021-08-31 00:00:46] DEBUG[4630][C-00000001] chan_dahdi.c: CallerID number: (null), name: (null), flags=3
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@from-analog:1] NoOp(“DAHDI/1-1”, "Entering from-dahdi with DID == ") in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@from-analog:2] Ringing(“DAHDI/1-1”, “”) in new stack
[2021-08-31 00:00:46] DEBUG[4630][C-00000001] chan_dahdi.c: Requested indication 3 on channel DAHDI/1-1
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@from-analog:3] Set(“DAHDI/1-1”, “DID=s”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@from-analog:4] NoOp(“DAHDI/1-1”, “DID is now s”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@from-analog:5] GotoIf(“DAHDI/1-1”, “1?dahdiok:checkzap”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (from-analog,s,9)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@from-analog:9] NoOp(“DAHDI/1-1”, “Is a DAHDi Channel”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@from-analog:10] Set(“DAHDI/1-1”, “CHAN=1-1”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@from-analog:11] Set(“DAHDI/1-1”, “CHAN=1”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@from-analog:12] Macro(“DAHDI/1-1”, “from-dahdi-1,s,1”) in new stack
[2021-08-31 00:00:46] WARNING[4630][C-00000001] app_macro.c: Macro() is deprecated and will be removed from a future version of Asterisk.
[2021-08-31 00:00:46] WARNING[4630][C-00000001] app_macro.c: Dialplan should be updated to use Gosub instead.
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-from-dahdi-1:1] NoOp(“DAHDI/1-1”, “Entering macro-from-dahdi-1 with DID = s and setting to: +302612345678”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-from-dahdi-1:2] Set(“DAHDI/1-1”, “__FROM_DID=+302612345678”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-from-dahdi-1:3] Goto(“DAHDI/1-1”, “from-trunk,+302612345678,1”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (from-trunk,+302612345678,1)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] app_macro.c: Channel ‘DAHDI/1-1’ jumping out of macro ‘from-dahdi-1’
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:1] Set(“DAHDI/1-1”, “__DIRECTION=INBOUND”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:2] Gosub(“DAHDI/1-1”, “sub-record-check,s,1(in,+302612345678,dontcare)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:1] GotoIf(“DAHDI/1-1”, “0?initialized”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:2] Set(“DAHDI/1-1”, “__REC_STATUS=INITIALIZED”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:3] Set(“DAHDI/1-1”, “NOW=1630357246”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:4] Set(“DAHDI/1-1”, “__DAY=31”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:5] Set(“DAHDI/1-1”, “__MONTH=08”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:6] Set(“DAHDI/1-1”, “__YEAR=2021”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:7] Set(“DAHDI/1-1”, “__TIMESTR=20210831-000046”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:8] Set(“DAHDI/1-1”, “__FROMEXTEN=unknown”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:9] Set(“DAHDI/1-1”, “__MON_FMT=wav”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:10] NoOp(“DAHDI/1-1”, “Recordings initialized”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:11] ExecIf(“DAHDI/1-1”, “0?Set(ARG3=dontcare)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:12] Set(“DAHDI/1-1”, “REC_POLICY_MODE_SAVE=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:13] ExecIf(“DAHDI/1-1”, “0?Set(REC_STATUS=NO)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:14] GotoIf(“DAHDI/1-1”, “2?checkaction”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (sub-record-check,s,17)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@sub-record-check:17] GotoIf(“DAHDI/1-1”, “1?sub-record-check,in,1”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (sub-record-check,in,1)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [in@sub-record-check:1] NoOp(“DAHDI/1-1”, “Inbound Recording Check to +302612345678”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [in@sub-record-check:2] Set(“DAHDI/1-1”, “FROMEXTEN=unknown”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [in@sub-record-check:3] ExecIf(“DAHDI/1-1”, “0?Set(FROMEXTEN=)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [in@sub-record-check:4] Gosub(“DAHDI/1-1”, “recordcheck,1(dontcare,in,+302612345678)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“DAHDI/1-1”, “Starting recording check against dontcare”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“DAHDI/1-1”, “dontcare”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“DAHDI/1-1”, “”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [in@sub-record-check:5] Return(“DAHDI/1-1”, “”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:3] Set(“DAHDI/1-1”, “CHANNEL(tonezone)=gr”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:4] Set(“DAHDI/1-1”, “__FROM_DID=+302612345678”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:5] Set(“DAHDI/1-1”, “returnhere=1”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:6] Gosub(“DAHDI/1-1”, “app-blacklist-check,s,1()”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@app-blacklist-check:1] GotoIf(“DAHDI/1-1”, “0?blacklisted”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@app-blacklist-check:2] Set(“DAHDI/1-1”, “CALLED_BLACKLIST=1”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@app-blacklist-check:3] Return(“DAHDI/1-1”, “”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:7] Set(“DAHDI/1-1”, “CDR(did)=+302612345678”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:8] GotoIf(“DAHDI/1-1”, “0?”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:9] ExecIf(“DAHDI/1-1”, “1 ?Set(CALLERID(name)=)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:10] Set(“DAHDI/1-1”, “__MOHCLASS=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:11] Set(“DAHDI/1-1”, “__REVERSAL_REJECT=FALSE”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:12] GotoIf(“DAHDI/1-1”, “1?post-reverse-charge”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (from-trunk,+302612345678,14)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:14] NoOp(“DAHDI/1-1”, “”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:15] Set(“DAHDI/1-1”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:16] Set(“DAHDI/1-1”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:17] Set(“DAHDI/1-1”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:18] Set(“DAHDI/1-1”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:19] NoOp(“DAHDI/1-1”, “CallerID Entry Point”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:20] Set(“DAHDI/1-1”, “__CRM_DIRECTION=INBOUND”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:21] Set(“DAHDI/1-1”, “__CRM_SOURCE=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:22] Set(“DAHDI/1-1”, “__CRM_LINKEDID=1630357244.0”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:23] AGI(“DAHDI/1-1”, “agi://127.0.0.1/sangomacrm.agi,true”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] res_agi.c: <DAHDI/1-1>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:24] ExecIf(“DAHDI/1-1”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [+302612345678@from-trunk:25] Goto(“DAHDI/1-1”, “from-did-direct,27,1”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (from-did-direct,27,1)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [27@from-did-direct:1] GotoIf(“DAHDI/1-1”, “1?ext-local,27,1:followme-check,27,1”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (ext-local,27,1)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [27@ext-local:1] Set(“DAHDI/1-1”, “__RINGTIMER=15”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [27@ext-local:2] ExecIf(“DAHDI/1-1”, “0?Set(__CWIGNORE=)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [27@ext-local:3] Macro(“DAHDI/1-1”, “exten-vm,novm,27,0,0,0”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:1] Macro(“DAHDI/1-1”, “user-callerid,”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:1] Set(“DAHDI/1-1”, “TOUCH_MONITOR=1630357244.0”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:2] Set(“DAHDI/1-1”, “CHANCONTEXT=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:3] Set(“DAHDI/1-1”, “CHANCONTEXT=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:4] Set(“DAHDI/1-1”, “CHANEXTENCONTEXT=1-1”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:5] Set(“DAHDI/1-1”, “CHANEXTEN=1-1”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:6] Set(“DAHDI/1-1”, “CALLERID(number)=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:7] Set(“DAHDI/1-1”, “AMPUSER=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:8] Set(“DAHDI/1-1”, “HOTDESCKCHAN=1-1”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:9] Set(“DAHDI/1-1”, “HOTDESKEXTEN=1”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:10] Set(“DAHDI/1-1”, “HOTDESKCALL=0”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:11] ExecIf(“DAHDI/1-1”, “0?Set(HOTDESKCALL=1)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:12] ExecIf(“DAHDI/1-1”, “0?Set(CALLERID(name)=)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:13] GotoIf(“DAHDI/1-1”, “0?report”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:14] ExecIf(“DAHDI/1-1”, “1?Set(REALCALLERIDNUM=)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:15] Set(“DAHDI/1-1”, “AMPUSER=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:16] GotoIf(“DAHDI/1-1”, “0?limit”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:17] Set(“DAHDI/1-1”, “AMPUSERCIDNAME=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:18] ExecIf(“DAHDI/1-1”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:19] GotoIf(“DAHDI/1-1”, “1?report”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (macro-user-callerid,s,28)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:28] NoOp(“DAHDI/1-1”, “Macro Depth is 2”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:29] GotoIf(“DAHDI/1-1”, “1?report2:macroerror”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (macro-user-callerid,s,30)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:30] GotoIf(“DAHDI/1-1”, “0?continue”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:31] ExecIf(“DAHDI/1-1”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:32] Set(“DAHDI/1-1”, “__TTL=64”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:33] GotoIf(“DAHDI/1-1”, “1?continue”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (macro-user-callerid,s,49)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:49] Set(“DAHDI/1-1”, “CALLERID(number)=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:50] Set(“DAHDI/1-1”, “CALLERID(name)=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:51] GotoIf(“DAHDI/1-1”, “1?cnum”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (macro-user-callerid,s,53)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:53] Set(“DAHDI/1-1”, “CDR(cnum)=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-user-callerid:54] Set(“DAHDI/1-1”, “CHANNEL(language)=gr”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:2] Set(“DAHDI/1-1”, “RingGroupMethod=none”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:3] Set(“DAHDI/1-1”, “__EXTTOCALL=27”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:4] Set(“DAHDI/1-1”, “__PICKUPMARK=27”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:5] Set(“DAHDI/1-1”, “RT=”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:6] ExecIf(“DAHDI/1-1”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:7] ExecIf(“DAHDI/1-1”, “0?MacroExit()”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:8] ExecIf(“DAHDI/1-1”, “0?Gosub(ext-intercom,*8027,1())”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:9] ExecIf(“DAHDI/1-1”, “0?MacroExit()”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:10] ExecIf(“DAHDI/1-1”, “0?ChanSpy(PJSIP/27,q)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:11] ExecIf(“DAHDI/1-1”, “0?MacroExit()”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:12] ExecIf(“DAHDI/1-1”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
.
.
.
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (sub-record-check,exten,11)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [exten@sub-record-check:11] Gosub(“DAHDI/1-1”, “recordcheck,1(dontcare,external,27)”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“DAHDI/1-1”, “Starting recording check against dontcare”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“DAHDI/1-1”, “dontcare”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“DAHDI/1-1”, “”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [exten@sub-record-check:12] Return(“DAHDI/1-1”, “”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:23] GotoIf(“DAHDI/1-1”, “1?macrodial”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx_builtins.c: Goto (macro-exten-vm,s,29)
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:29] GosubIf(“DAHDI/1-1”, “0?clrheader,1()”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [s@macro-exten-vm:30] Macro(“DAHDI/1-1”, “dial-one,HhTtr,27”) in new stack
.
.
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [dstring@macro-dial-one:11] NoOp(“DAHDI/1-1”, “Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS”) in new stack
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] pbx.c: Executing [dstring@macro-dial-one:12] Set(“DAHDI/1-1”, “THISDIAL=PJSIP/27/sip:27@50.100.150.200:25399;x-ast-orig-host=192.168.11.5:5060”) in new stack
.
.
.
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] app_stack.c: PJSIP/27-00000000 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] app_dial.c: Called PJSIP/27/sip:27@50.100.150.200:25399;x-ast-orig-host=192.168.11.5:5060
[2021-08-31 00:00:46] DEBUG[4630][C-00000001] chan_dahdi.c: Requested indication 3 on channel DAHDI/1-1
.
.
.
[2021-08-31 00:00:46] VERBOSE[4630][C-00000001] app_dial.c: Connected line update to DAHDI/1-1 prevented.
[2021-08-31 00:00:46] DEBUG[4630][C-00000001] sig_analog.c: analog_exception 1
[2021-08-31 00:00:46] DEBUG[4630][C-00000001] sig_analog.c: Exception on 35, channel 1
[2021-08-31 00:00:46] DEBUG[4630][C-00000001] sig_analog.c: __analog_handle_event 1
[2021-08-31 00:00:46] DEBUG[4630][C-00000001] sig_analog.c: Got event ANALOG_EVENT_RINGBEGIN(12) on channel 1 (index 0)
[2021-08-31 00:00:46] DEBUG[4630][C-00000001] chan_dahdi.c: Requested indication 33 on channel DAHDI/1-1
[2021-08-31 00:00:47] DEBUG[4630][C-00000001] chan_dahdi.c: Requested indication 33 on channel DAHDI/1-1
[2021-08-31 00:00:47] VERBOSE[4630][C-00000001] app_dial.c: PJSIP/27-00000000 is ringing
[2021-08-31 00:00:47] DEBUG[4630][C-00000001] chan_dahdi.c: Requested indication 3 on channel DAHDI/1-1
[2021-08-31 00:00:47] DEBUG[4630][C-00000001] chan_dahdi.c: Requested indication 33 on channel DAHDI/1-1
[2021-08-31 00:00:47] DEBUG[4630][C-00000001] sig_analog.c: analog_exception 1
[2021-08-31 00:00:47] DEBUG[4630][C-00000001] sig_analog.c: Exception on 35, channel 1
[2021-08-31 00:00:47] DEBUG[4630][C-00000001] sig_analog.c: __analog_handle_event 1
[2021-08-31 00:00:47] DEBUG[4630][C-00000001] sig_analog.c: Got event ANALOG_EVENT_RINGOFFHOOK(2) on channel 1 (index 0)
[2021-08-31 00:00:47] DEBUG[4630][C-00000001] sig_analog.c: Ring detected
[2021-08-31 00:00:55] VERBOSE[4630][C-00000001] app_stack.c: PJSIP/27-00000000 Internal Gosub(crm-hangup,s,1) start
.
.
.
.
[2021-08-31 00:00:56] VERBOSE[4630][C-00000001] app_stack.c: DAHDI/1-1 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2021-08-31 00:00:56] DEBUG[4630][C-00000001] chan_dahdi.c: dahdi_hangup(DAHDI/1-1)
[2021-08-31 00:00:56] DEBUG[4630][C-00000001] sig_analog.c: analog_hangup 1
[2021-08-31 00:00:56] DEBUG[4630][C-00000001] sig_analog.c: Hangup: channel: 1 index = 0, normal = 1, callwait = 0, thirdcall = 0
[2021-08-31 00:00:56] DEBUG[4630][C-00000001] chan_dahdi.c: Set option TONE VERIFY, mode: OFF(0) on DAHDI/1-1
[2021-08-31 00:00:56] DEBUG[4630][C-00000001] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/1-1
[2021-08-31 00:00:56] DEBUG[4630][C-00000001] sig_analog.c: Updated conferencing on 1, with 0 conference users
[2021-08-31 00:00:56] VERBOSE[4630][C-00000001] sig_analog.c: Hanging up on ‘DAHDI/1-1’
[2021-08-31 00:00:56] VERBOSE[4630][C-00000001] chan_dahdi.c: Hungup ‘DAHDI/1-1’

According to my poor understanding chan_dahdi driver should wait for the CID data to arrive (assuming that my chan_dahdi.conf configuration is correct) and then submit it for further processing according to Dialplan.

Instead just before the Dialplan begins execution chan_dahdi.c reports no CID data:

[2021-08-31 00:00:46] DEBUG[4630][C-00000001] chan_dahdi.c: CallerID number: (null), name: (null), flags=3

Even after the above log event and before the call is terminated neither chan_dahdi.c nor sig_analog.c reports any CID detection activity so I don’t think that the CID is ever parsed by the Dahdi driver.

Do you have any suggestion on how to further troubleshoot this issue?
Assuming that the chan_dahdi.conf has no mistake is it possible that we are facing a bug here?

4

No. It is a GUI sitting on top of many 100s of lines of custom dialplan; it is not a general purpose configuration tool for Asterisk. The dialplan implements a large number of abstractions, like IVRs, ring groups, trunks, routes, etc.

The general policy here is that you should get support for DAHDI related problems from the card vendor. As such I’m not used to analysing DAHDI debugging, but I do notice that you are starting a simple switch before the caller ID arrives. I would have assumed that would have required the line to go off hook. I’d suggest trying “immediate=yes”.

Also, to eliminate FreePBX, could you please replace the FreePBX dialplan with:

exten => s,1,Wait(5)
same => n,Noop(${CALLERID(all)})

5

According to your logs, this line in the FreePBX dialplan is overwriting the caller ID. It appears to be part of the outgoing processing for extension 27.

Unfortunately, I cannot find anywhere in the FreePBX source code, even trying several versions, where this macro accesses anything called CHANEXTEN, so I can’t match this to the FreePBX source code.

6

Need a ‘n,’ in there:

same => n,noop(${CALLERID(all)})
7

Hi David (and sedwards),
I have replaced the Dialplan as per your recommendation and tested with immediate=yes and no. In both cases the same log is received (as shown below). Unfortunately, no CID is presented yet.

[2021-08-31 21:18:22] DEBUG[2663] chan_dahdi.c: Monitor doohicky got event Ring Begin on channel 1
[2021-08-31 21:18:22] DEBUG[2663] sig_analog.c: channel (1) - signaling (5) - event (ANALOG_EVENT_RINGBEGIN)
[2021-08-31 21:18:23] DEBUG[2663] chan_dahdi.c: Monitor doohicky got event Ring/Answered on channel 1
[2021-08-31 21:18:23] DEBUG[2663] sig_analog.c: channel (1) - signaling (5) - event (ANALOG_EVENT_RINGOFFHOOK)
[2021-08-31 21:18:23] DEBUG[4022] sig_analog.c: __analog_ss_thread 1
[2021-08-31 21:18:23] VERBOSE[4022][C-00000001] sig_analog.c: Starting simple switch on ‘DAHDI/1-1’
[2021-08-31 21:18:25] DEBUG[4022][C-00000001] chan_dahdi.c: CallerID number: (null), name: (null), flags=3
[2021-08-31 21:18:25] VERBOSE[4022][C-00000001] pbx.c: Executing [s@from-dahdicid:1] Wait(“DAHDI/1-1”, “5”) in new stack
[2021-08-31 21:18:25] DEBUG[4022][C-00000001] sig_analog.c: analog_exception 1
[2021-08-31 21:18:25] DEBUG[4022][C-00000001] sig_analog.c: Exception on 34, channel 1
[2021-08-31 21:18:25] DEBUG[4022][C-00000001] sig_analog.c: __analog_handle_event 1
[2021-08-31 21:18:25] DEBUG[4022][C-00000001] sig_analog.c: Got event ANALOG_EVENT_RINGBEGIN(12) on channel 1 (index 0)
[2021-08-31 21:18:26] DEBUG[4022][C-00000001] sig_analog.c: analog_exception 1
[2021-08-31 21:18:26] DEBUG[4022][C-00000001] sig_analog.c: Exception on 34, channel 1
[2021-08-31 21:18:26] DEBUG[4022][C-00000001] sig_analog.c: __analog_handle_event 1
[2021-08-31 21:18:26] DEBUG[4022][C-00000001] sig_analog.c: Got event ANALOG_EVENT_RINGOFFHOOK(2) on channel 1 (index 0)
[2021-08-31 21:18:26] DEBUG[4022][C-00000001] sig_analog.c: Ring detected
[2021-08-31 21:18:30] VERBOSE[4022][C-00000001] pbx.c: Executing [s@from-dahdicid:2] NoOp(“DAHDI/1-1”, “”" <>") in new stack
[2021-08-31 21:18:30] VERBOSE[4022][C-00000001] pbx.c: Auto fallthrough, channel ‘DAHDI/1-1’ status is ‘UNKNOWN’
[2021-08-31 21:18:30] DEBUG[4022][C-00000001] chan_dahdi.c: dahdi_hangup(DAHDI/1-1)
[2021-08-31 21:18:30] DEBUG[4022][C-00000001] sig_analog.c: analog_hangup 1
[2021-08-31 21:18:30] DEBUG[4022][C-00000001] sig_analog.c: Hangup: channel: 1 index = 0, normal = 1, callwait = 0, thirdcall = 0
[2021-08-31 21:18:30] DEBUG[4022][C-00000001] chan_dahdi.c: Set option TONE VERIFY, mode: OFF(0) on DAHDI/1-1
[2021-08-31 21:18:30] DEBUG[4022][C-00000001] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/1-1
[2021-08-31 21:18:30] DEBUG[4022][C-00000001] sig_analog.c: Updated conferencing on 1, with 0 conference users
[2021-08-31 21:18:30] VERBOSE[4022][C-00000001] sig_analog.c: Hanging up on ‘DAHDI/1-1’
[2021-08-31 21:18:30] VERBOSE[4022][C-00000001] chan_dahdi.c: Hungup ‘DAHDI/1-1’

I am also uploading for your reference (pre-rx-on.wav) the line monitor recording that the FSK CID information can be heard between the first and second ring tones.
Do you have any suggestions on how to further troubleshoot this problem?

8

Can you try immediate=yes, as well. You currently definitely don’t have any caller ID coming through.

9

I did try to set immediate=yes as well. No CID is received again. I am receiving the same logs that I get with immediate=no

10

I’d expect not to get the “starting simple switch” line if you used immediate, successfully. A check of the code confirms this. Checking the detailed handling of caller ID would be a lot more work, though.

However, because vendors are expected to address such things, people generally don’t debug DAHDI issues on this forum, and most people are SIP, rather than analogue users. I haven’t seen the Digium employee who might have known about DAHDI contributing here recently, and I think all the current Sangoma contributors are VoIP people.

11

Digium still sell analog cards and I am sure that a lot of people using them as VoIP infrastructure is not everywhere available yet. It is disappointing to see such an important feature as the Caller ID malfunctioning.
Since most probably this is a bug shall I try to report it to Digium?

12

Digium were taken over by Sangoma, although it would appear that that series of cards is still being sold.

Before the takeover, the position used to be that, because Digium cards were supported you should use their support. The idea being, I think, that third party clones would not be supported, and they didn’t want to fund a forum that was making up for that lack of support.

However, there do seem to have been occasions when people with old cards were no longer able to get support. Consequently, I’m not really sure whether your card would still be supported, and whether Sangoma is providing free support for Digium cards.

However, although I’m not sure that “immediate” is the problem, the code does indicate that setting it to true should result in no “starting simple switch” message, so I think you should double check that you successfully set it, as it will produce a difference in the logs.

13

What about the observation I mentioned in my first post:

  • Setting the “Callerid” property to a specific number (e.g. callerid=123456) instead of “asreceived” has no effect. I was expecting that this will force the CID in the logs to be 123456 but instead there is no CID information again that makes me wonder if the chan_dahdi.conf is parsed properly.

Your remark that setting immediate to yes should have an effect and my observation above maybe is an indication that something else is the problem?

14

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