[2011-02-07 14:02:00] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.150 with 192.168.0.0
[2011-02-07 14:02:00] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.150 with 10.0.0.0
[2011-02-07 14:02:00] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.150 with 172.16.0.0
[2011-02-07 14:02:00] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.150 with 169.254.0.0
[2011-02-07 14:02:00] DEBUG[5462]: chan_sip.c:4800 sip_alloc: Allocating new SIP dialog for f3bd6725-ca067ba6-b0642a87@192.168.30.150 - SUBSCRIBE (No RTP)
[2011-02-07 14:02:00] DEBUG[5462]: chan_sip.c:8909 build_route: build_route: Contact hop: <sip:6003@192.168.30.150:5060>
[2011-02-07 14:02:00] DEBUG[5462]: chan_sip.c:8847 build_route: build_route: Retaining previous route: <sip:6003@192.168.30.150:5060>
[2011-02-07 14:02:00] DEBUG[5462]: chan_sip.c:16299 handle_request_subscribe: Received SIP subscribe for unknown event package: missed-call-summary
[2011-02-07 14:02:00]     -- Accepting call from '1800555123' to '6900' on channel 0/23, span 1
[2011-02-07 14:02:00] DEBUG[5485]: chan_dahdi.c:1786 dahdi_enable_ec: Enabled echo cancellation on channel 23
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:1] Set("Zap/23-1", "__INCOMING_DNIS=6900") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:2] Set("Zap/23-1", "LINE_TENANT=default") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:3] Set("Zap/23-1", "LINE_LANGUAGE=en") in new stack
[2011-02-07 14:02:00] DEBUG[5524]: manager.c:2263 process_message: Manager received command 'GetVar'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:4] Set("Zap/23-1", "LINE_CLID_NUM=0000000000") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:5] Set("Zap/23-1", "LINE_CLID_NAME=") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is '1800555123'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:6] Set("Zap/23-1", "LINE_CLID_NUM_DEF=91800555123") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:7] Set("Zap/23-1", "LINE_MOH=default") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Gosub'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:8] Gosub("Zap/23-1", "all-incoming-check|s|1") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is '1800555123'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is 'BCM50bob'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'NoOp'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:1] NoOp("Zap/23-1", ""INCOMING CALL FROM CALLER ID: 1800555123 (BCM50bob)"") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '7'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:2] GotoIf("Zap/23-1", "1?7") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,7)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '10'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:7] GotoIf("Zap/23-1", "1?10") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,10)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '12'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:10] GotoIf("Zap/23-1", "1?12") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,12)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '14'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:12] GotoIf("Zap/23-1", "1?14") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,14)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '16'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:14] GotoIf("Zap/23-1", "1?16") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,16)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '0'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '18'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:16] GotoIf("Zap/23-1", "0?18") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:6104 pbx_builtin_gotoif: Not taking any branch
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:17] Set("Zap/23-1", "CHANNEL(musicclass)=default") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:18] Set("Zap/23-1", "CALLERID(dnid)=6900") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:19] Set("Zap/23-1", "CDR(userfield)=6900") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:20] Set("Zap/23-1", "__EXTCONTEXT=default-default") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:21] Set("Zap/23-1", "__INCOMINGLINE=1") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is '1297105320.2'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:22] Set("Zap/23-1", "__ORGCALLID=1297105320.2") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '25'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:23] GotoIf("Zap/23-1", "1?25") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,25)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '27'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:25] GotoIf("Zap/23-1", "1?27") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,27)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '29'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:27] GotoIf("Zap/23-1", "1?29") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,29)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '31'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:29] GotoIf("Zap/23-1", "1?31") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,31)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'AGI'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:31] AGI("Zap/23-1", "agi://127.0.0.1:4573/fixcidname") in new stack
[2011-02-07 14:02:00]     -- AGI Script agi://127.0.0.1:4573/fixcidname completed, returning 0
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '34'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:32] GotoIf("Zap/23-1", "1?34") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,34)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '0'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '36'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:34] GotoIf("Zap/23-1", "0?36") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:6104 pbx_builtin_gotoif: Not taking any branch
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:35] Set("Zap/23-1", "CHANNEL(language)=en") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:36] Set("Zap/23-1", "FAXNUMBER=6900") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '39'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:37] GotoIf("Zap/23-1", "1?39") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,39)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '41'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:39] GotoIf("Zap/23-1", "1?41") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,41)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '44'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:41] GotoIf("Zap/23-1", "1?44") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,44)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '0'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '49'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:44] GotoIf("Zap/23-1", "0?49") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:6104 pbx_builtin_gotoif: Not taking any branch
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is '1800555123'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '47'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:45] GotoIf("Zap/23-1", "1?47") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,47)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is '1800555123'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '49'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:47] GotoIf("Zap/23-1", "1?49") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,49)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '54'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:49] GotoIf("Zap/23-1", "1?54") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,54)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '0'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '56'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:54] GotoIf("Zap/23-1", "0?56") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:6104 pbx_builtin_gotoif: Not taking any branch
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:55] Set("Zap/23-1", "CALLERID(number)=91800555123") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '58'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:56] GotoIf("Zap/23-1", "1?58") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,58)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '60'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:58] GotoIf("Zap/23-1", "1?60") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,60)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '62'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:60] GotoIf("Zap/23-1", "1?62") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,62)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:62] Set("Zap/23-1", "CALLFILENAME=1297105320.2") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '65'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:63] GotoIf("Zap/23-1", "1?65") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,65)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '1'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '67'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:65] GotoIf("Zap/23-1", "1?67") in new stack
[2011-02-07 14:02:00]     -- Goto (all-incoming-check,s,67)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Return'
[2011-02-07 14:02:00]     -- Executing [s@all-incoming-check:67] Return("Zap/23-1", "") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Answer'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:9] Answer("Zap/23-1", "") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel Zap/23
[2011-02-07 14:02:00] DEBUG[5448]: channel.c:1139 channel_find_locked: Avoiding initial deadlock for channel '0x9b18b20'
[2011-02-07 14:02:00] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication -1 on channel Zap/23-1
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Goto'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:10] Goto("Zap/23-1", "20") in new stack
[2011-02-07 14:02:00]     -- Goto (zap-incoming,6900,20)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is '91800555123'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '0'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '23'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:20] GotoIf("Zap/23-1", "0?23") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:6104 pbx_builtin_gotoif: Not taking any branch
[2011-02-07 14:02:00] DEBUG[5448]: devicestate.c:287 do_state_change: Changing state for Zap/23 - state 2 (In use)
[2011-02-07 14:02:00] DEBUG[5490]: app_queue.c:711 handle_statechange: Device 'Zap/23' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is '91800555123'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is 'cidname/91800555123'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is ''
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '0'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '22'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '23'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:21] GotoIf("Zap/23-1", "0?22:23") in new stack
[2011-02-07 14:02:00]     -- Goto (zap-incoming,6900,23)
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is '91800555123'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '0'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '25'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:23] GotoIf("Zap/23-1", "0?25") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:6104 pbx_builtin_gotoif: Not taking any branch
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is '91800555123'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is 'blacklist/91800555123'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is ''
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1775 pbx_substitute_variables_helper_full: Expression result is '0'
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'GotoIf'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:24] GotoIf("Zap/23-1", "0?all-blacklisted|s|1") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:6104 pbx_builtin_gotoif: Not taking any branch
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Gosub'
[2011-02-07 14:02:00]     -- Executing [6900@zap-incoming:25] Gosub("Zap/23-1", "default-aa-servicemainmenubutton1englishsubmenu|s|1") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Answer'
[2011-02-07 14:02:00]     -- Executing [s@default-aa-servicemainmenubutton1englishsubmenu:1] Answer("Zap/23-1", "") in new stack
[2011-02-07 14:02:00] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication -1 on channel Zap/23-1
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'AGI'
[2011-02-07 14:02:00]     -- Executing [s@default-aa-servicemainmenubutton1englishsubmenu:2] AGI("Zap/23-1", "agi://127.0.0.1:4573/ivr?arg1=4894") in new stack
[2011-02-07 14:02:00]     -- AGI Script agi://127.0.0.1:4573/ivr?arg1=4894 completed, returning 0
[2011-02-07 14:02:00] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Wait'
[2011-02-07 14:02:00]     -- Executing [s@default-aa-servicemainmenubutton1englishsubmenu:3] Wait("Zap/23-1", "1") in new stack
[2011-02-07 14:02:01] DEBUG[5462]: chan_sip.c:2177 __sip_autodestruct: Auto destroying SIP dialog 'e27a35a6-5fa88de2-aadf54@66.252.148.166'
[2011-02-07 14:02:01] DEBUG[5462]: chan_sip.c:3499 sip_destroy: Destroying SIP dialog e27a35a6-5fa88de2-aadf54@66.252.148.166
[2011-02-07 14:02:01] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:01]     -- Executing [s@default-aa-servicemainmenubutton1englishsubmenu:4] Set("Zap/23-1", "MAXCOUNT_TIMEOUT=3") in new stack
[2011-02-07 14:02:01] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:01]     -- Executing [s@default-aa-servicemainmenubutton1englishsubmenu:5] Set("Zap/23-1", "COUNT_TIMEOUT=0") in new stack
[2011-02-07 14:02:01] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:01]     -- Executing [s@default-aa-servicemainmenubutton1englishsubmenu:6] Set("Zap/23-1", "MAXCOUNT_INVALID=3") in new stack
[2011-02-07 14:02:01] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:01]     -- Executing [s@default-aa-servicemainmenubutton1englishsubmenu:7] Set("Zap/23-1", "COUNT_INVALID=0") in new stack
[2011-02-07 14:02:01] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:01]     -- Executing [s@default-aa-servicemainmenubutton1englishsubmenu:8] Set("Zap/23-1", "__IVRNAME=default-aa-servicemainmenubutton1englishsubmenu") in new stack
[2011-02-07 14:02:01] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
2011-02-07 14:02:01]     -- Executing [s@default-aa-servicemainmenubutton1englishsubmenu:9] Set("Zap/23-1", "TIMEOUT(digit)=3") in new stack
[2011-02-07 14:02:01]     -- Digit timeout set to 3
[2011-02-07 14:02:01] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:01]     -- Executing [s@default-aa-servicemainmenubutton1englishsubmenu:10] Set("Zap/23-1", "TIMEOUT(response)=5") in new stack
[2011-02-07 14:02:01]     -- Response timeout set to 5
[2011-02-07 14:02:01] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:01]     -- Executing [s@default-aa-servicemainmenubutton1englishsubmenu:11] Set("Zap/23-1", "CHANNEL(language)=en") in new stack
[2011-02-07 14:02:01] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'BackGround'
[2011-02-07 14:02:01]     -- Executing [s@default-aa-servicemainmenubutton1englishsubmenu:12] BackGround("Zap/23-1", "custom/0003") in new stack
[2011-02-07 14:02:01] DEBUG[6030]: channel.c:3369 set_format: Set channel Zap/23-1 to write format slin
[2011-02-07 14:02:01] DEBUG[6030]: channel.c:1980 ast_settimeout: Scheduling timer at 160 sample intervals
[2011-02-07 14:02:01]     -- <Zap/23-1> Playing 'custom/0003' (language 'en')
[2011-02-07 14:02:03] 
[2011-02-07 14:02:03] DEBUG[5488]: 
[2011-02-07 14:02:03] DEBUG[6030]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:03] DEBUG[6030]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131114(131114) on channel 23 (index 0)
[2011-02-07 14:02:03] DEBUG[6030]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '*'
[2011-02-07 14:02:03] DTMF[6030]: channel.c:2464 __ast_read: DTMF begin '*' received on Zap/23-1
[2011-02-07 14:02:03] DTMF[6030]: channel.c:2468 __ast_read: DTMF begin ignored '*' on Zap/23-1
[2011-02-07 14:02:03] DEBUG[6030]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:03] DEBUG[6030]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262186(262186) on channel 23 (index 0)
[2011-02-07 14:02:03] DEBUG[6030]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '*'
[2011-02-07 14:02:03] DEBUG[6030]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: * on Zap/23-1
[2011-02-07 14:02:03] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '*' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:03] DTMF[6030]: channel.c:2448 __ast_read: DTMF end passthrough '*' on Zap/23-1
[2011-02-07 14:02:03] DEBUG[6030]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-02-07 14:02:03] DEBUG[6030]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-02-07 14:02:03] DEBUG[6030]: channel.c:3369 set_format: Set channel Zap/23-1 to write format ulaw
[2011-02-07 14:02:03] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'AGI'
[2011-02-07 14:02:03]     -- Executing [*@default-aa-servicemainmenubutton1englishsubmenu:1] AGI("Zap/23-1", "agi://127.0.0.1:4573/ivr?arg1=4894&arg2=star") in new stack
[2011-02-07 14:02:03] DEBUG[6156]: manager.c:2263 process_message: Manager received command 'login'
[2011-02-07 14:02:03]   == Parsing '/etc/asterisk/manager.conf': [2011-02-07 14:02:03] DEBUG[6156]: config.c:895 config_text_file_load: Parsing /etc/asterisk/manager.conf
[2011-02-07 14:02:03] Found
[2011-02-07 14:02:03] DEBUG[6156]: acl.c:355 ast_append_ha: 127.0.0.1/255.255.255.255 appended to acl for peer
[2011-02-07 14:02:03] DEBUG[6156]: acl.c:370 ast_apply_ha: ##### Testing 127.0.0.1 with 127.0.0.1
[2011-02-07 14:02:03] DEBUG[6156]: manager.c:2263 process_message: Manager received command 'Command'
[2011-02-07 14:02:04]     -- AGI Script agi://127.0.0.1:4573/ivr?arg1=4894&arg2=star completed, returning 0
[2011-02-07 14:02:04] DEBUG[6030]: pbx.c:1859 pbx_extension_helper: Launching 'Dial'
[2011-02-07 14:02:04]     -- Executing [*@default-aa-servicemainmenubutton1englishsubmenu:2] Dial("Zap/23-1", "Local/*844@default-application") in new stack
[2011-02-07 14:02:04] DEBUG[6030]: rtp.c:1696 ast_rtp_make_compatible: Channel 'Local/*844@default-application-9720,1' has no RTP, not doing anything
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable DIALEDTIME.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable ANSWEREDTIME.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable DIALEDPEERNAME.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable DIALSTATUS.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable AGISTATUS.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3977 ast_channel_inherit_variables: Copying hard-transferable variable IVRNAME.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable COUNT_INVALID.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable MAXCOUNT_INVALID.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable COUNT_TIMEOUT.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable MAXCOUNT_TIMEOUT.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable ~GOSUB~STACK~.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable CALLFILENAME.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable FAXNUMBER.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3977 ast_channel_inherit_variables: Copying hard-transferable variable ORGCALLID.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3977 ast_channel_inherit_variables: Copying hard-transferable variable INCOMINGLINE.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3977 ast_channel_inherit_variables: Copying hard-transferable variable EXTCONTEXT.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable LINE_MOH.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable LINE_CLID_NUM_DEF.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable LINE_CLID_NAME.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable LINE_CLID_NUM.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable LINE_LANGUAGE.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable LINE_TENANT.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3977 ast_channel_inherit_variables: Copying hard-transferable variable INCOMING_DNIS.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable CALLEDTON.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable PRIREDIRECTREASON.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable ANI2.
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:3982 ast_channel_inherit_variables: Not copying variable TRANSFERCAPABILITY.
[2011-02-07 14:02:04]     -- Called *844@default-application
[2011-02-07 14:02:04] DEBUG[6167]: pbx.c:1707 pbx_substitute_variables_helper_full: Function result is '91800555123'
[2011-02-07 14:02:04] DEBUG[6167]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:04]     -- Executing [*844@default-application:1] Set("Local/*844@default-application-9720,2", "GROUP(OUTGOING)=91800555123") in new stack
[2011-02-07 14:02:04] DEBUG[6167]: pbx.c:1859 pbx_extension_helper: Launching 'Answer'
[2011-02-07 14:02:04]     -- Executing [*844@default-application:2] Answer("Local/*844@default-application-9720,2", "") in new stack
[2011-02-07 14:02:04] DEBUG[6167]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/*844@default-application
[2011-02-07 14:02:04] DEBUG[6030]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/*844@default-application
[2011-02-07 14:02:04]     -- Local/*844@default-application-9720,1 answered Zap/23-1
[2011-02-07 14:02:04] DEBUG[6030]: rtp.c:1614 ast_rtp_early_bridge: Channel 'Zap/23-1' has no RTP, not doing anything
[2011-02-07 14:02:04] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication -1 on channel Zap/23-1
[2011-02-07 14:02:04] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:4546 ast_generic_bridge: Got a FRAME_CONTROL (-1) frame on channel Local/*844@default-application-9720,1
[2011-02-07 14:02:04] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:04] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:04] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication -1 on channel Zap/23-1
[2011-02-07 14:02:04] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:04] DEBUG[6167]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:04]     -- Executing [*844@default-application:3] Set("Local/*844@default-application-9720,2", "TIMEOUT(digit)=5") in new stack
[2011-02-07 14:02:04]     -- Digit timeout set to 5
[2011-02-07 14:02:04] DEBUG[6167]: pbx.c:1859 pbx_extension_helper: Launching 'Set'
[2011-02-07 14:02:04]     -- Executing [*844@default-application:4] Set("Local/*844@default-application-9720,2", "TIMEOUT(response)=10") in new stack
[2011-02-07 14:02:04]     -- Response timeout set to 10
[2011-02-07 14:02:04] DEBUG[6167]: pbx.c:1859 pbx_extension_helper: Launching 'VoiceMailMain'
[2011-02-07 14:02:04]     -- Executing [*844@default-application:5] VoiceMailMain("Local/*844@default-application-9720,2", "@default") in new stack
[2011-02-07 14:02:04] DEBUG[6167]: res_adsi.c:378 ast_adsi_transmit_message_full: Switch to data is sent!
[2011-02-07 14:02:04] DEBUG[5524]: manager.c:2263 process_message: Manager received command 'GetVar'
[2011-02-07 14:02:04] DEBUG[5448]: chan_local.c:146 local_devicestate: Checking if extension *844@default-application exists (devicestate)
[2011-02-07 14:02:04] DEBUG[5524]: manager.c:2263 process_message: Manager received command 'GetVar'
[2011-02-07 14:02:04] DEBUG[5524]: manager.c:2263 process_message: Manager received command 'GetVar'
[2011-02-07 14:02:04] DEBUG[5524]: manager.c:2263 process_message: Manager received command 'GetVar'
[2011-02-07 14:02:04] DEBUG[5448]: devicestate.c:287 do_state_change: Changing state for Local/*844@default-application - state 2 (In use)
[2011-02-07 14:02:04] DEBUG[5448]: chan_local.c:146 local_devicestate: Checking if extension *844@default-application exists (devicestate)
[2011-02-07 14:02:04] DEBUG[5448]: devicestate.c:287 do_state_change: Changing state for Local/*844@default-application - state 2 (In use)
[2011-02-07 14:02:04] DEBUG[5490]: app_queue.c:711 handle_statechange: Device 'Local/*844@default-application' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[2011-02-07 14:02:04] DEBUG[5490]: app_queue.c:711 handle_statechange: Device 'Local/*844@default-application' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[2011-02-07 14:02:04] DEBUG[6167]: res_adsi.c:235 __adsi_transmit_messages: No ADSI CPE detected (0)
[2011-02-07 14:02:04] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 160 sample intervals
[2011-02-07 14:02:04]     -- <Local/*844@default-application-9720,2> Playing 'vm-login' (language 'en')
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131126(131126) on channel 23 (index 0)
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '6'
[2011-02-07 14:02:05] DTMF[6030]: channel.c:2464 __ast_read: DTMF begin '6' received on Zap/23-1
[2011-02-07 14:02:05] DTMF[6030]: channel.c:2474 __ast_read: DTMF begin passthrough '6' on Zap/23-1
[2011-02-07 14:02:05] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:05] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262198(262198) on channel 23 (index 0)
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '6'
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: 6 on Zap/23-1
[2011-02-07 14:02:05] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '6' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:05] DTMF[6030]: channel.c:2419 __ast_read: DTMF end accepted with begin '6' on Zap/23-1
[2011-02-07 14:02:05] DTMF[6030]: channel.c:2448 __ast_read: DTMF end passthrough '6' on Zap/23-1
[2011-02-07 14:02:05] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:05] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:05] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=6, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:05] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '6' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:05] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '6' on Local/*844@default-application-9720,2
[2011-02-07 14:02:05] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '6' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:05] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '6' on Local/*844@default-application-9720,2
[2011-02-07 14:02:05] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-02-07 14:02:05] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-02-07 14:02:05] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:05] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131120(131120) on channel 23 (index 0)
[2011-02-07 14:02:05] DEBUG[5928]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '0'
[2011-02-07 14:02:05] DTMF[5928]: channel.c:2464 __ast_read: DTMF begin '0' received on Zap/23-1
[2011-02-07 14:02:05] DTMF[5928]: channel.c:2468 __ast_read: DTMF begin ignored '0' on Zap/23-1
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262192(262192) on channel 23 (index 0)
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '0'
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: 0 on Zap/23-1
[2011-02-07 14:02:05] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:05] DTMF[6030]: channel.c:2408 __ast_read: DTMF begin emulation of '0' with duration 80 queued on Zap/23-1
[2011-02-07 14:02:05] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:05] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:05] DTMF[6030]: channel.c:2541 __ast_read: DTMF end emulation of '0' queued on Zap/23-1
[2011-02-07 14:02:05] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:05] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:05] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:05] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=0, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:05] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:05] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131121(131121) on channel 23 (index 0)
[2011-02-07 14:02:05] DEBUG[5928]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '1'
[2011-02-07 14:02:05] DTMF[5928]: channel.c:2464 __ast_read: DTMF begin '1' received on Zap/23-1
[2011-02-07 14:02:05] DTMF[5928]: channel.c:2468 __ast_read: DTMF begin ignored '1' on Zap/23-1
[2011-02-07 14:02:05] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '0' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:05] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '0' on Local/*844@default-application-9720,2
[2011-02-07 14:02:05] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '0' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:05] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Local/*844@default-application-9720,2
[2011-02-07 14:02:05] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:05] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262193(262193) on channel 23 (index 0)
[2011-02-07 14:02:05] DEBUG[5928]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '1'
[2011-02-07 14:02:05] DEBUG[5928]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: 1 on Zap/23-1
[2011-02-07 14:02:05] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '1' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:05] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '1' on Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:06] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '1' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:06] DTMF[6030]: channel.c:2408 __ast_read: DTMF begin emulation of '1' with duration 80 queued on Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:06] DTMF[6030]: channel.c:2541 __ast_read: DTMF end emulation of '1' queued on Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:06] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=1, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:06] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:06] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131120(131120) on channel 23 (index 0)
[2011-02-07 14:02:06] DEBUG[5928]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '0'
[2011-02-07 14:02:06] DTMF[5928]: channel.c:2464 __ast_read: DTMF begin '0' received on Zap/23-1
[2011-02-07 14:02:06] DTMF[5928]: channel.c:2468 __ast_read: DTMF begin ignored '0' on Zap/23-1
[2011-02-07 14:02:06] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '1' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:06] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '1' on Local/*844@default-application-9720,2
[2011-02-07 14:02:06] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:06] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262192(262192) on channel 23 (index 0)
[2011-02-07 14:02:06] DEBUG[5928]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '0'
[2011-02-07 14:02:06] DEBUG[5928]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: 0 on Zap/23-1
[2011-02-07 14:02:06] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:06] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Zap/23-1
[2011-02-07 14:02:06] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '1' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:06] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '1' on Local/*844@default-application-9720,2
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:06] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:06] DTMF[6030]: channel.c:2408 __ast_read: DTMF begin emulation of '0' with duration 80 queued on Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131107(131107) on channel 23 (index 0)
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '#'
[2011-02-07 14:02:06] DTMF[6030]: channel.c:2464 __ast_read: DTMF begin '#' received on Zap/23-1
[2011-02-07 14:02:06] DTMF[6030]: channel.c:2468 __ast_read: DTMF begin ignored '#' on Zap/23-1
[2011-02-07 14:02:06] DTMF[6030]: channel.c:2541 __ast_read: DTMF end emulation of '0' queued on Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:06] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=0, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:06] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:06] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262179(262179) on channel 23 (index 0)
[2011-02-07 14:02:06] DEBUG[5928]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '#'
[2011-02-07 14:02:06] DEBUG[5928]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: # on Zap/23-1
[2011-02-07 14:02:06] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '#' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:06] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '#' on Zap/23-1
[2011-02-07 14:02:06] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '0' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:06] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '0' on Local/*844@default-application-9720,2
[2011-02-07 14:02:06] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '0' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:06] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Local/*844@default-application-9720,2
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:06] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '#' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:06] DTMF[6030]: channel.c:2408 __ast_read: DTMF begin emulation of '#' with duration 80 queued on Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:06] DTMF[6030]: channel.c:2541 __ast_read: DTMF end emulation of '#' queued on Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:06] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:06] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:06] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=#, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:07] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '#' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:07] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '#' on Local/*844@default-application-9720,2
[2011-02-07 14:02:07] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '#' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:07] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '#' on Local/*844@default-application-9720,2
[2011-02-07 14:02:07] DEBUG[6167]: app_voicemail.c:7517 vm_authenticate: Before find user for mailbox 6010
[2011-02-07 14:02:07] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 160 sample intervals
[2011-02-07 14:02:07]     -- <Local/*844@default-application-9720,2> Playing 'vm-password' (language 'en')
[2011-02-07 14:02:07] 
[2011-02-07 14:02:07] DEBUG[5488]: 
[2011-02-07 14:02:07] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:07] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.150 with 192.168.0.0
[2011-02-07 14:02:07] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.150 with 10.0.0.0
[2011-02-07 14:02:07] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.150 with 172.16.0.0
[2011-02-07 14:02:07] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.150 with 169.254.0.0
[2011-02-07 14:02:07] DEBUG[5462]: chan_sip.c:4800 sip_alloc: Allocating new SIP dialog for bb182750-45b599f1-edf432f2@192.168.30.150 - SUBSCRIBE (No RTP)
[2011-02-07 14:02:07] DEBUG[5462]: chan_sip.c:8909 build_route: build_route: Contact hop: <sip:6003@192.168.30.150:5060>
[2011-02-07 14:02:07] DEBUG[5462]: chan_sip.c:8847 build_route: build_route: Retaining previous route: <sip:6003@192.168.30.150:5060>
[2011-02-07 14:02:07] DEBUG[5462]: chan_sip.c:16299 handle_request_subscribe: Received SIP subscribe for unknown event package: missed-call-summary
[2011-02-07 14:02:07] DEBUG[6030]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:07] DEBUG[6030]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131126(131126) on channel 23 (index 0)
[2011-02-07 14:02:07] DEBUG[6030]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '6'
[2011-02-07 14:02:07] DTMF[6030]: channel.c:2464 __ast_read: DTMF begin '6' received on Zap/23-1
[2011-02-07 14:02:07] DTMF[6030]: channel.c:2474 __ast_read: DTMF begin passthrough '6' on Zap/23-1
[2011-02-07 14:02:07] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:07] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:07] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:07] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:07] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 80 sample intervals
[2011-02-07 14:02:07] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-02-07 14:02:07] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-02-07 14:02:07] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-02-07 14:02:07] DEBUG[6030]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:07] DEBUG[6030]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262198(262198) on channel 23 (index 0)
[2011-02-07 14:02:07] DEBUG[6030]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '6'
[2011-02-07 14:02:07] DEBUG[6030]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: 6 on Zap/23-1
[2011-02-07 14:02:07] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '6' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:07] DTMF[6030]: channel.c:2419 __ast_read: DTMF end accepted with begin '6' on Zap/23-1
[2011-02-07 14:02:07] DTMF[6030]: channel.c:2448 __ast_read: DTMF end passthrough '6' on Zap/23-1
[2011-02-07 14:02:07] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:07] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:07] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:07] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=6, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:08] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '6' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:08] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '6' on Local/*844@default-application-9720,2
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131120(131120) on channel 23 (index 0)
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '0'
[2011-02-07 14:02:08] DTMF[5928]: channel.c:2464 __ast_read: DTMF begin '0' received on Zap/23-1
[2011-02-07 14:02:08] DTMF[5928]: channel.c:2468 __ast_read: DTMF begin ignored '0' on Zap/23-1
[2011-02-07 14:02:08] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '6' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:08] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '6' on Local/*844@default-application-9720,2
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262192(262192) on channel 23 (index 0)
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '0'
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: 0 on Zap/23-1
[2011-02-07 14:02:08] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:08] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Zap/23-1
[2011-02-07 14:02:08] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:08] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:08] DTMF[6030]: channel.c:2408 __ast_read: DTMF begin emulation of '0' with duration 80 queued on Zap/23-1
[2011-02-07 14:02:08] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:08] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:08] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:08] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:08] DTMF[6030]: channel.c:2541 __ast_read: DTMF end emulation of '0' queued on Zap/23-1
[2011-02-07 14:02:08] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:08] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:08] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:08] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=0, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131121(131121) on channel 23 (index 0)
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '1'
[2011-02-07 14:02:08] DTMF[5928]: channel.c:2464 __ast_read: DTMF begin '1' received on Zap/23-1
[2011-02-07 14:02:08] DTMF[5928]: channel.c:2468 __ast_read: DTMF begin ignored '1' on Zap/23-1
[2011-02-07 14:02:08] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '0' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:08] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '0' on Local/*844@default-application-9720,2
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262193(262193) on channel 23 (index 0)
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '1'
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: 1 on Zap/23-1
[2011-02-07 14:02:08] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '1' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:08] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '1' on Zap/23-1
[2011-02-07 14:02:08] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '0' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:08] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Local/*844@default-application-9720,2
[2011-02-07 14:02:08] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:08] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '1' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:08] DTMF[6030]: channel.c:2408 __ast_read: DTMF begin emulation of '1' with duration 80 queued on Zap/23-1
[2011-02-07 14:02:08] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:08] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:08] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:08] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:08] DEBUG[6030]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:08] DEBUG[6030]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131120(131120) on channel 23 (index 0)
[2011-02-07 14:02:08] DEBUG[6030]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '0'
[2011-02-07 14:02:08] DTMF[6030]: channel.c:2464 __ast_read: DTMF begin '0' received on Zap/23-1
[2011-02-07 14:02:08] DTMF[6030]: channel.c:2468 __ast_read: DTMF begin ignored '0' on Zap/23-1
[2011-02-07 14:02:08] DTMF[6030]: channel.c:2541 __ast_read: DTMF end emulation of '1' queued on Zap/23-1
[2011-02-07 14:02:08] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:08] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:08] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:08] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=1, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262192(262192) on channel 23 (index 0)
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '0'
[2011-02-07 14:02:08] DEBUG[5928]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: 0 on Zap/23-1
[2011-02-07 14:02:08] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:08] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:08] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Zap/23-1
[2011-02-07 14:02:08] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '1' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:08] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '1' on Local/*844@default-application-9720,2
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131126(131126) on channel 23 (index 0)
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '6'
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2464 __ast_read: DTMF begin '6' received on Zap/23-1
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2468 __ast_read: DTMF begin ignored '6' on Zap/23-1
[2011-02-07 14:02:09] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '1' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:09] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '1' on Local/*844@default-application-9720,2
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262198(262198) on channel 23 (index 0)
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '6'
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: 6 on Zap/23-1
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '6' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '6' on Zap/23-1
[2011-02-07 14:02:09] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:09] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:09] DTMF[6030]: channel.c:2408 __ast_read: DTMF begin emulation of '0' with duration 80 queued on Zap/23-1
[2011-02-07 14:02:09] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:09] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:09] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:09] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:09] DTMF[6030]: channel.c:2497 __ast_read: DTMF end emulation of '0' queued on Zap/23-1
[2011-02-07 14:02:09] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:09] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:09] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:09] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=0, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '6' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '6' on Zap/23-1
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131120(131120) on channel 23 (index 0)
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '0'
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2464 __ast_read: DTMF begin '0' received on Zap/23-1
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2468 __ast_read: DTMF begin ignored '0' on Zap/23-1
[2011-02-07 14:02:09] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '0' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:09] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '0' on Local/*844@default-application-9720,2
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262192(262192) on channel 23 (index 0)
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '0'
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: 0 on Zap/23-1
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Zap/23-1
[2011-02-07 14:02:09] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '0' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:09] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Local/*844@default-application-9720,2
[2011-02-07 14:02:09] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:09] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '6' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:09] DTMF[6030]: channel.c:2408 __ast_read: DTMF begin emulation of '6' with duration 80 queued on Zap/23-1
[2011-02-07 14:02:09] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:09] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:09] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:09] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:09] DTMF[6030]: channel.c:2497 __ast_read: DTMF end emulation of '6' queued on Zap/23-1
[2011-02-07 14:02:09] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:09] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:09] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:09] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=6, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Zap/23-1
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131121(131121) on channel 23 (index 0)
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '1'
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2464 __ast_read: DTMF begin '1' received on Zap/23-1
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2468 __ast_read: DTMF begin ignored '1' on Zap/23-1
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262193(262193) on channel 23 (index 0)
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '1'
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: 1 on Zap/23-1
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '1' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '1' on Zap/23-1
[2011-02-07 14:02:09] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '6' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:09] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '6' on Local/*844@default-application-9720,2
[2011-02-07 14:02:09] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '6' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:09] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '6' on Local/*844@default-application-9720,2
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131120(131120) on channel 23 (index 0)
[2011-02-07 14:02:09] DEBUG[5928]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '0'
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2464 __ast_read: DTMF begin '0' received on Zap/23-1
[2011-02-07 14:02:09] DTMF[5928]: channel.c:2468 __ast_read: DTMF begin ignored '0' on Zap/23-1
[2011-02-07 14:02:09] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:09] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:09] DTMF[6030]: channel.c:2408 __ast_read: DTMF begin emulation of '0' with duration 80 queued on Zap/23-1
[2011-02-07 14:02:09] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:09] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:09] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:09] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:10] DTMF[6030]: channel.c:2497 __ast_read: DTMF end emulation of '0' queued on Zap/23-1
[2011-02-07 14:02:10] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:10] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:10] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:10] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=0, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '1' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '1' on Zap/23-1
[2011-02-07 14:02:10] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:10] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262192(262192) on channel 23 (index 0)
[2011-02-07 14:02:10] DEBUG[5928]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '0'
[2011-02-07 14:02:10] DEBUG[5928]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: 0 on Zap/23-1
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Zap/23-1
[2011-02-07 14:02:10] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '0' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:10] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '0' on Local/*844@default-application-9720,2
[2011-02-07 14:02:10] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:10] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 131107(131107) on channel 23 (index 0)
[2011-02-07 14:02:10] DEBUG[5928]: chan_dahdi.c:4248 dahdi_handle_event: DTMF Down '#'
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2464 __ast_read: DTMF begin '#' received on Zap/23-1
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2468 __ast_read: DTMF begin ignored '#' on Zap/23-1
[2011-02-07 14:02:10] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '0' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:10] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Local/*844@default-application-9720,2
[2011-02-07 14:02:10] DEBUG[5928]: chan_dahdi.c:5137 __dahdi_exception: Exception on 38, channel 23
[2011-02-07 14:02:10] DEBUG[5928]: chan_dahdi.c:4226 dahdi_handle_event: Got event Event 262179(262179) on channel 23 (index 0)
[2011-02-07 14:02:10] DEBUG[5928]: chan_dahdi.c:4231 dahdi_handle_event: Detected digit '#'
[2011-02-07 14:02:10] DEBUG[5928]: chan_dahdi.c:4096 dahdi_handle_dtmfup: DTMF digit: # on Zap/23-1
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '#' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '#' on Zap/23-1
[2011-02-07 14:02:10] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:10] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '1' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:10] DTMF[6030]: channel.c:2408 __ast_read: DTMF begin emulation of '1' with duration 80 queued on Zap/23-1
[2011-02-07 14:02:10] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:10] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:10] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:10] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:10] DTMF[6030]: channel.c:2497 __ast_read: DTMF end emulation of '1' queued on Zap/23-1
[2011-02-07 14:02:10] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:10] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:10] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:10] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=1, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Zap/23-1
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '#' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '#' on Zap/23-1
[2011-02-07 14:02:10] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '1' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:10] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '1' on Local/*844@default-application-9720,2
[2011-02-07 14:02:10] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '1' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:10] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '1' on Local/*844@default-application-9720,2
[2011-02-07 14:02:10] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:10] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '0' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:10] DTMF[6030]: channel.c:2408 __ast_read: DTMF begin emulation of '0' with duration 80 queued on Zap/23-1
[2011-02-07 14:02:10] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:10] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:10] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:10] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:10] DTMF[6030]: channel.c:2497 __ast_read: DTMF end emulation of '0' queued on Zap/23-1
[2011-02-07 14:02:10] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:10] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:10] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:10] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=0, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2382 __ast_read: DTMF end '#' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:10] DTMF[5928]: channel.c:2448 __ast_read: DTMF end passthrough '#' on Zap/23-1
[2011-02-07 14:02:10] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '0' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:10] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '0' on Local/*844@default-application-9720,2
[2011-02-07 14:02:10] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '0' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:10] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '0' on Local/*844@default-application-9720,2
[2011-02-07 14:02:11] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:11] DTMF[6030]: channel.c:2382 __ast_read: DTMF end '#' received on Zap/23-1, duration 80 ms
[2011-02-07 14:02:11] DTMF[6030]: channel.c:2408 __ast_read: DTMF begin emulation of '#' with duration 80 queued on Zap/23-1
[2011-02-07 14:02:11] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF begin on channel (Zap/23-1)
[2011-02-07 14:02:11] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:11] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:11] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:11] DEBUG[5462]: chan_sip.c:4800 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[2011-02-07 14:02:11] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 66.252.148.166 with 192.168.0.0
[2011-02-07 14:02:11] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 66.252.148.166 with 10.0.0.0
[2011-02-07 14:02:11] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 66.252.148.166 with 172.16.0.0
[2011-02-07 14:02:11] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 66.252.148.166 with 169.254.0.0
[2011-02-07 14:02:11] DEBUG[5462]: chan_sip.c:1898 ast_sip_ouraddrfor: Target address 66.252.148.166 is not local, substituting externip
[2011-02-07 14:02:11] 
[2011-02-07 14:02:11] DEBUG[5488]: 
[2011-02-07 14:02:11] DEBUG[5462]: chan_sip.c:2272 __sip_ack: Stopping retransmission on '1d5b4d775532ba3020e83a8308b45680@216.235.14.204' of Request 102: Match Found
[2011-02-07 14:02:11] DTMF[6030]: channel.c:2541 __ast_read: DTMF end emulation of '#' queued on Zap/23-1
[2011-02-07 14:02:11] DEBUG[6030]: channel.c:4569 ast_generic_bridge: Got DTMF end on channel (Zap/23-1)
[2011-02-07 14:02:11] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:11] DEBUG[6030]: channel.c:4886 ast_channel_bridge: Bridge stops bridging channels Zap/23-1 and Local/*844@default-application-9720,1
[2011-02-07 14:02:11] DEBUG[6030]: res_features.c:1539 feature_interpret: Feature interpret: chan=Zap/23-1, peer=Local/*844@default-application-9720,1, code=#, sense=1, features=0, dynamic=atxfer#atdxfer#blindxfer#automon#automixmon#hookflash#supervisor#conference#tagcode-*1000#tagcode-*1001#tagcode-*1002#tagcode-*
[2011-02-07 14:02:11] DTMF[6167]: channel.c:2464 __ast_read: DTMF begin '#' received on Local/*844@default-application-9720,2
[2011-02-07 14:02:11] DTMF[6167]: channel.c:2468 __ast_read: DTMF begin ignored '#' on Local/*844@default-application-9720,2
[2011-02-07 14:02:11] DTMF[6167]: channel.c:2382 __ast_read: DTMF end '#' received on Local/*844@default-application-9720,2, duration 100 ms
[2011-02-07 14:02:11] DTMF[6167]: channel.c:2448 __ast_read: DTMF end passthrough '#' on Local/*844@default-application-9720,2
[2011-02-07 14:02:11] DEBUG[6167]: app_voicemail.c:7695 vm_execmain: After vm_authenticate
[2011-02-07 14:02:11] DEBUG[6167]: app_voicemail.c:7737 vm_execmain: Before open_mailbox
[2011-02-07 14:02:11] DEBUG[6167]: app.c:1052 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/6010/Old'
[2011-02-07 14:02:11] DEBUG[6167]: app.c:1073 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/6010/Old'
[2011-02-07 14:02:11] DEBUG[6167]: app.c:1052 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/6010/Old'
[2011-02-07 14:02:11] DEBUG[6167]: app.c:1073 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/6010/Old'
[2011-02-07 14:02:11] DEBUG[6167]: app_voicemail.c:7743 vm_execmain: Number of old messages: 1
[2011-02-07 14:02:11] DEBUG[6167]: app.c:1052 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/6010/INBOX'
[2011-02-07 14:02:11] DEBUG[6167]: app.c:1073 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/6010/INBOX'
[2011-02-07 14:02:11] DEBUG[6167]: app.c:1052 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/6010/INBOX'
[2011-02-07 14:02:11] DEBUG[6167]: app.c:1073 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/6010/INBOX'
[2011-02-07 14:02:11] DEBUG[6167]: app_voicemail.c:7750 vm_execmain: Number of new messages: 0
[2011-02-07 14:02:11] DEBUG[6167]: app.c:1052 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/6010/Old'
[2011-02-07 14:02:11] DEBUG[6167]: app.c:1073 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/6010/Old'
[2011-02-07 14:02:11] DEBUG[6167]: app.c:1052 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/6010/Old'
[2011-02-07 14:02:11] DEBUG[6167]: app.c:1073 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/6010/Old'
[2011-02-07 14:02:11] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.86 with 192.168.0.0
[2011-02-07 14:02:11] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.86 with 10.0.0.0
[2011-02-07 14:02:11] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.86 with 172.16.0.0
[2011-02-07 14:02:11] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 160 sample intervals
[2011-02-07 14:02:11]     -- <Local/*844@default-application-9720,2> Playing 'vm-youhave' (language 'en')
[2011-02-07 14:02:11] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.86 with 169.254.0.0
[2011-02-07 14:02:11] DEBUG[5462]: chan_sip.c:4800 sip_alloc: Allocating new SIP dialog for 5d27248f-d9c030a6-f5a2cb31@192.168.30.86 - SUBSCRIBE (No RTP)
[2011-02-07 14:02:11] DEBUG[5462]: chan_sip.c:8909 build_route: build_route: Contact hop: <sip:6057@192.168.30.86:5060>
[2011-02-07 14:02:11] DEBUG[5462]: chan_sip.c:8847 build_route: build_route: Retaining previous route: <sip:6057@192.168.30.86:5060>
[2011-02-07 14:02:11] DEBUG[5462]: chan_sip.c:16299 handle_request_subscribe: Received SIP subscribe for unknown event package: missed-call-summary
[2011-02-07 14:02:11] DEBUG[6030]: chan_dahdi.c:5569 dahdi_indicate: Requested indication 20 on channel Zap/23-1
[2011-02-07 14:02:11] DEBUG[5462]: chan_sip.c:4800 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[2011-02-07 14:02:11] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 10.0.0.122 with 192.168.0.0
[2011-02-07 14:02:11] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 10.0.0.122 with 10.0.0.0
[2011-02-07 14:02:11] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 10.0.0.122 with 172.16.0.0
[2011-02-07 14:02:11] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 10.0.0.122 with 169.254.0.0
[2011-02-07 14:02:11] DEBUG[5462]: chan_sip.c:2272 __sip_ack: Stopping retransmission on '1369422f462da4603bca462a70f214d6@10.0.0.138' of Request 102: Match Found
[2011-02-07 14:02:12] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 139 sample intervals
[2011-02-07 14:02:12] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-02-07 14:02:12] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-02-07 14:02:12] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-02-07 14:02:12] DEBUG[6167]: channel.c:1980 ast_settimeout: Scheduling timer at 160 sample intervals
[2011-02-07 14:02:12]     -- <Local/*844@default-application-9720,2> Playing 'digits/1' (language 'en')
[2011-02-07 14:02:12] DEBUG[5462]: chan_sip.c:4800 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[2011-02-07 14:02:12] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.80 with 192.168.0.0
[2011-02-07 14:02:12] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.80 with 10.0.0.0
[2011-02-07 14:02:12] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.80 with 172.16.0.0
[2011-02-07 14:02:12] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.80 with 169.254.0.0
[2011-02-07 14:02:12] DEBUG[5462]: chan_sip.c:2272 __sip_ack: Stopping retransmission on '4c245a5b7464e36c540ce0512dc9e00b@192.168.30.254' of Request 102: Match Found
[2011-02-07 14:02:12] DEBUG[5462]: chan_sip.c:4800 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[2011-02-07 14:02:12] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.86 with 192.168.0.0
[2011-02-07 14:02:12] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.86 with 10.0.0.0
[2011-02-07 14:02:12] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.86 with 172.16.0.0
[2011-02-07 14:02:12] DEBUG[5462]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.86 with 169.254.0.0
[2011-02-07 14:02:12] DEBUG[5462]: chan_sip.c:2272 __sip_ack: Stopping retransmission on '25cb271c29fe2ec17ce84d49314a6283@192.168.30.254' of Request 102: Match Found