[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Executing [2434@incoming:1] Goto("SIP/gw2-b5ef9568", "incoming|s|1") in new stack
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Goto (incoming,s,1)
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Executing [s@incoming:1] Set("SIP/gw2-b5ef9568", "TIMEOUT(digit)=2") in new stack
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Digit timeout set to 2
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Executing [s@incoming:2] Set("SIP/gw2-b5ef9568", "TIMEOUT(response)=2") in new stack
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Response timeout set to 2
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Executing [s@incoming:3] SetMusicOnHold("SIP/gw2-b5ef9568", "default") in new stack
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Executing [s@incoming:4] GotoIf("SIP/gw2-b5ef9568", "0?blacklisted|s|1") in new stack
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Executing [s@incoming:5] NoOp("SIP/gw2-b5ef9568", " Not Blacklisted ") in new stack
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Executing [s@incoming:6] Answer("SIP/gw2-b5ef9568", "") in new stack
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Executing [s@incoming:7] SetGlobalVar("SIP/gw2-b5ef9568", "INBOUNDCIDNUM=asterisk") in new stack
[Sep 29 14:41:27] VERBOSE[20359] logger.c:   == Setting global variable 'INBOUNDCIDNUM' to 'asterisk'
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Executing [s@incoming:8] Goto("SIP/gw2-b5ef9568", "ivrmenu1|s|6") in new stack
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Goto (ivrmenu1,s,6)
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- Executing [s@ivrmenu1:6] BackGround("SIP/gw2-b5ef9568", "ivrmenu1") in new stack
[Sep 29 14:41:27] VERBOSE[20359] logger.c:     -- <SIP/gw2-b5ef9568> Playing 'ivrmenu1' (language 'en')
[Sep 29 14:41:30] DTMF[20359] channel.c: DTMF begin '0' received on SIP/gw2-b5ef9568
[Sep 29 14:41:30] DTMF[20359] channel.c: DTMF begin ignored '0' on SIP/gw2-b5ef9568
[Sep 29 14:41:30] DTMF[20359] channel.c: DTMF end '0' received on SIP/gw2-b5ef9568, duration 220 ms
[Sep 29 14:41:30] DTMF[20359] channel.c: DTMF end passthrough '0' on SIP/gw2-b5ef9568
[Sep 29 14:41:32] VERBOSE[20359] logger.c:   == CDR updated on SIP/gw2-b5ef9568
[Sep 29 14:41:32] VERBOSE[20359] logger.c:     -- Executing [0@ivrmenu1:1] Goto("SIP/gw2-b5ef9568", "default|0|1") in new stack
[Sep 29 14:41:32] VERBOSE[20359] logger.c:     -- Goto (default,0,1)
[Sep 29 14:41:32] VERBOSE[20359] logger.c:     -- Executing [0@default:1] Macro("SIP/gw2-b5ef9568", "stdexten|100|SIP/100") in new stack
[Sep 29 14:41:32] VERBOSE[20359] logger.c:     -- Executing [s@macro-stdexten:1] Playback("SIP/gw2-b5ef9568", "transfer|skip") in new stack
[Sep 29 14:41:32] VERBOSE[20359] logger.c:     -- <SIP/gw2-b5ef9568> Playing 'transfer' (language 'en')
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: Playback
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-stdexten:2] Macro("SIP/gw2-b5ef9568", "recordcall|100") in new stack
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-recordcall:1] NoOp("SIP/gw2-b5ef9568", "Calling extension 100") in new stack
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: NoOp
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-recordcall:2] Ringing("SIP/gw2-b5ef9568", "") in new stack
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: Ringing
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-recordcall:3] Set("SIP/gw2-b5ef9568", "trimChannel=gw2-b5ef9568") in new stack
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: Set
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-recordcall:4] Set("SIP/gw2-b5ef9568", "trimChannel=gw2") in new stack
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: Set
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-recordcall:5] GotoIf("SIP/gw2-b5ef9568", "0?6:8") in new stack
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Goto (macro-recordcall,s,8)
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: GotoIf
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-recordcall:8] NoOp("SIP/gw2-b5ef9568", "End of recordcall macro asterisk asterisk") in new stack
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: NoOp
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: Macro
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-stdexten:3] SetMusicOnHold("SIP/gw2-b5ef9568", "default") in new stack
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: SetMusicOnHold
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-stdexten:4] Set("SIP/gw2-b5ef9568", "MYTEMP=gw2-b5ef9568") in new stack
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: Set
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-stdexten:5] Set("SIP/gw2-b5ef9568", "MYEXT=gw2") in new stack
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: Set
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-stdexten:6] GotoIf("SIP/gw2-b5ef9568", "0?16:7") in new stack
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Goto (macro-stdexten,s,7)
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: GotoIf
[Sep 29 14:41:34] DEBUG[20359] func_db.c: DB: CFIM/100 not found in database.
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-stdexten:7] Set("SIP/gw2-b5ef9568", "number=") in new stack
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: Set
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-stdexten:8] GotoIf("SIP/gw2-b5ef9568", "1?10:9") in new stack
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Goto (macro-stdexten,s,10)
[Sep 29 14:41:34] DEBUG[20359] app_macro.c: Executed application: GotoIf
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Executing [s@macro-stdexten:10] Dial("SIP/gw2-b5ef9568", "SIP/100|25|W") in new stack
[Sep 29 14:41:34] VERBOSE[20359] logger.c:     -- Called 100
[Sep 29 14:41:35] VERBOSE[20359] logger.c:     -- SIP/100-08522d08 is ringing
[Sep 29 14:41:39] VERBOSE[20359] logger.c:     -- SIP/100-08522d08 answered SIP/gw2-b5ef9568
[Sep 29 14:41:47] VERBOSE[20359] logger.c:     -- Started music on hold, class 'default', on SIP/gw2-b5ef9568
[Sep 29 14:41:50] VERBOSE[20359] logger.c:   == Spawn extension (macro-stdexten, s, 10) exited non-zero on 'SIP/100-b5c26d18<ZOMBIE>' in macro 'stdexten'
[Sep 29 14:41:50] VERBOSE[20359] logger.c:   == Spawn extension (default, 0, 1) exited non-zero on 'SIP/100-b5c26d18<ZOMBIE>'
[Sep 29 14:41:50] VERBOSE[20359] logger.c:     -- Executing [h@default:1] Hangup("SIP/100-b5c26d18<ZOMBIE>", "") in new stack
[Sep 29 14:41:50] VERBOSE[20359] logger.c:   == Spawn extension (default, h, 1) exited non-zero on 'SIP/100-b5c26d18<ZOMBIE>'