--- set_address_from_contact host '215.32.47.88' -- SIP/org_tiskeledom_2-082a1520 answered Local/03@ext-dialer-ac5e;2 > Channel Local/03@ext-dialer-ac5e;1 was answered. [Nov 20 17:48:36] DEBUG[2318]: pbx.c:2555 pbx_extension_helper: Launching 'Set' -- Executing [03@ext-dialer-message:1] Set("Local/03@ext-dialer-ac5e;1", "AGISIGHUP=yes") in new stack [Nov 20 17:48:36] DEBUG[2318]: pbx.c:2555 pbx_extension_helper: Launching 'AGI' -- Executing [03@ext-dialer-message:2] AGI("Local/03@ext-dialer-ac5e;1", "dialer/dial-message.php,2,3") in new stack -- Launched AGI Script /var/lib/asterisk/agi-bin/dialer/dial-message.php -- AGI Script Executing Application: (Wait) Options: (1) -- AGI Script Executing Application: (Set) Options: (CHANNEL(language)=ru-1) -- AGI Script Executing Application: (Playback) Options: (main_1_1) [Nov 20 17:48:37] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 160 sample intervals -- Playing 'main_1_1.slin' (language 'ru-1') [Nov 20 17:48:37] DEBUG[2318]: rtp.c:3103 ast_rtp_write: Ooh, format changed from unknown to g729 [Nov 20 17:48:37] DEBUG[2318]: rtp.c:3119 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Nov 20 17:48:38] DEBUG[2318]: manager.c:2372 process_message: Manager received command 'Ping' [Nov 20 17:48:38] DEBUG[2318]: manager.c:2372 process_message: Manager received command 'Command' [Nov 20 17:48:39] DEBUG[2318]: channel.c:3935 ast_generic_bridge: Didn't get a frame from channel: SIP/org_tiskeledom_2-082a1520 [Nov 20 17:48:39] DEBUG[2318]: channel.c:4266 ast_channel_bridge: Bridge stops bridging channels Local/03@ext-dialer-ac5e;2 and SIP/org_tiskeledom_2-082a1520 [Nov 20 17:48:39] DEBUG[2318]: channel.c:1453 ast_hangup: Hanging up channel 'SIP/org_tiskeledom_2-082a1520' [Nov 20 17:48:39] DEBUG[2318]: chan_sip.c:4044 sip_hangup: Hangup call SIP/org_tiskeledom_2-082a1520, SIP callid 582a80b77331f3da7920a72b63279b8a@siptel-omsk.ru [Nov 20 17:48:39] DEBUG[2318]: app_dial.c:1822 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Nov 20 17:48:39] DEBUG[2318]: pbx.c:3198 __ast_pbx_run: Spawn extension (ext-dialer,03,5) exited non-zero on 'Local/03@ext-dialer-ac5e;2' == Spawn extension (ext-dialer, 03, 5) exited non-zero on 'Local/03@ext-dialer-ac5e;2' [Nov 20 17:48:39] DEBUG[2318]: channel.c:1354 ast_softhangup_nolock: Soft-Hanging up channel 'Local/03@ext-dialer-ac5e;2' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2555 pbx_extension_helper: Launching 'Set' -- Executing [h@ext-dialer:1] Set("Local/03@ext-dialer-ac5e;2", "DATA_STATUS=ANSWER") in new stack [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2555 pbx_extension_helper: Launching 'Set' -- Executing [h@ext-dialer:2] Set("Local/03@ext-dialer-ac5e;2", "DATA_CAUSE=16") in new stack [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '0' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2555 pbx_extension_helper: Launching 'Set' -- Executing [h@ext-dialer:3] Set("Local/03@ext-dialer-ac5e;2", "DATA_TIME=0") in new stack [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2555 pbx_extension_helper: Launching 'AGI' -- Executing [h@ext-dialer:4] AGI("Local/03@ext-dialer-ac5e;2", "dialer/dial-final.php") in new stack [Nov 20 17:48:39] NOTICE[2318]: res_agi.c:2121 agi_exec_full: Hungup channel detected, running agi in dead mode. -- Launched AGI Script /var/lib/asterisk/agi-bin/dialer/dial-final.php -- AGI Script dialer/dial-final.php completed, returning 0 [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2555 pbx_extension_helper: Launching 'Hangup' -- Executing [h@ext-dialer:5] Hangup("Local/03@ext-dialer-ac5e;2", "") in new stack [Nov 20 17:48:39] DEBUG[2318]: pbx.c:3327 __ast_pbx_run: Spawn extension (ext-dialer,h,5) exited non-zero on 'Local/03@ext-dialer-ac5e;2' == Spawn extension (ext-dialer, h, 5) exited non-zero on 'Local/03@ext-dialer-ac5e;2' [Nov 20 17:48:39] DEBUG[2318]: channel.c:1453 ast_hangup: Hanging up channel 'Local/03@ext-dialer-ac5e;2' [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 20 17:48:39] DEBUG[2318]: cdr_addon_mysql.c:247 mysql_log: cdr_mysql: inserting a CDR record. [Nov 20 17:48:39] DEBUG[2318]: cdr_addon_mysql.c:261 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO ast_cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,userfield) VALUES ('2007-11-20 17:48:28','','','03','ext-dialer', 'Local/03@ext-dialer-ac5e;2','SIP/org_tiskeledom_2-082a1520','Dial','SIP/org_tiskeledom_2/220372,20,',11,3,'ANSWERED',3,'','3') [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '03' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'ext-dialer' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'Local/03@ext-dialer-ac5e;2' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'SIP/org_tiskeledom_2-082a1520' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'SIP/org_tiskeledom_2/220372,20,' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '2007-11-20 17:48:28' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '2007-11-20 17:48:36' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '2007-11-20 17:48:39' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '11' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '3' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '1195559308.4' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '3' -- AGI Script Executing Application: (Playback) Options: (pervoe) [Nov 20 17:48:39] WARNING[2318]: file.c:619 ast_readaudio_callback: Failed to write frame [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals -- Playing 'pervoe.slin' (language 'ru-1') [Nov 20 17:48:39] WARNING[2318]: app_playback.c:444 playback_exec: ast_streamfile failed on Local/03@ext-dialer-ac5e;1 for pervoe -- AGI Script Executing Application: (Playback) Options: (mon-11) [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 20 17:48:39] WARNING[2318]: file.c:619 ast_readaudio_callback: Failed to write frame [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals -- Playing 'mon-11.slin' (language 'ru-1') [Nov 20 17:48:39] WARNING[2318]: app_playback.c:444 playback_exec: ast_streamfile failed on Local/03@ext-dialer-ac5e;1 for mon-11 -- AGI Script Executing Application: (Playback) Options: (main_1_3) [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 20 17:48:39] WARNING[2318]: file.c:619 ast_readaudio_callback: Failed to write frame [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals -- Playing 'main_1_3.slin' (language 'ru-1') [Nov 20 17:48:39] WARNING[2318]: app_playback.c:444 playback_exec: ast_streamfile failed on Local/03@ext-dialer-ac5e;1 for main_1_3 [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 20 17:48:39] WARNING[2318]: file.c:619 ast_readaudio_callback: Failed to write frame [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals -- Playing 'digits/30.slin' (language 'ru-1') [Nov 20 17:48:39] WARNING[2318]: app_playback.c:126 s_streamwait3: Unable to play message digits/30 [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 20 17:48:39] WARNING[2318]: file.c:619 ast_readaudio_callback: Failed to write frame [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals -- Playing 'digits/5.slin' (language 'ru-1') [Nov 20 17:48:39] WARNING[2318]: app_playback.c:126 s_streamwait3: Unable to play message digits/5 -- AGI Script Executing Application: (Playback) Options: (rubles) [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 20 17:48:39] WARNING[2318]: file.c:619 ast_readaudio_callback: Failed to write frame [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals -- Playing 'rubles.slin' (language 'ru-1') [Nov 20 17:48:39] WARNING[2318]: app_playback.c:444 playback_exec: ast_streamfile failed on Local/03@ext-dialer-ac5e;1 for rubles [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 20 17:48:39] WARNING[2318]: file.c:619 ast_readaudio_callback: Failed to write frame [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals -- Playing 'digits/60.slin' (language 'ru-1') [Nov 20 17:48:39] WARNING[2318]: app_playback.c:126 s_streamwait3: Unable to play message digits/60 -- AGI Script Executing Application: (Playback) Options: (kopejek) [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 20 17:48:39] WARNING[2318]: file.c:619 ast_readaudio_callback: Failed to write frame [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals -- Playing 'kopejek.slin' (language 'ru-1') [Nov 20 17:48:39] WARNING[2318]: app_playback.c:444 playback_exec: ast_streamfile failed on Local/03@ext-dialer-ac5e;1 for kopejek -- AGI Script Executing Application: (Playback) Options: (main_1_8) [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 20 17:48:39] WARNING[2318]: file.c:619 ast_readaudio_callback: Failed to write frame [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals -- Playing 'main_1_8.slin' (language 'ru-1') [Nov 20 17:48:39] WARNING[2318]: app_playback.c:444 playback_exec: ast_streamfile failed on Local/03@ext-dialer-ac5e;1 for main_1_8 -- AGI Script Executing Application: (Playback) Options: (main_1_9) [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 20 17:48:39] WARNING[2318]: file.c:619 ast_readaudio_callback: Failed to write frame [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals -- Playing 'main_1_9.slin' (language 'ru-1') [Nov 20 17:48:39] WARNING[2318]: app_playback.c:444 playback_exec: ast_streamfile failed on Local/03@ext-dialer-ac5e;1 for main_1_9 -- AGI Script Executing Application: (Playback) Options: (main_1_10) [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 20 17:48:39] WARNING[2318]: file.c:619 ast_readaudio_callback: Failed to write frame [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals -- Playing 'main_1_10.slin' (language 'ru-1') [Nov 20 17:48:39] WARNING[2318]: app_playback.c:444 playback_exec: ast_streamfile failed on Local/03@ext-dialer-ac5e;1 for main_1_10 -- AGI Script dialer/dial-message.php completed, returning -1 [Nov 20 17:48:39] DEBUG[2318]: pbx.c:3180 __ast_pbx_run: Extension 03, priority 2 returned normally even though call was hung up [Nov 20 17:48:39] DEBUG[2318]: channel.c:1354 ast_softhangup_nolock: Soft-Hanging up channel 'Local/03@ext-dialer-ac5e;1' [Nov 20 17:48:39] DEBUG[2318]: channel.c:1980 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 20 17:48:39] DEBUG[2318]: channel.c:1453 ast_hangup: Hanging up channel 'Local/03@ext-dialer-ac5e;1' [Nov 20 17:48:39] DEBUG[2318]: cdr_addon_mysql.c:247 mysql_log: cdr_mysql: inserting a CDR record. [Nov 20 17:48:39] DEBUG[2318]: cdr_addon_mysql.c:261 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO ast_cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,userfield) VALUES ('2007-11-20 17:48:28','','','03','ext-dialer', 'Local/03@ext-dialer-ac5e;1','','Playback','main_1_1',11,3,'ANSWERED',3,'','') [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '03' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'ext-dialer' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'Local/03@ext-dialer-ac5e;1' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'Playback' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'main_1_1' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '2007-11-20 17:48:28' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '2007-11-20 17:48:36' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '2007-11-20 17:48:39' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '11' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '3' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '1195559308.3' [Nov 20 17:48:39] DEBUG[2318]: pbx.c:2397 pbx_substitute_variables_helper_full: Function result is '' [Nov 20 17:48:39] NOTICE[2318]: pbx_spool.c:342 attempt_thread: Call completed to Local/03@ext-dialer/n