[Apr 14 22:49:25] VERBOSE[7867] logger.c:     -- Executing [s-DIAL@macro-dialone:11] Set("Zap/31-1", "EXITCONTEXT=callback") in new stack
[Apr 14 22:49:25] DEBUG[7867] app_macro.c: Executed application: Set
[Apr 14 22:49:25] DEBUG[7867] pbx.c: Launching 'Set'
[Apr 14 22:49:25] VERBOSE[7867] logger.c:     -- Executing [s-DIAL@macro-dialone:12] Set("Zap/31-1", "orig_exten=236") in new stack
[Apr 14 22:49:25] DEBUG[7867] app_macro.c: Executed application: Set
[Apr 14 22:49:25] DEBUG[7867] pbx.c: Launching 'Dial'
[Apr 14 22:49:25] VERBOSE[7867] logger.c:     -- Executing [s-DIAL@macro-dialone:13] Dial("Zap/31-1", "SIP/236|30|dtT") in new stack
[Apr 14 22:49:25] DEBUG[7867] chan_sip.c: Asked to create a SIP channel with formats: 0x8 (alaw)
[Apr 14 22:49:25] DEBUG[7867] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
[Apr 14 22:49:25] DEBUG[7867] chan_sip.c: Setting NAT on RTP to On
[Apr 14 22:49:25] DEBUG[7867] acl.c: ##### Testing 10.10.5.1 with 10.10.0.0
[Apr 14 22:49:25] DEBUG[7867] rtp.c: Channel 'Zap/31-1' has no RTP, not doing anything
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable MACRO_DEPTH.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable orig_exten.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable EXITCONTEXT.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable calls.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable peer.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable ARG2.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable DIALNUM.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable CFNA.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable CFBS.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable CFIM.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable COUNT.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable ARG1.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable MACRO_PRIORITY.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable MACRO_CONTEXT.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable MACRO_EXTEN.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Copying soft-transferable variable start.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Copying soft-transferable variable intern.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable CALLEDTON.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable ANI2.
[Apr 14 22:49:25] DEBUG[7867] channel.c: Not copying variable TRANSFERCAPABILITY.
[Apr 14 22:49:25] DEBUG[7867] chan_sip.c: Outgoing Call for 236
[Apr 14 22:49:25] VERBOSE[7867] logger.c:     -- Called 236
[Apr 14 22:49:25] DEBUG[7867] channel.c: Set channel SIP/236-08219bb0 to read format slin
[Apr 14 22:49:25] DEBUG[7867] channel.c: Set channel Zap/31-1 to write format slin
[Apr 14 22:49:25] DEBUG[7867] channel.c: Set channel Zap/31-1 to read format g729
[Apr 14 22:49:25] DEBUG[7616] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '65fc078c0c6cd24f5c068b770dabc923@xxx.at' Request 102: Found
[Apr 14 22:49:25] VERBOSE[7867] logger.c:     -- SIP/236-08219bb0 is ringing
[Apr 14 22:49:25] DEBUG[7867] rtp.c: Channel 'Zap/31-1' has no RTP, not doing anything
[Apr 14 22:49:25] DEBUG[7867] chan_zap.c: Requested indication 3 on channel Zap/31-1
[Apr 14 22:49:26] DEBUG[7616] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '65fc078c0c6cd24f5c068b770dabc923@xxx.at' Request 102: Found
[Apr 14 22:49:26] VERBOSE[7867] logger.c:     -- SIP/236-08219bb0 is ringing
[Apr 14 22:49:26] DEBUG[7867] rtp.c: Channel 'Zap/31-1' has no RTP, not doing anything
[Apr 14 22:49:27] DEBUG[7616] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '65fc078c0c6cd24f5c068b770dabc923@xxx.at' Request 102: Found
[Apr 14 22:49:27] VERBOSE[7867] logger.c:     -- SIP/236-08219bb0 is ringing
[Apr 14 22:49:27] DEBUG[7867] rtp.c: Channel 'Zap/31-1' has no RTP, not doing anything
[Apr 14 22:49:29] DEBUG[7616] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '65fc078c0c6cd24f5c068b770dabc923@xxx.at' Request 102: Found
[Apr 14 22:49:29] VERBOSE[7867] logger.c:     -- SIP/236-08219bb0 is ringing
[Apr 14 22:49:29] DEBUG[7867] rtp.c: Channel 'Zap/31-1' has no RTP, not doing anything
[Apr 14 22:49:33] DEBUG[7616] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '65fc078c0c6cd24f5c068b770dabc923@xxx.at' Request 102: Found
[Apr 14 22:49:33] VERBOSE[7867] logger.c:     -- SIP/236-08219bb0 is ringing
[Apr 14 22:49:33] DEBUG[7867] rtp.c: Channel 'Zap/31-1' has no RTP, not doing anything
[Apr 14 22:49:37] VERBOSE[7609] logger.c:     -- Channel 0/31, span 1 got hangup request, cause 16
[Apr 14 22:49:37] DEBUG[7867] rtp.c: Channel 'Zap/31-1' has no RTP, not doing anything
[Apr 14 22:49:37] DEBUG[7867] channel.c: Hanging up channel 'SIP/236-08219bb0'
[Apr 14 22:49:37] DEBUG[7867] chan_sip.c: Hangup call SIP/236-08219bb0, SIP callid 65fc078c0c6cd24f5c068b770dabc923@xxx.at)
[Apr 14 22:49:37] DEBUG[7867] chan_sip.c: Acked pending invite 102
[Apr 14 22:49:37] DEBUG[7867] chan_sip.c: Stopping retransmission on '65fc078c0c6cd24f5c068b770dabc923@xxx.at' of Request 102: Match Found
[Apr 14 22:49:37] DEBUG[7867] app_dial.c: Exiting with DIALSTATUS=CANCEL.
[Apr 14 22:49:37] DEBUG[7867] app_macro.c: Spawn extension (macro-dialone,s-DIAL,13) exited non-zero on 'Zap/31-1' in macro 'dialone'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Spawn extension (macro-dialone,s-DIAL,13) exited non-zero on 'Zap/31-1'
[Apr 14 22:49:37] VERBOSE[7867] logger.c:   == Spawn extension (macro-dialone, s-DIAL, 13) exited non-zero on 'Zap/31-1'
[Apr 14 22:49:37] DEBUG[7867] channel.c: Soft-Hanging up channel 'Zap/31-1'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Expression result is '1'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Launching 'GotoIf'
[Apr 14 22:49:37] VERBOSE[7867] logger.c:     -- Executing [h@macro-dialone:1] GotoIf("Zap/31-1", "1?3") in new stack
[Apr 14 22:49:37] VERBOSE[7867] logger.c:     -- Goto (macro-dialone,h,3)
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Launching 'DeadAGI'
[Apr 14 22:49:37] VERBOSE[7867] logger.c:     -- Executing [h@macro-dialone:3] DeadAGI("Zap/31-1", "callback.sh") in new stack
[Apr 14 22:49:37] VERBOSE[7867] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/callback.sh
[Apr 14 22:49:37] VERBOSE[7867] logger.c:     -- AGI Script callback.sh completed, returning 0
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Launching 'Hangup'
[Apr 14 22:49:37] VERBOSE[7867] logger.c:     -- Executing [h@macro-dialone:4] Hangup("Zap/31-1", "") in new stack
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Spawn extension (macro-dialone,h,4) exited non-zero on 'Zap/31-1'
[Apr 14 22:49:37] VERBOSE[7867] logger.c:   == Spawn extension (macro-dialone, h, 4) exited non-zero on 'Zap/31-1'
[Apr 14 22:49:37] DEBUG[7867] channel.c: Hanging up channel 'Zap/31-1'
[Apr 14 22:49:37] DEBUG[7867] chan_zap.c: zt_hangup(Zap/31-1)
[Apr 14 22:49:37] DEBUG[7867] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/31-1
[Apr 14 22:49:37] DEBUG[7867] chan_zap.c: Hangup: channel: 31 index = 0, normal = 43, callwait = -1, thirdcall = -1
[Apr 14 22:49:37] DEBUG[7867] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
[Apr 14 22:49:37] DEBUG[7867] chan_zap.c: disabled echo cancellation on channel 31
[Apr 14 22:49:37] DEBUG[7867] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/31-1
[Apr 14 22:49:37] DEBUG[7867] chan_zap.c: Updated conferencing on 31, with 0 conference users
[Apr 14 22:49:37] DEBUG[7867] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/31-1
[Apr 14 22:49:37] DEBUG[7867] chan_zap.c: disabled echo cancellation on channel 31
[Apr 14 22:49:37] VERBOSE[7867] logger.c:     -- Hungup 'Zap/31-1'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is ''
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is ''
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is '236'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is 'default'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is 'Zap/31-1'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is 'SIP/236-08219bb0'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is 'Dial'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is 'SIP/236|30|dtT'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is '2009-04-14 22:49:25'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is ''
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is '2009-04-14 22:49:37'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is '12'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is '0'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is 'NO ANSWER'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is 'DOCUMENTATION'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is ''
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is '1239742165.4'
[Apr 14 22:49:37] DEBUG[7867] pbx.c: Function result is ''
[Apr 14 22:49:37] DEBUG[7616] chan_sip.c: Stopping retransmission on '65fc078c0c6cd24f5c068b770dabc923@xxx.at' of Request 102: Match Found