Hi,
many thanks for your reply.
Please check the following log
localhost*CLI>
[2017-06-12 23:31:16] DEBUG[20340]: chan_dahdi.c:12625 do_monitor: Monitor doohicky got event Ring Begin on channel 7
[2017-06-12 23:31:16] DEBUG[20340]: sig_analog.c:3694 analog_handle_init_event: channel (7) - signaling (5) - event (ANALOG_EVENT_RINGBEGIN)
[2017-06-12 23:31:17] DEBUG[2402]: chan_sip.c:8679 sip_alloc: Allocating new SIP dialog for 5bf362715a3be02e20fec4ff5d2d47c8@[::1]:5060 - OPTIONS (No RTP)
[2017-06-12 23:31:17] DEBUG[2402]: chan_sip.c:8465 change_callid_pvt: SIP call-id changed from ‘5bf362715a3be02e20fec4ff5d2d47c8@[::1]:5060’ to ‘[email protected]:5060’
[2017-06-12 23:31:17] DEBUG[2402]: chan_sip.c:3374 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2017-06-12 23:31:17] DEBUG[2402]: chan_sip.c:4429 __sip_ack: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2017-06-12 23:31:17] DEBUG[20340]: chan_dahdi.c:12625 do_monitor: Monitor doohicky got event Ring/Answered on channel 7
[2017-06-12 23:31:17] DEBUG[20340]: sig_analog.c:3694 analog_handle_init_event: channel (7) - signaling (5) - event (ANALOG_EVENT_RINGOFFHOOK)
[2017-06-12 23:31:17] DEBUG[20340][C-000003c9]: dsp.c:475 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[2017-06-12 23:31:17] DEBUG[20340][C-000003c9]: dsp.c:475 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[2017-06-12 23:31:17] DEBUG[2471]: sig_analog.c:1766 __analog_ss_thread: __analog_ss_thread 7
– Starting simple switch on ‘DAHDI/7-1’
[2017-06-12 23:31:21] DEBUG[2402]: chan_sip.c:8679 sip_alloc: Allocating new SIP dialog for 6e6f09e72ca1246146ac6bda68650a9e@[::1]:5060 - OPTIONS (No RTP)
[2017-06-12 23:31:21] DEBUG[2402]: chan_sip.c:8465 change_callid_pvt: SIP call-id changed from ‘6e6f09e72ca1246146ac6bda68650a9e@[::1]:5060’ to ‘[email protected]:5060’
[2017-06-12 23:31:21] DEBUG[2402]: chan_sip.c:3374 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2017-06-12 23:31:21] DEBUG[2402]: chan_sip.c:4429 __sip_ack: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘NoOp’
– Executing [s@from-analog:1] NoOp(“DAHDI/7-1”, "Entering from-dahdi with DID == ") in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Ringing’
– Executing [s@from-analog:2] Ringing(“DAHDI/7-1”, “”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: chan_dahdi.c:10047 dahdi_indicate: Requested indication 3 on channel DAHDI/7-1
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:4905 pbx_substitute_variables_helper_full: Expression result is ‘1’
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@from-analog:3] Set(“DAHDI/7-1”, “DID=s”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘NoOp’
– Executing [s@from-analog:4] NoOp(“DAHDI/7-1”, “DID is now s”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:4905 pbx_substitute_variables_helper_full: Expression result is ‘1’
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘GotoIf’
– Executing [s@from-analog:5] GotoIf(“DAHDI/7-1”, “1?dahdiok:checkzap”) in new stack
– Goto (from-analog,s,9)
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘NoOp’
– Executing [s@from-analog:9] NoOp(“DAHDI/7-1”, “Is a DAHDi Channel”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@from-analog:10] Set(“DAHDI/7-1”, “CHAN=7-1”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@from-analog:11] Set(“DAHDI/7-1”, “CHAN=7”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Macro’
– Executing [s@from-analog:12] Macro(“DAHDI/7-1”, “from-dahdi-7,s,1”) in new stack
[2017-06-12 23:31:27] WARNING[2471][C-000003c9]: app_macro.c:309 _macro_exec: No such context ‘macro-from-dahdi-7’ for macro ‘from-dahdi-7’. Was called by s@from-analog
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘NoOp’
– Executing [s@from-analog:13] NoOp(“DAHDI/7-1”, “Returned from Macro from-dahdi-7”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Goto’
– Executing [s@from-analog:14] Goto(“DAHDI/7-1”, “from-pstn,s,1”) in new stack
– Goto (from-pstn,s,1)
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:4905 pbx_substitute_variables_helper_full: Expression result is ‘1’
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘ExecIf’
– Executing [s@from-pstn:1] ExecIf(“DAHDI/7-1”, “1?Set(__FROM_DID=s)”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Gosub’
– Executing [s@from-pstn:2] Gosub(“DAHDI/7-1”, “app-blacklist-check,s,1()”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: app_stack.c:579 gosub_exec: Channel DAHDI/7-1 has no datastore, so we’re allocating one.
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: db.c:376 db_get_common: Unable to find key ‘’ in family ‘blacklist’
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: db.c:376 db_get_common: Unable to find key ‘’ in family ‘blacklist’
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:4905 pbx_substitute_variables_helper_full: Expression result is ‘0’
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘GotoIf’
– Executing [s@app-blacklist-check:1] GotoIf(“DAHDI/7-1”, “0?blacklisted”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:12181 pbx_builtin_gotoif: Not taking any branch
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@app-blacklist-check:2] Set(“DAHDI/7-1”, “CALLED_BLACKLIST=1”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Return’
– Executing [s@app-blacklist-check:3] Return(“DAHDI/7-1”, “”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@from-pstn:3] Set(“DAHDI/7-1”, “CDR(did)=s”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:4905 pbx_substitute_variables_helper_full: Expression result is ‘1’
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘ExecIf’
– Executing [s@from-pstn:4] ExecIf(“DAHDI/7-1”, “1 ?Set(CALLERID(name)=)”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@from-pstn:5] Set(“DAHDI/7-1”, “CHANNEL(musicclass)=default”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@from-pstn:6] Set(“DAHDI/7-1”, “__MOHCLASS=default”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@from-pstn:7] Set(“DAHDI/7-1”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@from-pstn:8] Set(“DAHDI/7-1”, “CALLERPRES()=allowed_not_screened”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Goto’
– Executing [s@from-pstn:9] Goto(“DAHDI/7-1”, “ivr-4,s,1”) in new stack
– Goto (ivr-4,s,1)
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@ivr-4:1] Set(“DAHDI/7-1”, “TIMEOUT_LOOPCOUNT=0”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@ivr-4:2] Set(“DAHDI/7-1”, “INVALID_LOOPCOUNT=0”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@ivr-4:3] Set(“DAHDI/7-1”, “_IVR_CONTEXT_ivr-4=”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@ivr-4:4] Set(“DAHDI/7-1”, “_IVR_CONTEXT=ivr-4”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@ivr-4:5] Set(“DAHDI/7-1”, “__IVR_RETVM=”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:4905 pbx_substitute_variables_helper_full: Expression result is ‘0’
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘GotoIf’
– Executing [s@ivr-4:6] GotoIf(“DAHDI/7-1”, “0?skip”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:12181 pbx_builtin_gotoif: Not taking any branch
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Answer’
– Executing [s@ivr-4:7] Answer(“DAHDI/7-1”, “”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: sig_analog.c:1497 analog_answer: analog_answer 7
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: sig_analog.c:1528 analog_answer: Took DAHDI/7-1 off hook
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: chan_dahdi.c:5379 dahdi_enable_ec: Enabled echo cancellation on channel 7
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: chan_dahdi.c:5398 dahdi_train_ec: No echo training requested
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: chan_dahdi.c:10047 dahdi_indicate: Requested indication -1 on channel DAHDI/7-1
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Wait’
– Executing [s@ivr-4:8] Wait(“DAHDI/7-1”, “1”) in new stack
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: channel.c:5416 set_format: Set channel DAHDI/7-1 to write format slin
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: channel.c:3597 ast_settimeout_full: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[2017-06-12 23:31:27] DEBUG[2471][C-000003c9]: channel.c:8846 ast_channel_start_silence_generator: Started silence generator on ‘DAHDI/7-1’
[2017-06-12 23:31:28] DEBUG[2471][C-000003c9]: channel.c:3597 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2017-06-12 23:31:28] DEBUG[2471][C-000003c9]: channel.c:8881 ast_channel_stop_silence_generator: Stopped silence generator on ‘DAHDI/7-1’
[2017-06-12 23:31:28] DEBUG[2471][C-000003c9]: channel.c:5416 set_format: Set channel DAHDI/7-1 to write format ulaw
[2017-06-12 23:31:28] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@ivr-4:9] Set(“DAHDI/7-1”, “IVR_MSG=custom/Main_Welcome2”) in new stack
[2017-06-12 23:31:28] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Set’
– Executing [s@ivr-4:10] Set(“DAHDI/7-1”, “TIMEOUT(digit)=3”) in new stack
– Digit timeout set to 3.000
[2017-06-12 23:31:28] DEBUG[2471][C-000003c9]: pbx.c:4905 pbx_substitute_variables_helper_full: Expression result is ‘1’
[2017-06-12 23:31:28] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘ExecIf’
– Executing [s@ivr-4:11] ExecIf(“DAHDI/7-1”, “1?Background(custom/Main_Welcome2)”) in new stack
[2017-06-12 23:31:28] DEBUG[2471][C-000003c9]: channel.c:5416 set_format: Set channel DAHDI/7-1 to write format slin
[2017-06-12 23:31:28] DEBUG[2471][C-000003c9]: channel.c:3597 ast_settimeout_full: Scheduling timer at (50 requested / 50 actual) timer ticks per second
– <DAHDI/7-1> Playing ‘custom/Main_Welcome2.slin’ (language ‘en’)
[2017-06-12 23:31:33] DEBUG[2402]: chan_sip.c:8679 sip_alloc: Allocating new SIP dialog for 5f104e661bf3d5eb3397a4766159bcfa@[::1]:5060 - OPTIONS (No RTP)
[2017-06-12 23:31:33] DEBUG[2402]: chan_sip.c:8465 change_callid_pvt: SIP call-id changed from ‘5f104e661bf3d5eb3397a4766159bcfa@[::1]:5060’ to ‘[email protected]:5060’
[2017-06-12 23:31:33] DEBUG[2402]: chan_sip.c:3374 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2017-06-12 23:31:33] DEBUG[2402]: chan_sip.c:4429 __sip_ack: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: dsp.c:1525 ast_dsp_process: Requesting Hangup because the busy tone was detected on channel DAHDI/7-1
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: channel.c:3597 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: channel.c:3597 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: channel.c:5416 set_format: Set channel DAHDI/7-1 to write format ulaw
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: pbx.c:6789 __ast_pbx_run: Spawn extension (ivr-4,s,11) exited non-zero on ‘DAHDI/7-1’
== Spawn extension (ivr-4, s, 11) exited non-zero on ‘DAHDI/7-1’
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: channel.c:2664 ast_softhangup_nolock: Soft-Hanging up channel ‘DAHDI/7-1’
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: channel.c:2664 ast_softhangup_nolock: Soft-Hanging up channel ‘DAHDI/7-1’
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: pbx.c:5005 pbx_extension_helper: Launching ‘Hangup’
– Executing [h@ivr-4:1] Hangup(“DAHDI/7-1”, “”) in new stack
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: channel.c:2664 ast_softhangup_nolock: Soft-Hanging up channel ‘DAHDI/7-1’
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: pbx.c:6305 ast_pbx_h_exten_run: Spawn extension (ivr-4,h,1) exited non-zero on ‘DAHDI/7-1’
== Spawn extension (ivr-4, h, 1) exited non-zero on ‘DAHDI/7-1’
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: channel.c:2843 ast_hangup: Hanging up channel ‘DAHDI/7-1’
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: chan_dahdi.c:6659 dahdi_hangup: dahdi_hangup(DAHDI/7-1)
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: sig_analog.c:1280 analog_hangup: analog_hangup 7
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: sig_analog.c:1303 analog_hangup: Hangup: channel: 7 index = 0, normal = 1, callwait = 0, thirdcall = 0
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: chan_dahdi.c:5414 dahdi_disable_ec: Disabled echo cancellation on channel 7
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: chan_dahdi.c:7299 dahdi_setoption: Set option TONE VERIFY, mode: OFF(0) on DAHDI/7-1
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: chan_dahdi.c:7309 dahdi_setoption: Set option TDD MODE, value: OFF(0) on DAHDI/7-1
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: sig_analog.c:785 analog_update_conf: Updated conferencing on 7, with 0 conference users
– Hanging up on ‘DAHDI/7-1’
– Hungup ‘DAHDI/7-1’
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: cdr_mysql.c:343 mysql_log: Inserting a CDR record.
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: cdr_mysql.c:346 mysql_log: SQL command as follows: INSERT INTO cdr (calldate
,dst
,dcontext
,channel
,lastapp
,lastdata
,duration
,billsec
,disposition
,amaflags
,uniqueid
,did
) VALUES (‘2017-06-12 23:31:17’,‘s’,‘ivr-4’,‘DAHDI/7-1’,‘BackGround’,‘custom/Main_Welcome2’,‘20’,‘10’,‘ANSWERED’,‘3’,‘1497292277.1768’,‘s’)
[2017-06-12 23:31:37] DEBUG[2471][C-000003c9]: cdr_sqlite3_custom.c:261 write_cdr: About to log: INSERT INTO cdr (calldate,clid,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield,test,src,dst) VALUES (‘2017-06-12 23:31:17’,’’,‘ivr-4’,‘DAHDI/7-1’,’’,‘BackGround’,‘custom/Main_Welcome2’,‘20’,‘10’,‘ANSWERED’,‘DOCUMENTATION’,’’,‘1497292277.1768’,’’,’’,’’,‘s’)
Awaiting reply
Regards