09:54:06:786 EROR SNDCACHE titan.la Unsupported Content-Type of "audio/x-gsm" returned for http://localhost/examples/welcome.gsm in url/localhost/examples/welcome.gsm
09:55:48:318 EROR SNDCACHE titan.la Unsupported Content-Type of "audio/x-gsm" returned for http://localhost/call/vxml/test/welcome.gsm in url/localhost/call/vxml/test/welcome.gsm
09:59:06:884 EROR SNDCACHE titan.la Unsupported Content-Type of "audio/x-gsm" returned for http://localhost/examples/welcome.gsm in url/localhost/examples/welcome.gsm
10:00:48:352 EROR SNDCACHE titan.la Unsupported Content-Type of "audio/x-gsm" returned for http://localhost/call/vxml/test/welcome.gsm in url/localhost/call/vxml/test/welcome.gsm
10:03:29:949 ==== DYNLOG -DYNLOG- Changing log level to DBUG (7)
10:03:29:952 INFO DYNLOG -DYNLOG- log client "::LOGGER6" disconnected code = 0
10:03:41:852 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: PeerStatus\r\nPrivilege: system,all\r\nPeer: SIP/17035421885\r\nPeerStatus: Registered\r\n\r\n"
10:03:42:476 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: PeerStatus\r\nPrivilege: system,all\r\nPeer: SIP/17035421885\r\nPeerStatus: Registered\r\n\r\n"
10:03:44:202 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: PeerStatus\r\nPrivilege: system,all\r\nPeer: SIP/sameer\r\nPeerStatus: Registered\r\n\r\n"
10:03:46:599 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: PeerStatus\r\nPrivilege: system,all\r\nPeer: SIP/sameer\r\nPeerStatus: Registered\r\n\r\n"
10:03:52:442 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Newchannel\r\nPrivilege: call,all\r\nChannel: SIP/sip_proxy-out-01473900\r\nState: Down\r\nCallerIDNum: <unknown>\r\nCallerIDName: <unknown>\r\nUniqueid: asterisk-1245074632.10180\r\n\r\n"
10:03:52:443 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Newcallerid\r\nPrivilege: call,all\r\nChannel: SIP/sip_proxy-out-01473900\r\nCallerID: <Unknown>\r\nCallerIDName: <Unknown>\r\nUniqueid: asterisk-1245074632.10180\r\nCID-CallingPres: 0 (Presentation Allowed, Not Screened)\r\n\r\n"
10:03:53:459 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: PeerStatus\r\nPrivilege: system,all\r\nPeer: SIP/7035421885\r\nPeerStatus: Registered\r\n\r\n"
10:03:56:772 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Newstate\r\nPrivilege: call,all\r\nChannel: SIP/sip_proxy-out-01473900\r\nState: Up\r\nCallerID: <unknown>\r\nCallerIDName: <unknown>\r\nUniqueid: asterisk-1245074632.10180\r\n\r\n"
10:03:56:772 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: OriginateResponse\r\nPrivilege: call,all\r\nResponse: Success\r\nChannel: SIP/sip_proxy-out-01473900\r\nContext: lastpass\r\nExten: 9501\r\nReason: 4\r\nUniqueid: asterisk-1245074632.10180\r\nCallerID: <unknown>\r\nCallerIDNum: <unknown>\r\nCallerIDName: <unknown>\r\n\r\n"
10:03:56:772 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Newexten\r\nPrivilege: call,all\r\nChannel: SIP/sip_proxy-out-01473900\r\nContext: lastpass\r\nExtension: 9501\r\nPriority: 1\r\nApplication: AGI\r\nAppData: agi://localhost/url=http%3A%2F%2Flocalhost%2F%7Edrew%2Fcall%2Fvxml%2Fapi%2Fcall.php&callid=10af7145975ce05b62389e1db5d5ca52\r\nUniqueid: asterisk-1245074632.10180\r\n\r\n"
10:03:56:772 INFO PHONGLUE titan.la New AGI connection on fh = ::FASTAGI6031
10:03:56:772 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_network: yes\n"
10:03:56:773 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_network" = "yes"
10:03:56:773 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_network_script: url=http%3A%2F%2Flocalhost%2F%7Edrew%2Fcall%2Fvxml%2Fapi%2Fcall.php&callid=10af7145975ce05b62389e1db5d5ca52\n"
10:03:56:773 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_network_script" = "url=http%3A%2F%2Flocalhost%2F%7Edrew%2Fcall%2Fvxml%2Fapi%2Fcall.php&callid=10af7145975ce05b62389e1db5d5ca52"
10:03:56:773 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_request: agi://localhost/url=http%3A%2F%2Flocalhost%2F%7Edrew%2Fcall%2Fvxml%2Fapi%2Fcall.php&callid=10af7145975ce05b62389e1db5d5ca52\n"
10:03:56:773 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_request" = "agi://localhost/url=http%3A%2F%2Flocalhost%2F%7Edrew%2Fcall%2Fvxml%2Fapi%2Fcall.php&callid=10af7145975ce05b62389e1db5d5ca52"
10:03:56:773 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_channel: SIP/sip_proxy-out-01473900\n"
10:03:56:773 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_channel" = "SIP/sip_proxy-out-01473900"
10:03:56:773 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_language: en\n"
10:03:56:773 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_language" = "en"
10:03:56:773 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_type: SIP\n"
10:03:56:773 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_type" = "SIP"
10:03:56:773 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_uniqueid: asterisk-1245074632.10180\n"
10:03:56:774 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_uniqueid" = "asterisk-1245074632.10180"
10:03:56:774 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_callerid: unknown\n"
10:03:56:774 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_callerid" = "unknown"
10:03:56:774 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_calleridname: unknown\n"
10:03:56:774 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_calleridname" = "unknown"
10:03:56:774 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_callingpres: 0\n"
10:03:56:774 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_callingpres" = "0"
10:03:56:774 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_callingani2: 0\n"
10:03:56:774 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_callingani2" = "0"
10:03:56:774 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_callington: 0\n"
10:03:56:775 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_callington" = "0"
10:03:56:775 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_callingtns: 0\n"
10:03:56:775 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_callingtns" = "0"
10:03:56:775 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_dnid: unknown\n"
10:03:56:775 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_dnid" = "unknown"
10:03:56:775 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_rdnis: unknown\n"
10:03:56:775 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_rdnis" = "unknown"
10:03:56:775 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_context: lastpass\n"
10:03:56:775 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_context" = "lastpass"
10:03:56:775 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_extension: 9501\n"
10:03:56:775 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_extension" = "9501"
10:03:56:775 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_priority: 1\n"
10:03:56:776 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_priority" = "1"
10:03:56:776 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_enhanced: 0.0\n"
10:03:56:776 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_enhanced" = "0.0"
10:03:56:776 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "agi_accountcode: 10af7145975ce05b623\n"
10:03:56:776 DBUG PHONGLUE titan.la ::FASTAGI6031 initial data "agi_accountcode" = "10af7145975ce05b623"
10:03:56:776 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "\n"
10:03:56:776 INFO PHONGLUE titan.la callid=[6031] new incoming assigned to index 0 of 1: CT client on fh="::CTCLIENT2" at host=127.0.0.1 proto=SATC
10:03:56:777 DBUG PHONGLUE titan.la callid=[6031] snd incoming callid=6031 ani="unknown" dnis="9501" arg="url=http%3A%2F%2Flocalhost%2F%7Edrew%2Fcall%2Fvxml%2Fapi%2Fcall.php&callid=10af7145975ce05b62389e1db5d5ca52" to CT client on fh="::CTCLIENT2" at host=127.0.0.1 proto=SATC
10:03:56:778 DBUG PHONGLUE titan.la snd "incoming 6031 unknown 9501 \"url=http%3A%2F%2Flocalhost%2F%7Edrew%2Fcall%2Fvxml%2Fapi%2Fcall.php&callid=10af7145975ce05b62389e1db5d5ca52\"\n" to ::CTCLIENT2
10:03:56:781 DBUG VOICEGLU titan.la rcv ctsrv: "incoming 6031 unknown 9501 \"url=http%3A%2F%2Flocalhost%2F%7Edrew%2Fcall%2Fvxml%2Fapi%2Fcall.php&callid=10af7145975ce05b62389e1db5d5ca52\"\n"
10:03:56:781 DBUG VOICEGLU titan.la callid=[6031] parsed incoming callid=6031 ani="unknown" dnis="9501" arg="url=http%3A%2F%2Flocalhost%2F%7Edrew%2Fcall%2Fvxml%2Fapi%2Fcall.php&callid=10af7145975ce05b62389e1db5d5ca52"
10:03:56:781 NOTI VOICEGLU titan.la callid=[6031] starting VXML interp on url="http://localhost/~drew/call/vxml/api/call.php?callid=10af7145975ce05b62389e1db5d5ca52" for DNIS="9501" perlfd=10 vxmlfd=11
10:03:56:782 NOTI OPEN_VXI titan.la callid=[6031] Channel 6031: Waiting for Call 1
10:03:56:783 DBUG OPEN_VXI titan.la callid=[6031] |140347469982032|6031|60001|testClient::ChannelThread|About to call VXIplatformWaitForCall
10:03:56:783 DBUG OPEN_VXI titan.la callid=[6031] |140347469982032|6031|60001|testClient::ChannelThread|In a Call
10:03:56:784 NOTI OPEN_VXI titan.la callid=[6031] Channel 6031: In a Call
10:03:56:789 DBUG OPEN_VXI titan.la callid=[6031] JsiContext::Create() started
10:03:56:790 DBUG OPEN_VXI titan.la callid=[6031] JsiContext::Create(): JS_THREADSAFE set
10:03:56:792 DBUG OPEN_VXI titan.la callid=[6031] JSDOMDocument::JSInit() started
10:03:56:793 DBUG OPEN_VXI titan.la callid=[6031] JS_InitClass(JSDOMDocument) OK, do: InitNodeObject()
10:03:56:794 DBUG OPEN_VXI titan.la callid=[6031] JsiContext::Create() finished
10:03:56:927 DBUG OPEN_VXI titan.la callid=[6031] VXIpromptQueue called with spec=<?xml version='1.0'?><speak version='1.0' xmlns='http://www.w3.org/2001/10/synthesis' xml:base='http://localhost/~drew/call/vxml/api/welcome.php' xml:lang='en'><audio src="http://www.zitnay.com/stuff/test2.wav" fetchtimeout="7s" fetchhint="prefetch"/></speak>, properties={" absoluteURI"="http://localhost/~drew/call/vxml/api/welcome.php" " base"="http://localhost/~drew/call/vxml/api/welcome.php" " encoding"="UTF-8" "audiofetchhint"="prefetch" "bargein"="false" "bargeintype"="speech" "confidencelevel"="0.5" "datafetchhint"="prefetch" "documentfetchhint"="safe" "fetchaudiodelay"="2s" "fetchaudiominimum"="5s" "fetchtimeout"="7s" "grammarfetchhint"="prefetch" "inet.urlBase"="http://localhost/~drew/call/vxml/api/welcome.php" "inputmodes"="dtmf voice" "maxnbest"="1" "objectfetchhint"="prefetch" "scriptfetchhint"="prefetch" "sensitivity"="0.5" "speedvsaccuracy"="0.5" "swirec_extra_nbest_keys"="" "termchar"="#" "termtimeout"="0s" "universals"="none"}
10:03:56:927 DBUG OPEN_VXI titan.la callid=[6031] VXIpromptQueue (<?xml version='1.0'?><speak version='1.0' xmlns='http://www.w3.org/2001/10/synthesis' xml:base='http://localhost/~drew/call/vxml/api/welcome.php' xml:lang='en'><audio src="http://www.zitnay.com/stuff/test2.wav" fetchtimeout="7s" fetchhint="prefetch"/></speak>, )
10:03:56:928 DBUG OPEN_VXI titan.la callid=[6031] snd vg: Queue "<?xml version=\'1.0\'?><speak version=\'1.0\' xmlns=\'http://www.w3.org/2001/10/synthesis\' xml:base=\'http://localhost/~drew/call/vxml/api/welcome.php\' xml:lang=\'en\'><audio src=\"http://www.zitnay.com/stuff/test2.wav\" fetchtimeout=\"7s\" fetchhint=\"prefetch\"/></speak>" ""
10:03:56:928 DBUG VOICEGLU titan.la callid=[6031] rcv ovxi: "Queue \"<?xml version=\\\'1.0\\\'?><speak version=\\\'1.0\\\' xmlns=\\\'http://www.w3.org/2001/10/synthesis\\\' xml:base=\\\'http://localhost/~drew/call/vxml/api/welcome.php\\\' xml:lang=\\\'en\\\'><audio src=\\\"http://www.zitnay.com/stuff/test2.wav\\\" fetchtimeout=\\\"7s\\\" fetchhint=\\\"prefetch\\\"/></speak>\" \"\"\n"
10:03:56:930 DBUG VOICEGLU titan.la callid=[6031] made sound cache request screq=[6818] for play_queued index 0 as: 6818 t=7s - url http://www.zitnay.com/stuff/test2.wav
10:03:56:932 DBUG VOICEGLU titan.la snd "6818 t=7s - url http://www.zitnay.com/stuff/test2.wav\n" to ::MAIN_TO_SC
10:03:56:932 DBUG OPEN_VXI titan.la callid=[6031] VXIpromptPlay()
10:03:56:933 DBUG OPEN_VXI titan.la callid=[6031] snd vg: Play
10:03:56:933 DBUG VOICEGLU titan.la callid=[6031] rcv ovxi: "Play\n"
10:03:56:933 DBUG VOICEGLU titan.la callid=[6031] snd Played to VXML interpreter on fh="::PERL_VXML_6031" at host=localhost callid=[6031]
10:03:56:933 DBUG VOICEGLU titan.la snd "Played\n" to ::PERL_VXML_6031
10:03:56:933 DBUG SNDCACHE titan.la rcv main: "6818 t=7s - url http://www.zitnay.com/stuff/test2.wav\n"
10:03:56:933 DBUG SNDCACHE titan.la screq=[6818] processing url request soundreq=http://www.zitnay.com/stuff/test2.wav path=url/www.zitnay.com/stuff/test2.wav hashname=test2_wav_stuff_www_zitnay_com__http_ host=www.zitnay.com maxage=300 cookies=HASH(0x2939528) timeout=7 for http://www.zitnay.com/stuff/test2.wav
10:03:56:933 DBUG OPEN_VXI titan.la callid=[6031] rcv vg: Played
10:03:56:936 DBUG OPEN_VXI titan.la callid=[6031] VXIpromptPlay()
10:03:56:936 DBUG OPEN_VXI titan.la callid=[6031] snd vg: Play
10:03:56:937 DBUG VOICEGLU titan.la callid=[6031] rcv ovxi: "Play\n"
10:03:56:937 DBUG VOICEGLU titan.la callid=[6031] snd Played to VXML interpreter on fh="::PERL_VXML_6031" at host=localhost callid=[6031]
10:03:56:938 DBUG VOICEGLU titan.la snd "Played\n" to ::PERL_VXML_6031
10:03:56:938 DBUG OPEN_VXI titan.la callid=[6031] rcv vg: Played
10:03:56:938 DBUG OPEN_VXI titan.la callid=[6031] VXIpromptWait()
10:03:56:939 DBUG OPEN_VXI titan.la callid=[6031] snd vg: Wait
10:03:56:939 DBUG VOICEGLU titan.la callid=[6031] rcv ovxi: "Wait\n"
10:03:56:940 DBUG VOICEGLU titan.la callid=[6031] dpal(): do_prompt_and_listen() called
10:03:56:940 DBUG VOICEGLU titan.la callid=[6031] dpal(): Checking for prompts
10:03:56:940 DBUG VOICEGLU titan.la callid=[6031] dpal(): No prompts ready, waiting for more
10:03:56:978 DBUG SNDCACHE titan.la screq=[6818] started pid=563 as curl -q --create-dirs -o /usr/share/asterisk/sounds/voiceglue/url/www.zitnay.com/stuff/test2.wav.tmp -b /usr/share/asterisk/sounds/voiceglue/url/www.zitnay.com/stuff/test2.wav.cookies-snd -c /usr/share/asterisk/sounds/voiceglue/url/www.zitnay.com/stuff/test2.wav.cookies-rcv -D /usr/share/asterisk/sounds/voiceglue/url/www.zitnay.com/stuff/test2.wav.header --stderr /usr/share/asterisk/sounds/voiceglue/url/www.zitnay.com/stuff/test2.wav.err -f -s -S -m 7 http://www.zitnay.com/stuff/test2.wav
10:03:57:985 DBUG VOICEGLU titan.la rcv sc: "6818 1 voiceglue/link/test2_wav_stuff_www_zitnay_com__http_"
10:03:57:985 DBUG VOICEGLU titan.la callid=[6031] dpal(): do_prompt_and_listen() called
10:03:57:986 DBUG VOICEGLU titan.la callid=[6031] dpal(): Checking for prompts
10:03:57:986 DBUG VOICEGLU titan.la callid=[6031] dpal(): Found prompts to play, playing
10:03:57:986 DBUG VOICEGLU titan.la callid=[6031] snd play callid=6031 files=("voiceglue/link/test2_wav_stuff_www_zitnay_com__http_") stopkeys="" to CT server on fh="::CTSRV" at host=localhost
10:03:57:986 DBUG VOICEGLU titan.la snd "play 6031 \"voiceglue/link/test2_wav_stuff_www_zitnay_com__http_\" \"\"\n" to ::CTSRV
10:03:57:986 DBUG SNDCACHE titan.la pid=563 done on url/www.zitnay.com/stuff/test2.wav
10:03:57:986 DBUG SNDCACHE titan.la http://www.zitnay.com/stuff/test2.wav in url/www.zitnay.com/stuff/test2.wav is not cacheable
10:03:57:986 DBUG SNDCACHE titan.la url/www.zitnay.com/stuff/test2.wav content creation succeeded
10:03:57:986 DBUG SNDCACHE titan.la screq=[6818] succeeded for url/www.zitnay.com/stuff/test2.wav returning success (=1)
10:03:57:986 DBUG SNDCACHE titan.la snd "6818 1 voiceglue/link/test2_wav_stuff_www_zitnay_com__http_\n" to ::SC_TO_MAIN
10:03:57:987 DBUG PHONGLUE titan.la rcv ct(::CTCLIENT2): "play 6031 \"voiceglue/link/test2_wav_stuff_www_zitnay_com__http_\" \"\"\n"
10:03:57:987 DBUG PHONGLUE titan.la callid=[6031] parsed play callid=6031 files=("voiceglue/link/test2_wav_stuff_www_zitnay_com__http_") stopkeys=""
10:03:57:987 DBUG PHONGLUE titan.la callid=[6031] snd PLAYFILE file="voiceglue/link/test2_wav_stuff_www_zitnay_com__http_" stopkeys="" to AGI client on fh="::FASTAGI6031" at host=127.0.0.1 callid=[6031]
10:03:57:988 DBUG PHONGLUE titan.la snd "STREAM FILE voiceglue/link/test2_wav_stuff_www_zitnay_com__http_ \"\"\n" to ::FASTAGI6031
10:04:02:480 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: PeerStatus\r\nPrivilege: system,all\r\nPeer: SIP/17035421885\r\nPeerStatus: Registered\r\n\r\n"
10:04:02:847 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: PeerStatus\r\nPrivilege: system,all\r\nPeer: SIP/17035421885\r\nPeerStatus: Registered\r\n\r\n"
10:04:06:124 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: PeerStatus\r\nPrivilege: system,all\r\nPeer: SIP/sameer\r\nPeerStatus: Registered\r\n\r\n"
10:04:06:185 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Newchannel\r\nPrivilege: call,all\r\nChannel: Local/9500\@default-964f,1\r\nState: Down\r\nCallerIDNum: <unknown>\r\nCallerIDName: <unknown>\r\nUniqueid: asterisk-1245074646.10182\r\n\r\n"
10:04:06:201 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Newchannel\r\nPrivilege: call,all\r\nChannel: Local/9500\@default-964f,2\r\nState: Ring\r\nCallerIDNum: <unknown>\r\nCallerIDName: <unknown>\r\nUniqueid: asterisk-1245074646.10183\r\n\r\n"
10:04:06:201 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Newcallerid\r\nPrivilege: call,all\r\nChannel: Local/9500\@default-964f,1\r\nCallerID: <Unknown>\r\nCallerIDName: <Unknown>\r\nUniqueid: asterisk-1245074646.10182\r\nCID-CallingPres: 0 (Presentation Allowed, Not Screened)\r\n\r\n"
10:04:06:201 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Newexten\r\nPrivilege: call,all\r\nChannel: Local/9500\@default-964f,2\r\nContext: default\r\nExtension: 9500\r\nPriority: 1\r\nApplication: AGI\r\nAppData: agi://localhost\r\nUniqueid: asterisk-1245074646.10183\r\n\r\n"
10:04:06:201 INFO PHONGLUE titan.la New AGI connection on fh = ::FASTAGI6032
10:04:06:201 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_network: yes\n"
10:04:06:201 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_network" = "yes"
10:04:06:201 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_request: agi://localhost\n"
10:04:06:201 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_request" = "agi://localhost"
10:04:06:201 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_channel: Local/9500\@default-964f,2\n"
10:04:06:202 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_channel" = "Local/9500@default-964f,2"
10:04:06:202 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_language: en\n"
10:04:06:202 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_language" = "en"
10:04:06:202 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_type: Local\n"
10:04:06:202 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_type" = "Local"
10:04:06:202 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_uniqueid: asterisk-1245074646.10183\n"
10:04:06:202 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_uniqueid" = "asterisk-1245074646.10183"
10:04:06:202 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_callerid: unknown\n"
10:04:06:202 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_callerid" = "unknown"
10:04:06:202 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_calleridname: unknown\n"
10:04:06:203 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_calleridname" = "unknown"
10:04:06:203 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_callingpres: 0\n"
10:04:06:203 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_callingpres" = "0"
10:04:06:203 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_callingani2: 0\n"
10:04:06:203 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_callingani2" = "0"
10:04:06:203 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_callington: 0\n"
10:04:06:203 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_callington" = "0"
10:04:06:203 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_callingtns: 0\n"
10:04:06:203 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_callingtns" = "0"
10:04:06:203 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_dnid: unknown\n"
10:04:06:203 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_dnid" = "unknown"
10:04:06:203 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_rdnis: unknown\n"
10:04:06:204 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_rdnis" = "unknown"
10:04:06:204 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_context: default\n"
10:04:06:204 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_context" = "default"
10:04:06:204 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_extension: 9500\n"
10:04:06:204 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_extension" = "9500"
10:04:06:204 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_priority: 1\n"
10:04:06:204 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_priority" = "1"
10:04:06:204 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_enhanced: 0.0\n"
10:04:06:204 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_enhanced" = "0.0"
10:04:06:204 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "agi_accountcode: 5b638bcf337ed11014a\n"
10:04:06:204 DBUG PHONGLUE titan.la ::FASTAGI6032 initial data "agi_accountcode" = "5b638bcf337ed11014a"
10:04:06:204 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6032): "\n"
10:04:06:205 INFO PHONGLUE titan.la callid=[6032] new incoming assigned to index 0 of 1: CT client on fh="::CTCLIENT2" at host=127.0.0.1 proto=SATC
10:04:06:205 DBUG PHONGLUE titan.la callid=[6032] snd incoming callid=6032 ani="unknown" dnis="9500" arg="" to CT client on fh="::CTCLIENT2" at host=127.0.0.1 proto=SATC
10:04:06:205 DBUG PHONGLUE titan.la snd "incoming 6032 unknown 9500 \"\"\n" to ::CTCLIENT2
10:04:06:205 DBUG VOICEGLU titan.la rcv ctsrv: "incoming 6032 unknown 9500 \"\"\n"
10:04:06:205 DBUG VOICEGLU titan.la callid=[6032] parsed incoming callid=6032 ani="unknown" dnis="9500" arg=""
10:04:06:205 NOTI VOICEGLU titan.la callid=[6032] starting VXML interp on url="http://localhost/examples/welcome-audiofile.vxml" for DNIS="9500" perlfd=13 vxmlfd=14
10:04:06:267 DBUG VOICEGLU titan.la callid=[6032] rcv ovxi: "Queue \"<?xml version=\\\'1.0\\\'?><speak version=\\\'1.0\\\' xmlns=\\\'http://www.w3.org/2001/10/synthesis\\\' xml:base=\\\'http://localhost/examples/welcome-audiofile.vxml\\\' xml:lang=\\\'en\\\'><audio src=\\\"http://localhost/examples/welcome.gsm\\\" fetchtimeout=\\\"7s\\\" fetchhint=\\\"prefetch\\\"/></speak>\" \"\"\n"
10:04:06:269 DBUG VOICEGLU titan.la callid=[6032] made sound cache request screq=[6819] for play_queued index 0 as: 6819 t=7s - url http://localhost/examples/welcome.gsm
10:04:06:270 DBUG VOICEGLU titan.la snd "6819 t=7s - url http://localhost/examples/welcome.gsm\n" to ::MAIN_TO_SC
10:04:06:286 DBUG SNDCACHE titan.la rcv main: "6819 t=7s - url http://localhost/examples/welcome.gsm\n"
10:04:06:286 DBUG SNDCACHE titan.la screq=[6819] processing url request soundreq=http://localhost/examples/welcome.gsm path=url/localhost/examples/welcome.gsm hashname=welcome_gsm_examples_localhost__http_ host= maxage=300 cookies=HASH(0x2944768) timeout=7 for http://localhost/examples/welcome.gsm
10:04:06:286 DBUG SNDCACHE titan.la screq=[6819] retrying past failed attempt
10:04:06:296 DBUG VOICEGLU titan.la callid=[6032] rcv ovxi: "Play\n"
10:04:06:297 DBUG VOICEGLU titan.la callid=[6032] snd Played to VXML interpreter on fh="::PERL_VXML_6032" at host=localhost callid=[6032]
10:04:06:297 DBUG VOICEGLU titan.la snd "Played\n" to ::PERL_VXML_6032
10:04:06:298 NOTI OPEN_VXI titan.la callid=[6032] Channel 6032: Waiting for Call 1
10:04:06:299 DBUG OPEN_VXI titan.la callid=[6032] |140347461589328|6032|60001|testClient::ChannelThread|About to call VXIplatformWaitForCall
10:04:06:299 DBUG OPEN_VXI titan.la callid=[6032] |140347461589328|6032|60001|testClient::ChannelThread|In a Call
10:04:06:300 NOTI OPEN_VXI titan.la callid=[6032] Channel 6032: In a Call
10:04:06:307 DBUG OPEN_VXI titan.la callid=[6032] JsiContext::Create() started
10:04:06:307 DBUG OPEN_VXI titan.la callid=[6032] JsiContext::Create(): JS_THREADSAFE set
10:04:06:308 DBUG OPEN_VXI titan.la callid=[6032] JSDOMDocument::JSInit() started
10:04:06:313 DBUG OPEN_VXI titan.la callid=[6032] JS_InitClass(JSDOMDocument) OK, do: InitNodeObject()
10:04:06:315 DBUG OPEN_VXI titan.la callid=[6032] JsiContext::Create() finished
10:04:06:316 DBUG OPEN_VXI titan.la callid=[6032] VXIpromptQueue called with spec=<?xml version='1.0'?><speak version='1.0' xmlns='http://www.w3.org/2001/10/synthesis' xml:base='http://localhost/examples/welcome-audiofile.vxml' xml:lang='en'><audio src="http://localhost/examples/welcome.gsm" fetchtimeout="7s" fetchhint="prefetch"/></speak>, properties={" absoluteURI"="http://localhost/examples/welcome-audiofile.vxml" " base"="http://localhost/examples/welcome-audiofile.vxml" " encoding"="UTF-8" "audiofetchhint"="prefetch" "bargein"="true" "bargeintype"="speech" "confidencelevel"="0.5" "datafetchhint"="prefetch" "documentfetchhint"="safe" "fetchaudiodelay"="2s" "fetchaudiominimum"="5s" "fetchtimeout"="7s" "grammarfetchhint"="prefetch" "inet.urlBase"="http://localhost/examples/welcome-audiofile.vxml" "inputmodes"="dtmf voice" "maxnbest"="1" "objectfetchhint"="prefetch" "scriptfetchhint"="prefetch" "sensitivity"="0.5" "speedvsaccuracy"="0.5" "swirec_extra_nbest_keys"="" "termchar"="#" "termtimeout"="0s" "universals"="none"}
10:04:06:317 DBUG OPEN_VXI titan.la callid=[6032] VXIpromptQueue (<?xml version='1.0'?><speak version='1.0' xmlns='http://www.w3.org/2001/10/synthesis' xml:base='http://localhost/examples/welcome-audiofile.vxml' xml:lang='en'><audio src="http://localhost/examples/welcome.gsm" fetchtimeout="7s" fetchhint="prefetch"/></speak>, )
10:04:06:317 DBUG OPEN_VXI titan.la callid=[6032] snd vg: Queue "<?xml version=\'1.0\'?><speak version=\'1.0\' xmlns=\'http://www.w3.org/2001/10/synthesis\' xml:base=\'http://localhost/examples/welcome-audiofile.vxml\' xml:lang=\'en\'><audio src=\"http://localhost/examples/welcome.gsm\" fetchtimeout=\"7s\" fetchhint=\"prefetch\"/></speak>" ""
10:04:06:318 DBUG OPEN_VXI titan.la callid=[6032] VXIpromptPlay()
10:04:06:319 DBUG OPEN_VXI titan.la callid=[6032] snd vg: Play
10:04:06:319 DBUG VOICEGLU titan.la callid=[6032] rcv ovxi: "Wait\n"
10:04:06:325 DBUG SNDCACHE titan.la screq=[6819] started pid=597 as curl -q --create-dirs -o /usr/share/asterisk/sounds/voiceglue/url/localhost/examples/welcome.gsm.tmp -b /usr/share/asterisk/sounds/voiceglue/url/localhost/examples/welcome.gsm.cookies-snd -c /usr/share/asterisk/sounds/voiceglue/url/localhost/examples/welcome.gsm.cookies-rcv -D /usr/share/asterisk/sounds/voiceglue/url/localhost/examples/welcome.gsm.header --stderr /usr/share/asterisk/sounds/voiceglue/url/localhost/examples/welcome.gsm.err -f -s -S -m 7 http://localhost/examples/welcome.gsm
10:04:06:326 DBUG VOICEGLU titan.la callid=[6032] dpal(): do_prompt_and_listen() called
10:04:06:327 DBUG VOICEGLU titan.la callid=[6032] dpal(): Checking for prompts
10:04:06:328 DBUG VOICEGLU titan.la callid=[6032] dpal(): No prompts ready, waiting for more
10:04:06:329 DBUG OPEN_VXI titan.la callid=[6032] rcv vg: Played
10:04:06:329 DBUG OPEN_VXI titan.la callid=[6032] VXIpromptWait()
10:04:06:330 DBUG OPEN_VXI titan.la callid=[6032] snd vg: Wait
10:04:06:911 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: PeerStatus\r\nPrivilege: system,all\r\nPeer: SIP/sameer\r\nPeerStatus: Registered\r\n\r\n"
10:04:07:335 DBUG VOICEGLU titan.la rcv sc: "6819 -1 url/localhost/examples/welcome.gsm"
10:04:07:335 DBUG VOICEGLU titan.la callid=[6032] dpal(): do_prompt_and_listen() called
10:04:07:335 DBUG VOICEGLU titan.la callid=[6032] dpal(): Checking for prompts
10:04:07:336 DBUG VOICEGLU titan.la callid=[6032] dpal(): Done with prompts
10:04:07:336 DBUG VOICEGLU titan.la callid=[6032] dpal(): Sending response to wait
10:04:07:336 DBUG VOICEGLU titan.la callid=[6032] dpal() Data Cleared
10:04:07:336 DBUG VOICEGLU titan.la callid=[6032] snd Waited to VXML interpreter on fh="::PERL_VXML_6032" at host=localhost callid=[6032]
10:04:07:336 DBUG VOICEGLU titan.la snd "Waited\n" to ::PERL_VXML_6032
10:04:07:336 DBUG SNDCACHE titan.la pid=597 done on url/localhost/examples/welcome.gsm
10:04:07:336 EROR SNDCACHE titan.la Unsupported Content-Type of "audio/x-gsm" returned for http://localhost/examples/welcome.gsm in url/localhost/examples/welcome.gsm
10:04:07:336 DBUG SNDCACHE titan.la screq=[6819] failed for url/localhost/examples/welcome.gsm looking for fallback
10:04:07:336 DBUG SNDCACHE titan.la screq=[6819] no more fallbacks for url/localhost/examples/welcome.gsm returning failure (=-1)
10:04:07:336 DBUG SNDCACHE titan.la snd "6819 -1 url/localhost/examples/welcome.gsm\n" to ::SC_TO_MAIN
10:04:07:343 INFO VOICEGLU titan.la VXML interpreter filehandle "::PERL_VXML_6032" stopped: code = 0
10:04:07:343 INFO VOICEGLU titan.la callid=[6032] lost its VXML interpreter
10:04:07:343 DBUG VOICEGLU titan.la callid=[6032] deallocating VXML thread
10:04:07:343 NOTI VOICEGLU titan.la callid=[6032] hanging up because VXML interpreter exited
10:04:07:343 DBUG VOICEGLU titan.la callid=[6032] snd hangup to CT server on fh="::CTSRV" at host=localhost
10:04:07:343 DBUG VOICEGLU titan.la snd "hangup 6032\n" to ::CTSRV
10:04:07:343 DBUG OPEN_VXI titan.la callid=[6032] rcv vg: Waited
10:04:07:343 DBUG OPEN_VXI titan.la callid=[6032] |140347461589328|6032|60001|testClient::ChannelThread|NULL result
10:04:07:344 DBUG OPEN_VXI titan.la callid=[6032] |140347461589328|6032|60001|testClient::ChannelThread|Call Terminated
10:04:07:344 NOTI OPEN_VXI titan.la callid=[6032] Channel 6032: Call Terminated
10:04:07:344 DBUG OPEN_VXI titan.la callid=[6032] |140347461589328|-1|3000|SBinetDestroyResource|entering: 0x0x3941870 (0x0x3737c70)
10:04:07:344 DBUG OPEN_VXI titan.la callid=[6032] |140347461589328|-1|3000|SBinetDestroyResource|exiting, returned 0
10:04:07:344 DBUG PHONGLUE titan.la rcv ct(::CTCLIENT2): "hangup 6032\n"
10:04:07:344 DBUG PHONGLUE titan.la callid=[6032] parsed hangup
10:04:07:344 INFO PHONGLUE titan.la AGI client filehandle "::FASTAGI6032" stopped: hangup requested
10:04:07:344 DBUG PHONGLUE titan.la callid=[6032] snd hungup callid=6032 to CT client on fh="::CTCLIENT2" at host=127.0.0.1 proto=SATC
10:04:07:344 DBUG PHONGLUE titan.la snd "hungup 6032\n" to ::CTCLIENT2
10:04:07:345 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Newexten\r\nPrivilege: call,all\r\nChannel: Local/9500\@default-964f,2\r\nContext: default\r\nExtension: 9500\r\nPriority: 2\r\nApplication: Hangup\r\nAppData: \r\nUniqueid: asterisk-1245074646.10183\r\n\r\n"
10:04:07:346 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Hangup\r\nPrivilege: call,all\r\nChannel: Local/9500\@default-964f,2\r\nUniqueid: asterisk-1245074646.10183\r\nCause: 16\r\nCause-txt: Normal Clearing\r\n\r\n"
10:04:07:346 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Hangup\r\nPrivilege: call,all\r\nChannel: Local/9500\@default-964f,1\r\nUniqueid: asterisk-1245074646.10182\r\nCause: 0\r\nCause-txt: Unknown\r\n\r\n"
10:04:07:348 DBUG VOICEGLU titan.la rcv ctsrv: "hungup 6032\n"
10:04:07:348 DBUG VOICEGLU titan.la callid=[6032] parsed hungup callid=6032
10:04:07:402 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: OriginateResponse\r\nPrivilege: call,all\r\nResponse: Failure\r\nChannel: Local/9500\r\nContext: lastpass\r\nExten: 9501\r\nReason: 1\r\nUniqueid: <null>\r\nCallerID: <unknown>\r\nCallerIDNum: <unknown>\r\nCallerIDName: <unknown>\r\n\r\n"
10:04:10:942 DBUG VOICEGLU titan.la rcv ctsrv: "played 6031 0 \"\" 1\n"
10:04:10:942 DBUG VOICEGLU titan.la callid=[6031] parsed played callid=6031 status=0 msg="" reason=end-of-data
10:04:10:942 DBUG VOICEGLU titan.la callid=[6031] dpal(): do_prompt_and_listen() called
10:04:10:942 DBUG VOICEGLU titan.la callid=[6031] dpal(): Sending response to wait
10:04:10:942 DBUG VOICEGLU titan.la callid=[6031] dpal() Data Cleared
10:04:10:942 DBUG VOICEGLU titan.la callid=[6031] snd Waited to VXML interpreter on fh="::PERL_VXML_6031" at host=localhost callid=[6031]
10:04:10:942 DBUG VOICEGLU titan.la snd "Waited\n" to ::PERL_VXML_6031
10:04:10:942 DBUG PHONGLUE titan.la rcv agi(::FASTAGI6031): "200 result=0 endpos=102697\n"
10:04:10:942 DBUG PHONGLUE titan.la callid=[6031] AGI result=0 values: endpos=102697
10:04:10:942 DBUG PHONGLUE titan.la callid=[6031] snd played callid=6031 status=0 msg="" reason=end-of-data to CT client on fh="::CTCLIENT2" at host=127.0.0.1 proto=SATC
10:04:10:943 DBUG PHONGLUE titan.la snd "played 6031 0 \"\" 1\n" to ::CTCLIENT2
10:04:10:945 DBUG OPEN_VXI titan.la callid=[6031] rcv vg: Waited
10:04:10:945 DBUG OPEN_VXI titan.la callid=[6031] |140347469982032|6031|60001|testClient::ChannelThread|NULL result
10:04:10:945 DBUG OPEN_VXI titan.la callid=[6031] |140347469982032|6031|60001|testClient::ChannelThread|Call Terminated
10:04:10:945 NOTI OPEN_VXI titan.la callid=[6031] Channel 6031: Call Terminated
10:04:10:947 DBUG OPEN_VXI titan.la callid=[6031] |140347469982032|-1|3000|SBinetDestroyResource|entering: 0x0x3753570 (0x0x3883550)
10:04:10:948 DBUG OPEN_VXI titan.la callid=[6031] |140347469982032|-1|3000|SBinetDestroyResource|exiting, returned 0
10:04:10:948 INFO VOICEGLU titan.la VXML interpreter filehandle "::PERL_VXML_6031" stopped: code = 0
10:04:10:948 INFO VOICEGLU titan.la callid=[6031] lost its VXML interpreter
10:04:10:948 DBUG VOICEGLU titan.la callid=[6031] deallocating VXML thread
10:04:10:949 NOTI VOICEGLU titan.la callid=[6031] hanging up because VXML interpreter exited
10:04:10:949 DBUG VOICEGLU titan.la callid=[6031] snd hangup to CT server on fh="::CTSRV" at host=localhost
10:04:10:949 DBUG VOICEGLU titan.la snd "hangup 6031\n" to ::CTSRV
10:04:10:950 DBUG PHONGLUE titan.la rcv ct(::CTCLIENT2): "hangup 6031\n"
10:04:10:951 DBUG PHONGLUE titan.la callid=[6031] parsed hangup
10:04:10:952 INFO PHONGLUE titan.la AGI client filehandle "::FASTAGI6031" stopped: hangup requested
10:04:10:952 DBUG PHONGLUE titan.la callid=[6031] snd hungup callid=6031 to CT client on fh="::CTCLIENT2" at host=127.0.0.1 proto=SATC
10:04:10:953 DBUG PHONGLUE titan.la snd "hungup 6031\n" to ::CTCLIENT2
10:04:10:954 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Newexten\r\nPrivilege: call,all\r\nChannel: SIP/sip_proxy-out-01473900\r\nContext: lastpass\r\nExtension: 9501\r\nPriority: 2\r\nApplication: Hangup\r\nAppData: \r\nUniqueid: asterisk-1245074632.10180\r\n\r\n"
10:04:10:954 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: Hangup\r\nPrivilege: call,all\r\nChannel: SIP/sip_proxy-out-01473900\r\nUniqueid: asterisk-1245074632.10180\r\nCause: 16\r\nCause-txt: Normal Clearing\r\n\r\n"
10:04:10:956 DBUG VOICEGLU titan.la rcv ctsrv: "hungup 6031\n"
10:04:10:956 DBUG VOICEGLU titan.la callid=[6031] parsed hungup callid=6031
10:04:13:925 DBUG PHONGLUE titan.la rcv mgr(::ASTMGR): "Event: PeerStatus\r\nPrivilege: system,all\r\nPeer: SIP/17035421886\r\nPeerStatus: Registered\r\n\r\n"