asterisk*CLI> set verbose 10
Verbosity was 0 and is now 10
    -- Starting simple switch on 'Zap/4-1'
    -- Executing Answer("Zap/4-1", "") in new stack
Apr 20 00:23:20 DEBUG[15317]: chan_zap.c:2682 zt_answer: Took Zap/4-1 off hook
Apr 20 00:23:20 DEBUG[15317]: chan_zap.c:1414 zt_enable_ec: No echo cancellation requested
Apr 20 00:23:20 DEBUG[15317]: chan_zap.c:1430 zt_train_ec: No echo training requested
    -- Executing BackGround("Zap/4-1", "hawaii") in new stack
Apr 20 00:23:20 DEBUG[15317]: channel.c:1761 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'hawaii' (language 'en')
Apr 20 00:23:20 DEBUG[15317]: channel.c:1761 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 20 00:23:20 DEBUG[15317]: channel.c:1761 ast_settimeout: Scheduling timer at 0 sample intervals
    -- Executing Set("Zap/4-1", "TIMEOUT(response)=5") in new stack
    -- Response timeout set to 5
    -- Executing Set("Zap/4-1", "TIMEOUT(digit)=5") in new stack
    -- Digit timeout set to 5
Apr 20 00:23:23 DEBUG[15317]: chan_zap.c:4636 zt_read: DTMF digit: f on Zap/4-1
    -- Redirecting Zap/4-1 to fax extension
Apr 20 00:23:26 DEBUG[15317]: chan_zap.c:4636 zt_read: DTMF digit: f on Zap/4-1
Apr 20 00:23:26 DEBUG[15317]: chan_zap.c:4677 zt_read: Fax already handled
    -- Timeout on Zap/4-1
  == CDR updated on Zap/4-1
    -- Executing Dial("Zap/4-1", "Zap/7|30|t") in new stack
    -- Called 7
    -- Zap/7-1 is ringing
Apr 20 00:23:28 DEBUG[15317]: chan_zap.c:4825 zt_indicate: Requested indication 3 on channel Zap/4-1
Apr 20 00:23:29 DEBUG[15317]: chan_zap.c:4636 zt_read: DTMF digit: f on Zap/4-1
Apr 20 00:23:29 DEBUG[15317]: chan_zap.c:4677 zt_read: Fax already handled
Apr 20 00:23:30 DEBUG[15317]: chan_zap.c:4359 __zt_exception: Exception on 31, channel 7
Apr 20 00:23:30 DEBUG[15317]: chan_zap.c:3547 zt_handle_event: Got event Ringer Off(11) on channel 7 (index 0)
    -- Zap/7-1 is ringing
Apr 20 00:23:31 DEBUG[15317]: chan_zap.c:4359 __zt_exception: Exception on 32, channel 4
Apr 20 00:23:31 DEBUG[15317]: chan_zap.c:3547 zt_handle_event: Got event On hook(1) on channel 4 (index 0)
Apr 20 00:23:31 DEBUG[15317]: chan_zap.c:2350 zt_hangup: Hangup: channel: 7 index = 0, normal = 31, callwait = -1, thirdcall = -1
Apr 20 00:23:31 DEBUG[15317]: chan_zap.c:2790 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/7-1
Apr 20 00:23:31 DEBUG[15317]: chan_zap.c:1380 update_conf: Updated conferencing on 7, with 0 conference users
    -- Hungup 'Zap/7-1'
Apr 20 00:23:31 DEBUG[15317]: app_dial.c:1635 dial_exec_full: Exiting with DIALSTATUS=CANCEL.
  == Spawn extension (incoming, t, 1) exited non-zero on 'Zap/4-1'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '"xxxxxxxxxxx" <xxxxxxxxxx>'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'xxxxxxxxxx'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 't'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'incoming'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Zap/4-1'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Zap/7-1'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Dial'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Zap/7|30|t'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2007-04-20 00:23:20'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2007-04-20 00:23:20'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2007-04-20 00:23:31'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '11'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '11'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'ANSWERED'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1177042999.0'
Apr 20 00:23:31 DEBUG[15317]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)'
Apr 20 00:23:31 DEBUG[15317]: chan_zap.c:2350 zt_hangup: Hangup: channel: 4 index = 0, normal = 32, callwait = -1, thirdcall = -1
Apr 20 00:23:31 DEBUG[15317]: chan_zap.c:2790 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/4-1
Apr 20 00:23:31 DEBUG[15317]: chan_zap.c:1380 update_conf: Updated conferencing on 4, with 0 conference users
    -- Hungup 'Zap/4-1'