-- Executing [150@from-ido-sip:1] Dial("SIP/401-09b2e1e0", "Zap/1/150|20") in new stack [Jun 7 16:49:40] DEBUG[19535]: chan_zap.c:7818 zt_request: Using channel 1 [Jun 7 16:49:40] DEBUG[19535]: rtp.c:1567 ast_rtp_make_compatible: Channel 'Zap/1-1' has no RTP, not doing anything [Jun 7 16:49:40] DEBUG[19535]: channel.c:3413 ast_channel_inherit_variables: Not copying variable STACK-from-ido-sip-150-1. [Jun 7 16:49:40] DEBUG[19535]: channel.c:3413 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Jun 7 16:49:40] DEBUG[19535]: channel.c:3413 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Jun 7 16:49:40] DEBUG[19535]: channel.c:3413 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Jun 7 16:49:40] DEBUG[19535]: channel.c:3413 ast_channel_inherit_variables: Not copying variable SIPURI. -- Requested transfer capability: 0x00 - SPEECH [Jun 7 16:49:40] DEBUG[19504]: channel.c:1058 channel_find_locked: Avoiding initial deadlock for channel '0x9b328a0' -- Called 1/150 [Jun 7 16:49:40] DEBUG[19535]: chan_sip.c:6478 transmit_response_with_sdp: Setting framing from config on incoming call [Jun 7 16:49:40] DEBUG[19535]: rtp.c:2717 ast_rtp_write: Ooh, format changed from unknown to alaw [Jun 7 16:49:40] DEBUG[19535]: rtp.c:2734 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160 [Jun 7 16:49:40] DEBUG[19506]: chan_zap.c:8957 pri_dchannel: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1 -- Zap/1-1 is proceeding passing it to SIP/401-09b2e1e0 [Jun 7 16:49:40] DEBUG[19535]: rtp.c:1492 ast_rtp_early_bridge: Channel 'Zap/1-1' has no RTP, not doing anything [Jun 7 16:49:40] DEBUG[19506]: chan_zap.c:1436 zt_enable_ec: No echo cancellation requested [Jun 7 16:49:40] DEBUG[19504]: channel.c:1058 channel_find_locked: Avoiding initial deadlock for channel '0x9b328a0' -- Zap/1-1 is ringing [Jun 7 16:49:40] DEBUG[19535]: rtp.c:1492 ast_rtp_early_bridge: Channel 'Zap/1-1' has no RTP, not doing anything [Jun 7 16:49:40] DEBUG[19535]: chan_sip.c:4131 sip_rtp_read: Oooh, format changed to 1 [Jun 7 16:49:40] WARNING[19535]: channel.c:2918 set_format: Unable to find a codec translation path from g723 to alaw [Jun 7 16:49:40] WARNING[19535]: channel.c:2918 set_format: Unable to find a codec translation path from g723 to alaw [Jun 7 16:49:40] WARNING[19535]: chan_zap.c:4934 zt_write: Cannot handle frames in 1 format [Jun 7 16:49:40] WARNING[19535]: app_dial.c:741 wait_for_answer: Unable to forward voice or dtmf [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is 's' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is 'from-ido' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is 'Zap/1-1' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '2007-06-07 16:49:40' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '2007-06-07 16:49:40' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '0' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '0' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is 'NO ANSWER' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '1181220580.7' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '' [Jun 7 16:49:40] DEBUG[19535]: channel.c:1727 ast_hangup: Hanging up channel 'Zap/1-1' [Jun 7 16:49:40] DEBUG[19535]: chan_zap.c:2411 zt_hangup: zt_hangup(Zap/1-1) [Jun 7 16:49:40] DEBUG[19535]: chan_zap.c:2956 zt_setoption: Set option AUDIO MODE, value: ON(1) on Zap/1-1 [Jun 7 16:49:40] DEBUG[19535]: chan_zap.c:2445 zt_hangup: Hangup: channel: 1 index = 0, normal = 9, callwait = -1, thirdcall = -1 [Jun 7 16:49:40] DEBUG[19535]: chan_zap.c:2599 zt_hangup: Not yet hungup... Calling hangup once with icause, and clearing call [Jun 7 16:49:40] DEBUG[19535]: chan_zap.c:2873 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/1-1 [Jun 7 16:49:40] DEBUG[19535]: chan_zap.c:1402 update_conf: Updated conferencing on 1, with 0 conference users [Jun 7 16:49:40] DEBUG[19535]: chan_zap.c:2952 zt_setoption: Set option AUDIO MODE, value: OFF(0) on Zap/1-1 -- Hungup 'Zap/1-1' == Everyone is busy/congested at this time (1:0/0/1) [Jun 7 16:49:40] DEBUG[19535]: rtp.c:1492 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Jun 7 16:49:40] DEBUG[19535]: app_dial.c:1691 dial_exec_full: Exiting with DIALSTATUS=CHANUNAVAIL. == Auto fallthrough, channel 'SIP/401-09b2e1e0' status is 'CHANUNAVAIL' [Jun 7 16:49:40] DEBUG[19535]: channel.c:1514 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/401-09b2e1e0' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '"401" <401>' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '401' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '150' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is 'from-ido-sip' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is 'SIP/401-09b2e1e0' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is 'Zap/1-1' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is 'Dial' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is 'Zap/1/150|20' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '2007-06-07 16:49:40' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '2007-06-07 16:49:40' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '0' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '0' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is 'NO ANSWER' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '1181220580.6' [Jun 7 16:49:40] DEBUG[19535]: pbx.c:1668 pbx_substitute_variables_helper_full: Function result is '' [Jun 7 16:49:40] DEBUG[19535]: channel.c:1727 ast_hangup: Hanging up channel 'SIP/401-09b2e1e0' [Jun 7 16:49:40] DEBUG[19535]: chan_sip.c:3346 sip_hangup: Hangup call SIP/401-09b2e1e0, SIP callid 1819216909-101944251@192.168.3.178) [Jun 7 16:49:40] DEBUG[19508]: chan_sip.c:2120 __sip_ack: Stopping retransmission on '1819216909-101944251@192.168.3.178' of Response 2: Match Found