[Sep 29 15:29:05] VERBOSE[22796] logger.c:     -- Starting simple switch on 'DAHDI/1-1'
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- Executing [s@incoming:1] Set("DAHDI/1-1", "TIMEOUT(digit)=2") in new stack
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- Digit timeout set to 2
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- Executing [s@incoming:2] Set("DAHDI/1-1", "TIMEOUT(response)=2") in new stack
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- Response timeout set to 2
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- Executing [s@incoming:3] SetMusicOnHold("DAHDI/1-1", "default") in new stack
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- Executing [s@incoming:4] GotoIf("DAHDI/1-1", "0?blacklisted|s|1") in new stack
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- Executing [s@incoming:5] NoOp("DAHDI/1-1", " Not Blacklisted ") in new stack
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- Executing [s@incoming:6] Answer("DAHDI/1-1", "") in new stack
[Sep 29 15:29:06] DEBUG[22796] chan_dahdi.c: Took DAHDI/1-1 off hook
[Sep 29 15:29:06] DEBUG[22796] chan_dahdi.c: No echo training requested
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- Executing [s@incoming:7] SetGlobalVar("DAHDI/1-1", "INBOUNDCIDNUM=3XXXXXXXX9") in new stack
[Sep 29 15:29:06] VERBOSE[22796] logger.c:   == Setting global variable 'INBOUNDCIDNUM' to '3XXXXXXXX9'
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- Executing [s@incoming:8] Goto("DAHDI/1-1", "ivrmenu1|s|6") in new stack
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- Goto (ivrmenu1,s,6)
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- Executing [s@ivrmenu1:6] BackGround("DAHDI/1-1", "ivrmenu1") in new stack
[Sep 29 15:29:06] VERBOSE[22796] logger.c:     -- <DAHDI/1-1> Playing 'ivrmenu1' (language 'en')
[Sep 29 15:29:12] DTMF[22796] channel.c: DTMF end '0' received on DAHDI/1-1, duration 0 ms
[Sep 29 15:29:12] DTMF[22796] channel.c: DTMF end accepted without begin '0' on DAHDI/1-1
[Sep 29 15:29:12] DTMF[22796] channel.c: DTMF end passthrough '0' on DAHDI/1-1
[Sep 29 15:29:14] VERBOSE[22796] logger.c:   == CDR updated on DAHDI/1-1
[Sep 29 15:29:14] VERBOSE[22796] logger.c:     -- Executing [0@ivrmenu1:1] Goto("DAHDI/1-1", "default|0|1") in new stack
[Sep 29 15:29:14] VERBOSE[22796] logger.c:     -- Goto (default,0,1)
[Sep 29 15:29:14] VERBOSE[22796] logger.c:     -- Executing [0@default:1] Macro("DAHDI/1-1", "stdexten|100|SIP/100") in new stack
[Sep 29 15:29:14] VERBOSE[22796] logger.c:     -- Executing [s@macro-stdexten:1] Playback("DAHDI/1-1", "transfer|skip") in new stack
[Sep 29 15:29:14] VERBOSE[22796] logger.c:     -- <DAHDI/1-1> Playing 'transfer' (language 'en')
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: Playback
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-stdexten:2] Macro("DAHDI/1-1", "recordcall|100") in new stack
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-recordcall:1] NoOp("DAHDI/1-1", "Calling extension 100") in new stack
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: NoOp
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-recordcall:2] Ringing("DAHDI/1-1", "") in new stack
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: Ringing
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-recordcall:3] Set("DAHDI/1-1", "trimChannel=1-1") in new stack
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: Set
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-recordcall:4] Set("DAHDI/1-1", "trimChannel=1") in new stack
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: Set
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-recordcall:5] GotoIf("DAHDI/1-1", "0?6:8") in new stack
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Goto (macro-recordcall,s,8)
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: GotoIf
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-recordcall:8] NoOp("DAHDI/1-1", "End of recordcall macro 3XXXXXXXX9 3XXXXXXXX9") in new stack
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: NoOp
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: Macro
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-stdexten:3] SetMusicOnHold("DAHDI/1-1", "default") in new stack
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: SetMusicOnHold
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-stdexten:4] Set("DAHDI/1-1", "MYTEMP=1-1") in new stack
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: Set
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-stdexten:5] Set("DAHDI/1-1", "MYEXT=1") in new stack
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: Set
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-stdexten:6] GotoIf("DAHDI/1-1", "0?16:7") in new stack
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Goto (macro-stdexten,s,7)
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: GotoIf
[Sep 29 15:29:16] DEBUG[22796] func_db.c: DB: CFIM/100 not found in database.
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-stdexten:7] Set("DAHDI/1-1", "number=") in new stack
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: Set
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-stdexten:8] GotoIf("DAHDI/1-1", "1?10:9") in new stack
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Goto (macro-stdexten,s,10)
[Sep 29 15:29:16] DEBUG[22796] app_macro.c: Executed application: GotoIf
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Executing [s@macro-stdexten:10] Dial("DAHDI/1-1", "SIP/100|25|W") in new stack
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- Called 100
[Sep 29 15:29:16] VERBOSE[22796] logger.c:     -- SIP/100-08af11c8 is ringing
[Sep 29 15:29:26] VERBOSE[22796] logger.c:     -- SIP/100-08af11c8 answered DAHDI/1-1
[Sep 29 15:29:35] VERBOSE[22796] logger.c:     -- Started music on hold, class 'default', on DAHDI/1-1
[Sep 29 15:29:37] VERBOSE[22796] logger.c:   == Spawn extension (macro-stdexten, s, 10) exited non-zero on 'SIP/100-b5c26d18<ZOMBIE>' in macro 'stdexten'
[Sep 29 15:29:37] VERBOSE[22796] logger.c:   == Spawn extension (default, 0, 1) exited non-zero on 'SIP/100-b5c26d18<ZOMBIE>'
[Sep 29 15:29:37] VERBOSE[22796] logger.c:     -- Executing [h@default:1] Hangup("SIP/100-b5c26d18<ZOMBIE>", "") in new stack
[Sep 29 15:29:37] VERBOSE[22796] logger.c:   == Spawn extension (default, h, 1) exited non-zero on 'SIP/100-b5c26d18<ZOMBIE>'