Created
March 20, 2012 09:52
-
-
Save benlangfeld/2133592 to your computer and use it in GitHub Desktop.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| {9:51}[ruby-1.9.3]~/code/VoIP/adhearsion/testapps/general ben% be ahn - | |
| Starting Adhearsion server at /Users/ben/code/VoIP/adhearsion/testapps/general | |
| [2012-03-20 09:52:00] WARN Adhearsion::LinuxProcName: Error while attaching libc function prctl: Function 'prctl' not found in [libc.dylib] | |
| [2012-03-20 09:52:00] INFO Adhearsion::Initializer: Setting RAILS_ENV to "development" | |
| [2012-03-20 09:52:01] INFO Adhearsion::PunchblockPlugin::Initializer: Starting connection to server | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: USING JID: usera@127.0.0.1/blmbp.home-28910 | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/stream/client.rb:21:in `start') <stream:stream to='127.0.0.1' xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en' > | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: RECEIVING (stream) <stream:stream xmlns:db="jabber:server:dialback" xmlns:stream="http://etherx.jabber.org/streams" from="127.0.0.1" id="xmpps_l0328mignyvl" lang="en" version="1.0"/> | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: RECEIVING (features) <stream:features xmlns:stream="http://etherx.jabber.org/streams"> | |
| <mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"> | |
| <mechanism>PLAIN</mechanism> | |
| </mechanisms> | |
| </stream:features> | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/stream/features/sasl.rb:177:in `authenticate') <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">dXNlcmFAMTI3LjAuMC4xAHVzZXJhADE=</auth> | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: RECEIVING (success) <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/> | |
| [2012-03-20 09:52:01] INFO Adhearsion::Console: Launching Adhearsion Console | |
| AHN> [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/stream/client.rb:21:in `start') <stream:stream to='127.0.0.1' xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en' > | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: RECEIVING (stream) <stream:stream xmlns:db="jabber:server:dialback" xmlns:stream="http://etherx.jabber.org/streams" from="127.0.0.1" id="xmpps_l0328mignyvl" lang="en" version="1.0"/> | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: RECEIVING (features) <stream:features xmlns:stream="http://etherx.jabber.org/streams"> | |
| <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/> | |
| <session xmlns="urn:ietf:params:xml:ns:xmpp-session"/> | |
| </stream:features> | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/stream/features/resource.rb:39:in `bind') <iq type="set" id="blather0002"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource>blmbp.home-28910</resource></bind></iq> | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="127.0.0.1" id="blather0002" to="usera@127.0.0.1" type="result"> | |
| <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"> | |
| <jid>usera@127.0.0.1/blmbp.home-28910</jid> | |
| </bind> | |
| </iq> | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: USING JID: usera@127.0.0.1/blmbp.home-28910 | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/stream/features/session.rb:40:in `session') <iq type="set" id="blather0004" to="127.0.0.1"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="127.0.0.1" id="blather0004" to="usera@127.0.0.1/blmbp.home-28910" type="result"/> | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/client/client.rb:149:in `write') <iq type="get" id="blather0006"><query xmlns="jabber:iq:roster"/></iq> | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="127.0.0.1" id="blather0006" to="usera@127.0.0.1/blmbp.home-28910" type="error"> | |
| <query xmlns="jabber:iq:roster"/> | |
| <error type="cancel"> | |
| <feature-not-implemented xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/> | |
| <text xmlns="urn:ietf:params:xml:ns:xmpp-stanzas" lang="en">Feature not supported</text> | |
| </error> | |
| </iq> | |
| [2012-03-20 09:52:01] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/client/client.rb:149:in `write') <presence/> | |
| [2012-03-20 09:52:01] INFO Punchblock::Connection::XMPP: Connected to XMPP as usera@127.0.0.1/blmbp.home-28910 | |
| [2012-03-20 09:52:01] INFO Adhearsion::PunchblockPlugin::Initializer: Connected to Punchblock server | |
| [2012-03-20 09:52:01] INFO Adhearsion::Process: Transitioning from booting to running with 0 active calls due to booted event. | |
| [2012-03-20 09:52:01] INFO Adhearsion::Initializer: Adhearsion v2.0.0.beta1 initialized in "development"! | |
| [2012-03-20 09:52:04] TRACE Punchblock::Connection::XMPP: RECEIVING (presence) <presence from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="041c9bc9-7e50-4c5e-a36a-4fa666c46c33" to="usera@127.0.0.1"> | |
| <offer xmlns="urn:xmpp:rayo:1" from="sip:rwbqgpia@192.168.1.73" to="sip:usera@127.0.0.1"> | |
| <header name="Max-Forwards" value="70"/> | |
| <header name="Content-Length" value="342"/> | |
| <header name="Contact" value="<sip:rwbqgpia@127.0.0.1:59615>"/> | |
| <header name="Supported" value="100rel"/> | |
| <header name="Allow" value="SUBSCRIBE"/> | |
| <header name="To" value="<sip:usera@127.0.0.1>"/> | |
| <header name="CSeq" value="22123 INVITE"/> | |
| <header name="User-Agent" value="Blink 0.24.1 (MacOSX)"/> | |
| <header name="Via" value="SIP/2.0/UDP 192.168.1.72:59615;rport=59615;branch=z9hG4bKPjE.KMjdg80mb40oy1nHXQiQ.unbXxr31K;received=127.0.0.1"/> | |
| <header name="Call-ID" value="T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u"/> | |
| <header name="Content-Type" value="application/sdp"/> | |
| <header name="From" value=""Ben Langfeld" <sip:rwbqgpia@192.168.1.73>;tag=c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL"/> | |
| </offer> | |
| </presence> | |
| [2012-03-20 09:52:04] DEBUG Adhearsion::Call: : Receiving message: #<Punchblock::Event::Offer to="sip:usera@127.0.0.1", from="sip:rwbqgpia@192.168.1.73", call_id="4vg6dkqc-lx7-fxod8zouyy3mb" | |
| [2012-03-20 09:52:04] DEBUG Adhearsion::Call: 4vg6dkqc-lx7-fxod8zouyy3mb: Executing command #<Punchblock::Command::Accept headers_hash={}, call_id=nil, component_id=nil> | |
| [2012-03-20 09:52:04] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/client/client.rb:149:in `write') <iq type="set" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather0008"><accept xmlns="urn:xmpp:rayo:1"/></iq> | |
| [2012-03-20 09:52:04] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather0008" to="usera@127.0.0.1/blmbp.home-28910" type="result"/> | |
| [2012-03-20 09:52:04] DEBUG Adhearsion::Router: Call 4vg6dkqc-lx7-fxod8zouyy3mb selected route "default" (#<Proc:0x00000100939b20@/Users/ben/code/VoIP/adhearsion/testapps/general/config/adhearsion.rb:6>) | |
| [2012-03-20 09:52:04] DEBUG Adhearsion::Call: 4vg6dkqc-lx7-fxod8zouyy3mb: Executing command #<Punchblock::Command::Answer headers_hash={}, call_id=nil, component_id=nil> | |
| [2012-03-20 09:52:04] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/client/client.rb:149:in `write') <iq type="set" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather000a"><answer xmlns="urn:xmpp:rayo:1"/></iq> | |
| [2012-03-20 09:52:04] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather000a" to="usera@127.0.0.1/blmbp.home-28910" type="result"/> | |
| [2012-03-20 09:52:04] DEBUG Adhearsion::Call: 4vg6dkqc-lx7-fxod8zouyy3mb: Receiving message: #<Punchblock::Event::Offer to="sip:usera@127.0.0.1", from="sip:rwbqgpia@192.168.1.73", call_id="4vg6dkqc-lx7-fxod8zouyy3mb" | |
| [2012-03-20 09:52:05] DEBUG Adhearsion::Call: 4vg6dkqc-lx7-fxod8zouyy3mb: Executing command #<Punchblock::Component::Output voice=nil, ssml="digits/3", call_id=nil, component_id=nil, interrupt_on=nil, start_offset=nil, start_paused=false, repeat_interval=nil, repeat_times=nil, max_time=nil> | |
| [2012-03-20 09:52:05] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/client/client.rb:149:in `write') <iq type="set" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather000c"><output xmlns="urn:xmpp:rayo:output:1">digits/3</output></iq> | |
| [2012-03-20 09:52:05] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather000c" to="usera@127.0.0.1/blmbp.home-28910" type="result"> | |
| <ref xmlns="urn:xmpp:rayo:1" id="eb5f6969-d096-4e40-97be-4fbece5c1c43"/> | |
| </iq> | |
| [2012-03-20 09:52:06] TRACE Punchblock::Connection::XMPP: RECEIVING (presence) <presence from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home/eb5f6969-d096-4e40-97be-4fbece5c1c43" id="579ced25-c02c-4e2a-8dae-8ea3b9f13b86" to="usera@127.0.0.1"> | |
| <complete xmlns="urn:xmpp:rayo:ext:1"> | |
| <success xmlns="urn:xmpp:rayo:output:complete:1"/> | |
| </complete> | |
| </presence> | |
| [2012-03-20 09:52:06] DEBUG Adhearsion::Call: 4vg6dkqc-lx7-fxod8zouyy3mb: Executing command #<Punchblock::Component::Output voice=nil, ssml=<speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"> | |
| <audio src="http://static1.grsites.com/archive/sounds/aircraft/aircraft001.mp3"/> | |
| </speak>, call_id=nil, component_id=nil, interrupt_on=nil, start_offset=nil, start_paused=false, repeat_interval=nil, repeat_times=nil, max_time=nil> | |
| [2012-03-20 09:52:06] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/client/client.rb:149:in `write') <iq type="set" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather000e"><output xmlns="urn:xmpp:rayo:output:1"><speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"><audio src="http://static1.grsites.com/archive/sounds/aircraft/aircraft001.mp3"/></speak></output></iq> | |
| [2012-03-20 09:52:06] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather000e" to="usera@127.0.0.1/blmbp.home-28910" type="result"> | |
| <ref xmlns="urn:xmpp:rayo:1" id="92f9a63d-6783-40b8-b076-0a9d44871f91"/> | |
| </iq> | |
| [2012-03-20 09:52:06] DEBUG Adhearsion::Call: 4vg6dkqc-lx7-fxod8zouyy3mb: Receiving message: #<Punchblock::Event::Complete reason=#<Punchblock::Component::Output::Complete::Success name=:success, call_id="4vg6dkqc-lx7-fxod8zouyy3mb", component_id="eb5f6969-d096-4e40-97be-4fbece5c1c43">, recording=nil, call_id="4vg6dkqc-lx7-fxod8zouyy3mb", component_id="eb5f6969-d096-4e40-97be-4fbece5c1c43"> | |
| [2012-03-20 09:52:11] TRACE Punchblock::Connection::XMPP: RECEIVING (presence) <presence from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home/92f9a63d-6783-40b8-b076-0a9d44871f91" id="05a322d7-a2ce-4c72-8d76-ed8dad54680f" to="usera@127.0.0.1"> | |
| <complete xmlns="urn:xmpp:rayo:ext:1"> | |
| <success xmlns="urn:xmpp:rayo:output:complete:1"/> | |
| </complete> | |
| </presence> | |
| [2012-03-20 09:52:11] DEBUG Adhearsion::Call: 4vg6dkqc-lx7-fxod8zouyy3mb: Executing command #<Punchblock::Component::Output voice=nil, ssml=<speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"> | |
| <audio src="digits/3"/> | |
| </speak>, call_id=nil, component_id=nil, interrupt_on=nil, start_offset=nil, start_paused=false, repeat_interval=nil, repeat_times=nil, max_time=nil> | |
| [2012-03-20 09:52:11] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/client/client.rb:149:in `write') <iq type="set" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather0010"><output xmlns="urn:xmpp:rayo:output:1"><speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"><audio src="digits/3"/></speak></output></iq> | |
| [2012-03-20 09:52:11] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather0010" to="usera@127.0.0.1/blmbp.home-28910" type="result"> | |
| <ref xmlns="urn:xmpp:rayo:1" id="f8440d4f-464b-43d9-b48c-3ec686268457"/> | |
| </iq> | |
| [2012-03-20 09:52:11] DEBUG Adhearsion::Call: 4vg6dkqc-lx7-fxod8zouyy3mb: Receiving message: #<Punchblock::Event::Complete reason=#<Punchblock::Component::Output::Complete::Success name=:success, call_id="4vg6dkqc-lx7-fxod8zouyy3mb", component_id="92f9a63d-6783-40b8-b076-0a9d44871f91">, recording=nil, call_id="4vg6dkqc-lx7-fxod8zouyy3mb", component_id="92f9a63d-6783-40b8-b076-0a9d44871f91"> | |
| [2012-03-20 09:52:11] TRACE Punchblock::Connection::XMPP: RECEIVING (presence) <presence from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home/f8440d4f-464b-43d9-b48c-3ec686268457" id="53797fbe-284b-4138-8f41-7886a7f64b0d" to="usera@127.0.0.1"> | |
| <complete xmlns="urn:xmpp:rayo:ext:1"> | |
| <error xmlns="urn:xmpp:rayo:ext:complete:1">Invalid SSML: The prefix "xml" cannot be bound to any namespace other than its usual namespace; neither can the namespace for "xml" be bound to any prefix other than "xml".</error> | |
| </complete> | |
| </presence> | |
| [2012-03-20 09:52:11] DEBUG Adhearsion::Call: 4vg6dkqc-lx7-fxod8zouyy3mb: Receiving message: #<Punchblock::Event::Complete reason=#<Punchblock::Event::Complete::Error details="Invalid SSML: The prefix \"xml\" cannot be bound to any namespace other than its usual namespace; neither can the namespace for \"xml\" be bound to any prefix other than \"xml\".", name=:error, call_id="4vg6dkqc-lx7-fxod8zouyy3mb", component_id="f8440d4f-464b-43d9-b48c-3ec686268457">, recording=nil, call_id="4vg6dkqc-lx7-fxod8zouyy3mb", component_id="f8440d4f-464b-43d9-b48c-3ec686268457"> | |
| [2012-03-20 09:52:11] ERROR Adhearsion::Call: 4vg6dkqc-lx7-fxod8zouyy3mb: <StandardError> Invalid SSML: The prefix "xml" cannot be bound to any namespace other than its usual namespace; neither can the namespace for "xml" be bound to any prefix other than "xml".: #<Punchblock::Component::Output voice=nil, ssml=<speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"> | |
| <audio src="digits/3"/> | |
| </speak>, call_id="4vg6dkqc-lx7-fxod8zouyy3mb", component_id="f8440d4f-464b-43d9-b48c-3ec686268457", interrupt_on=nil, start_offset=nil, start_paused=false, repeat_interval=nil, repeat_times=nil, max_time=nil> | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller.rb:118:in `execute_component_and_await_completion' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller/output.rb:124:in `output' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller/output.rb:118:in `play_ssml' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller/output.rb:185:in `play_ssml_for' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller/output.rb:46:in `block in play' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller/output.rb:39:in `each' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller/output.rb:39:in `inject' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller/outpu[2012-03-20 09:52:11] DEBUG Adhearsion::Call: 4vg6dkqc-lx7-fxod8zouyy3mb: Executing command #<Punchblock::Command::Hangup headers_hash={}, call_id=nil, component_id=nil> | |
| [2012-03-20 09:52:11] TRACE Punchblock::Connection::XMPP: SENDING: (/Users/ben/code/VoIP/adhearsion/testapps/general/vendor/ruby/1.9.1/gems/blather-0.7.0/lib/blather/client/client.rb:149:in `write') <iq type="set" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather0012"><hangup xmlns="urn:xmpp:rayo:1"/></iq> | |
| t.rb:39:in `play' | |
| /Users/ben/code/VoIP/adhearsion/testapps/general/config/adhearsion.rb:10:in `block (2 levels) in <top (required)>' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller.rb:77:in `instance_exec' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller.rb:77:in `run' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller.rb:67:in `execute!' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller.rb:41:in `block in exec' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller.rb:40:in `catch' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call_controller.rb:40:in `exec' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call.rb:262:in `block (2 levels) in execute_controller' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/foundation/exception_handler.rb:6:in `catching_standard_errors' | |
| /Users/ben/code/VoIP/adhearsion/core/lib/adhearsion/call.rb:260:in `block in execute_controller' | |
| [2012-03-20 09:52:11] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather0012" to="usera@127.0.0.1/blmbp.home-28910" type="result"/> | |
| [2012-03-20 09:52:11] TRACE Punchblock::Connection::XMPP: RECEIVING (presence) <presence from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="417b829a-1af7-4de2-94ce-b43134d08e15" to="usera@127.0.0.1"> | |
| <end xmlns="urn:xmpp:rayo:1"> | |
| <hangup/> | |
| </end> | |
| </presence> | |
| [2012-03-20 09:52:11] DEBUG Adhearsion::Call: 4vg6dkqc-lx7-fxod8zouyy3mb: Receiving message: #<Punchblock::Event::End reason=:hangup, headers_hash={}, call_id="4vg6dkqc-lx7-fxod8zouyy3mb", component_id=nil> |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| 2012-03-20 09:51:53.856 DEBUG [Timer-19] Reading JID Lookup Service configuration from disk [rayo-routing.properties] | |
| 2012-03-20 09:52:00.433 DEBUG [Timer-16] #SIP#: NonInviteServerTransaction[, , _state=COMPLETED, _id=z9hG4bKPj0ydf7nvUTkp5N01pqpCEdeqwJfxwFENZ, ] timerRemoveTransaction is fired. #[rayo][sas_2-14-smcie0vnntm7l6rayo][R.HJZ7wtTq45V045uWw8hyBEss1oBgBl][ss_xa80qogedq98][sip:1234@127.0.0.1(127.0.0.1:59615)][sip:1234@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:00.433 DEBUG [Timer-16] #SIP#: NonInviteServerTransaction[, , _state=TERMINATED, _id=z9hG4bKPj0ydf7nvUTkp5N01pqpCEdeqwJfxwFENZ, ] is released. #[rayo][sas_2-14-smcie0vnntm7l6rayo][R.HJZ7wtTq45V045uWw8hyBEss1oBgBl][ss_xa80qogedq98][sip:1234@127.0.0.1(127.0.0.1:59615)][sip:1234@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:01.218 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: Creating xmpp session with app: ApplicationImpl[_symbolicName=rayo-0, _state=STARTED, ] #[N/A][N/A][N/A][N/A][?, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.219 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: Created session: XMPPSessionImpl: _id=xmpps_l0328mignyvl, _direction=RECEIVEStream, _sessionType=CLIENT, _remotJID=null, _state=INITIAL, _remoteAddr=/127.0.0.1, _remotePort=59745, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=rayo-0, _state=STARTED, ] #[N/A][N/A][N/A][N/A][?, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.220 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" to="127.0.0.1" version="1.0" xml:lang="en"> #[rayo][null][xmpps_l0328mignyvl][CLIENT][?, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.223 DEBUG [XMPPService-t-24] #XMPP#: (o)<stream:stream xmlns="jabber:client" xmlns:db="jabber:server:dialback" from="127.0.0.1" id="xmpps_l0328mignyvl" xml:lang="en" version="1.0" xmlns:stream="http://etherx.jabber.org/streams"> #[rayo][null][xmpps_l0328mignyvl][CLIENT][?, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.223 DEBUG [XMPPService-t-24] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][?, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.225 DEBUG [XMPPService-t-24] #XMPP#: (o)<stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism></mechanisms></stream:features> #[rayo][null][xmpps_l0328mignyvl][CLIENT][?, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.225 DEBUG [XMPPService-t-24] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][?, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.297 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">dXNlcmFAMTI3LjAuMC4xAHVzZXJhADE=</auth> #[rayo][null][xmpps_l0328mignyvl][CLIENT][?, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.301 DEBUG [XMPPService-t-25] #XMPP#: (o)<success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/> #[rayo][null][xmpps_l0328mignyvl][CLIENT][?, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.301 DEBUG [XMPPService-t-25] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][?, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.321 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" to="127.0.0.1" version="1.0" xml:lang="en"> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.323 DEBUG [XMPPService-t-26] #XMPP#: (o)<stream:stream xmlns="jabber:client" xmlns:db="jabber:server:dialback" from="127.0.0.1" id="xmpps_l0328mignyvl" xml:lang="en" version="1.0" xmlns:stream="http://etherx.jabber.org/streams"> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.324 DEBUG [XMPPService-t-26] #XMPP#: Session :XMPPSessionImpl: _id=xmpps_l0328mignyvl, _direction=RECEIVEStream, _sessionType=CLIENT, _remotJID=usera@127.0.0.1, _state=CONFIRMED, _remoteAddr=/127.0.0.1, _remotePort=59745, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=rayo-0, _state=STARTED, ] negotiatied. The result is:true | |
| 2012-03-20 09:52:01.324 DEBUG [XMPPService-t-26] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.325 DEBUG [XMPPService-t-26] #XMPP#: (o)<stream:features><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></stream:features> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.325 DEBUG [XMPPService-t-26] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.328 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq id="blather0002" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource>blmbp.home-28910</resource></bind></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.330 DEBUG [XMPPService-t-27] #XMPP#: Intercept iq bind result, set full jid usera@127.0.0.1/blmbp.home-28910 to session XMPPSessionImpl: _id=xmpps_l0328mignyvl, _direction=RECEIVEStream, _sessionType=CLIENT, _remotJID=usera@127.0.0.1/blmbp.home-28910, _state=CONFIRMED, _remoteAddr=/127.0.0.1, _remotePort=59745, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=rayo-0, _state=STARTED, ] #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.332 DEBUG [XMPPService-t-27] #XMPP#: (o)<iq from="127.0.0.1" id="blather0002" to="usera@127.0.0.1" type="result"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>usera@127.0.0.1/blmbp.home-28910</jid></bind></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.332 DEBUG [XMPPService-t-27] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.333 DEBUG [XMPPService-t-27] #XMPP#: Session :XMPPSessionImpl: _id=xmpps_l0328mignyvl, _direction=RECEIVEStream, _sessionType=CLIENT, _remotJID=usera@127.0.0.1/blmbp.home-28910, _state=CONFIRMED, _remoteAddr=/127.0.0.1, _remotePort=59745, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=rayo-0, _state=STARTED, ] negotiatied. The result is:true | |
| 2012-03-20 09:52:01.334 DEBUG [XMPPService-t-27] Xmpp Session created | |
| 2012-03-20 09:52:01.335 DEBUG [XMPPService-t-27] Returning cached instance of singleton bean 'callRegistry' | |
| 2012-03-20 09:52:01.336 DEBUG [XMPPService-t-27] Returning cached instance of singleton bean 'jidRegistry' | |
| 2012-03-20 09:52:01.337 DEBUG [XMPPService-t-27] Returning cached instance of singleton bean 'sessionCleanupConfig' | |
| 2012-03-20 09:52:01.337 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq id="blather0004" to="127.0.0.1" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.338 DEBUG [XMPPService-t-28] #XMPP#: Invoke application:rayo null | |
| 2012-03-20 09:52:01.338 DEBUG [XMPPService-t-28] #XMPP#: Forwarding Request #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][null] | |
| 2012-03-20 09:52:01.339 DEBUG [XMPPService-t-28] <iq from="usera@127.0.0.1/blmbp.home-28910" id="blather0004" to="127.0.0.1" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> :: xmpps_l0328mignyvl | |
| 2012-03-20 09:52:01.341 DEBUG [XMPPService-t-28] #XMPP#: (o)<iq from="127.0.0.1" id="blather0004" to="usera@127.0.0.1/blmbp.home-28910" type="result"/> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.341 DEBUG [XMPPService-t-28] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.345 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq id="blather0006" type="get"><query xmlns="jabber:iq:roster"/></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.346 DEBUG [XMPPService-t-29] #XMPP#: Invoke application:rayo rayo | |
| 2012-03-20 09:52:01.346 DEBUG [XMPPService-t-29] #XMPP#: Forwarding Request #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][null] | |
| 2012-03-20 09:52:01.347 DEBUG [XMPPService-t-29] <iq from="usera@127.0.0.1/blmbp.home-28910" id="blather0006" to="127.0.0.1" type="get"><query xmlns="jabber:iq:roster"/></iq> :: xmpps_l0328mignyvl | |
| 2012-03-20 09:52:01.348 DEBUG [XMPPService-t-29] #XMPP#: (o)<iq from="127.0.0.1" id="blather0006" to="usera@127.0.0.1/blmbp.home-28910" type="error"><query xmlns="jabber:iq:roster"/><error type="cancel"><feature-not-implemented xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/><text xml:lang="en" xmlns="urn:ietf:params:xml:ns:xmpp-stanzas">Feature not supported</text></error></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.349 DEBUG [XMPPService-t-29] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.492 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<presence id="fc313c5f-3534-48e3-9998-ab1ebf73b5af"/> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:01.493 DEBUG [XMPPService-t-30] #XMPP#: Invoke application:rayo rayo | |
| 2012-03-20 09:52:01.493 DEBUG [XMPPService-t-30] #XMPP#: Forwarding Request #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][null] | |
| 2012-03-20 09:52:01.493 DEBUG [XMPPService-t-30] <presence from="usera@127.0.0.1/blmbp.home-28910" id="fc313c5f-3534-48e3-9998-ab1ebf73b5af" to="127.0.0.1"/> :: xmpps_l0328mignyvl | |
| 2012-03-20 09:52:01.494 WARN [XMPPService-t-30] Ignoring unknown presence message | |
| 2012-03-20 09:52:04.501 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[INVITE sip:usera@127.0.0.1 SIP/2.0\r\nContent-Type: application/sdp\r\nTo: <sip:usera@127.0.0.1>\r\nVia: SIP/2.0/UDP 192.168.1.72:59615;rport;branch=z9hG4bKPjE.KMjdg80mb40oy1nHXQiQ.unbXxr31K\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nCSeq: 22123 INVITE\r\nContent-Length: 342\r\nSupported: 100rel, norefersub\r\nCall-ID: T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u\r\nUser-Agent: Blink 0.24.1 (MacOSX)\r\nFrom: "Ben Langfeld" <sip:rwbqgpia@192.168.1.73>;tag=c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL\r\nMax-Forwards: 70\r\nContact: <sip:rwbqgpia@127.0.0.1:59615>\r\n\r\nv=0\r\no=- 3541225924 3541225924 IN IP4 127.0.0.1\r\ns=Blink 0.24.1 (MacOSX)\r\nc=IN IP4 127.0.0.1\r\nt=0 0\r\nm=audio 50068 RTP/AVP 9 104 103 102 3 101\r\na=rtcp:50069\r\na=rtpmap:9 G722/8000\r\na=rtpmap:104 speex/32000\r\na=rtpmap:103 speex/16000\r\na=rtpmap:102 speex/8000\r\na=rtpmap:3 GSM/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n] #[N/A][N/A][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][N/A][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.502 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: The transaction was created: z9hG4bKPjE.KMjdg80mb40oy1nHXQiQ.unbXxr31K #[N/A][N/A][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][N/A][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.503 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (o)[SIP/2.0 100 Trying\r\nTo: <sip:usera@127.0.0.1>\r\nVia: SIP/2.0/UDP 192.168.1.72:59615;rport=59615;branch=z9hG4bKPjE.KMjdg80mb40oy1nHXQiQ.unbXxr31K;received=127.0.0.1\r\nCSeq: 22123 INVITE\r\nContent-Length: 0\r\nCall-ID: T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u\r\nFrom: "Ben Langfeld" <sip:rwbqgpia@192.168.1.73>;tag=c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL\r\n\r\n] #[N/A][N/A][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][N/A][sip:usera@127.0.0.1(127.0.0.1:59615)][sip:rwbqgpia@192.168.1.73(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.503 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Send message to: /127.0.0.1:59615 by udp #[N/A][N/A][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][N/A][sip:usera@127.0.0.1(127.0.0.1:59615)][sip:rwbqgpia@192.168.1.73(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.504 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Connected to 127.0.0.1:59615/udp #[N/A][N/A][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][N/A][sip:usera@127.0.0.1(127.0.0.1:59615)][sip:rwbqgpia@192.168.1.73(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.504 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Found [rayo] to handle the request by port mappings: 5060 | |
| 2012-03-20 09:52:04.504 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipApplicationInfo: SipApplicationRouterInfo[ApplicationName=rayo, RouteModifier=NO_ROUTE, RouteRegion=null, SubscriberURI=sip:usera@127.0.0.1, StateInfo=rayo] #[N/A][N/A][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][N/A][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.505 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Session creating: ss_1hrqgtdr2wdid #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.506 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Session created:SipSessionImpl[_id=ss_1hrqgtdr2wdid, _parentId=sas_2-15-sm1i1a8cbvif5iarayo, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UNKNOW, _method=INVITE, _callId=T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, ] #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.506 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv request: INVITE #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.506 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ApplicationDispatchLayer invoke application: Controller with INVITE #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.507 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.507 DEBUG [udp/0.0.0.0/5060-t-3] Returning cached instance of singleton bean 'com.voxeo.moho.sip.IncomingCallFactoryImpl#0' | |
| 2012-03-20 09:52:04.509 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1i1a8cbvif5iarayo], invalidateWhenReady: true | |
| 2012-03-20 09:52:04.509 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_1hrqgtdr2wdid], current State = INITIAL, Vaild:true, Role:UNKNOW, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.509 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1i1a8cbvif5iarayo], invalidateWhenReady: true | |
| 2012-03-20 09:52:04.510 DEBUG [MOHO-21] Dispatching Event to listener:SIPCallImpl[SipSessionAdaptor[sessionid=ss_1hrqgtdr2wdid, appSessionId=sas_2-15-sm1i1a8cbvif5iarayo, ],INVITING] | |
| 2012-03-20 09:52:04.510 DEBUG [MOHO-21] Received incoming call | |
| 2012-03-20 09:52:04.510 DEBUG [MOHO-21] Creating CDR for call id [4vg6dkqc-lx7-fxod8zouyy3mb] | |
| 2012-03-20 09:52:04.511 INFO [pool-21-thread-2] Message [SIPCallImpl[SipSessionAdaptor[sessionid=ss_1hrqgtdr2wdid, appSessionId=sas_2-15-sm1i1a8cbvif5iarayo, ],INVITING]] | |
| 2012-03-20 09:52:04.511 INFO [pool-21-thread-2] Incoming Call [SIPCallImpl[SipSessionAdaptor[sessionid=ss_1hrqgtdr2wdid, appSessionId=sas_2-15-sm1i1a8cbvif5iarayo, ],INVITING]] | |
| 2012-03-20 09:52:04.511 DEBUG [pool-21-thread-2] Creating call actor for call [4vg6dkqc-lx7-fxod8zouyy3mb] | |
| 2012-03-20 09:52:04.515 DEBUG [pool-21-thread-2] Adding call [4vg6dkqc-lx7-fxod8zouyy3mb] to registry: [com.rayo.server.DefaultCallRegistry@491a97] | |
| 2012-03-20 09:52:04.516 INFO [pool-21-thread-3] Message [SIPCallImpl[SipSessionAdaptor[sessionid=ss_1hrqgtdr2wdid, appSessionId=sas_2-15-sm1i1a8cbvif5iarayo, ],INVITING]] | |
| 2012-03-20 09:52:04.519 INFO [pool-21-thread-3] Queued Event [OfferEvent[from=sip:rwbqgpia@192.168.1.73,to=sip:usera@127.0.0.1,headers={Max-Forwards=70, Content-Length=342, Contact=<sip:rwbqgpia@127.0.0.1:59615>, Supported=100rel, Allow=SUBSCRIBE, To=<sip:usera@127.0.0.1>, CSeq=22123 INVITE, User-Agent=Blink 0.24.1 (MacOSX), Via=SIP/2.0/UDP 192.168.1.72:59615;rport=59615;branch=z9hG4bKPjE.KMjdg80mb40oy1nHXQiQ.unbXxr31K;received=127.0.0.1, Call-ID=T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, Content-Type=application/sdp, From="Ben Langfeld" <sip:rwbqgpia@192.168.1.73>;tag=c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL}]] | |
| 2012-03-20 09:52:04.519 INFO [pool-21-thread-3] Event [OfferEvent[from=sip:rwbqgpia@192.168.1.73,to=sip:usera@127.0.0.1,headers={Max-Forwards=70, Content-Length=342, Contact=<sip:rwbqgpia@127.0.0.1:59615>, Supported=100rel, Allow=SUBSCRIBE, To=<sip:usera@127.0.0.1>, CSeq=22123 INVITE, User-Agent=Blink 0.24.1 (MacOSX), Via=SIP/2.0/UDP 192.168.1.72:59615;rport=59615;branch=z9hG4bKPjE.KMjdg80mb40oy1nHXQiQ.unbXxr31K;received=127.0.0.1, Call-ID=T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, Content-Type=application/sdp, From="Ben Langfeld" <sip:rwbqgpia@192.168.1.73>;tag=c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL}]] | |
| 2012-03-20 09:52:04.521 DEBUG [pool-21-thread-3] Found a match for sip:usera@127.0.0.1 : usera@127.0.0.1 | |
| 2012-03-20 09:52:04.521 DEBUG [pool-21-thread-3] Received Offer. Offer will be delivered to [usera@127.0.0.1] | |
| 2012-03-20 09:52:04.526 DEBUG [pool-21-thread-3] #XMPP#: (o)<presence from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="041c9bc9-7e50-4c5e-a36a-4fa666c46c33" to="usera@127.0.0.1"><offer xmlns="urn:xmpp:rayo:1" from="sip:rwbqgpia@192.168.1.73" to="sip:usera@127.0.0.1"><header name="Max-Forwards" value="70"/><header name="Content-Length" value="342"/><header name="Contact" value="<sip:rwbqgpia@127.0.0.1:59615>"/><header name="Supported" value="100rel"/><header name="Allow" value="SUBSCRIBE"/><header name="To" value="<sip:usera@127.0.0.1>"/><header name="CSeq" value="22123 INVITE"/><header name="User-Agent" value="Blink 0.24.1 (MacOSX)"/><header name="Via" value="SIP/2.0/UDP 192.168.1.72:59615;rport=59615;branch=z9hG4bKPjE.KMjdg80mb40oy1nHXQiQ.unbXxr31K;received=127.0.0.1"/><header name="Call-ID" value="T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u"/><header name="Content-Type" value="application/sdp"/><header name="From" value=""Ben Langfeld" <sip:rwbqgpia@192.168.1.73>;tag=c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL"/></offer></presence> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:04.526 DEBUG [pool-21-thread-3] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:04.725 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq id="blather0008" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" type="set"><accept xmlns="urn:xmpp:rayo:1"/></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:04.726 DEBUG [XMPPService-t-31] #XMPP#: Invoke application:rayo rayo | |
| 2012-03-20 09:52:04.726 DEBUG [XMPPService-t-31] #XMPP#: Forwarding Request #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][null] | |
| 2012-03-20 09:52:04.726 DEBUG [XMPPService-t-31] <iq from="usera@127.0.0.1/blmbp.home-28910" id="blather0008" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" type="set"><accept xmlns="urn:xmpp:rayo:1"/></iq> :: xmpps_l0328mignyvl | |
| 2012-03-20 09:52:04.727 DEBUG [XMPPService-t-31] Looking up call [4vg6dkqc-lx7-fxod8zouyy3mb] in registry: [com.rayo.server.DefaultCallRegistry@491a97] | |
| 2012-03-20 09:52:04.728 DEBUG [pool-21-thread-3] [IncomingCallActor[callId=4vg6dkqc-lx7-fxod8zouyy3mb]] : Request [AcceptCommand[callId=4vg6dkqc-lx7-fxod8zouyy3mb,headers={}]] | |
| 2012-03-20 09:52:04.728 DEBUG [pool-21-thread-3] #SIP#: SessionManagementLayer send response: INVITE/180 #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.729 DEBUG [pool-21-thread-3] #SIP#: Add Path[ id=T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u-c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL-dhgn9s9mk146, session=SipSessionImpl[_id=ss_1hrqgtdr2wdid, _parentId=sas_2-15-sm1i1a8cbvif5iarayo, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=INVITE, _callId=T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, ], party= CALLER] #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.730 DEBUG [pool-21-thread-3] #SIP#: (o)[SIP/2.0 180 Ringing\r\nTo: <sip:usera@127.0.0.1>;tag=dhgn9s9mk146\r\nVia: SIP/2.0/UDP 192.168.1.72:59615;rport=59615;branch=z9hG4bKPjE.KMjdg80mb40oy1nHXQiQ.unbXxr31K;received=127.0.0.1\r\nCSeq: 22123 INVITE\r\nContent-Length: 0\r\nCall-ID: T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u\r\nFrom: "Ben Langfeld" <sip:rwbqgpia@192.168.1.73>;tag=c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL\r\n\r\n] #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.730 DEBUG [pool-21-thread-3] #SIP#: Send message to: /127.0.0.1:59615 by udp #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.730 DEBUG [pool-21-thread-3] #SIP#: Connected to 127.0.0.1:59615/udp #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.730 DEBUG [pool-21-thread-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1i1a8cbvif5iarayo], invalidateWhenReady: true | |
| 2012-03-20 09:52:04.731 DEBUG [pool-21-thread-3] #SIP#: processInvalidationWhenReady [ss_1hrqgtdr2wdid], current State = EARLY, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.731 DEBUG [pool-21-thread-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1i1a8cbvif5iarayo], invalidateWhenReady: true | |
| 2012-03-20 09:52:04.731 INFO [pool-21-thread-3] Reply [null] | |
| 2012-03-20 09:52:04.732 DEBUG [pool-21-thread-3] #XMPP#: (o)<iq from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather0008" to="usera@127.0.0.1/blmbp.home-28910" type="result"/> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:04.732 DEBUG [pool-21-thread-3] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:04.825 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq id="blather000a" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" type="set"><answer xmlns="urn:xmpp:rayo:1"/></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:04.826 DEBUG [XMPPService-t-32] #XMPP#: Invoke application:rayo rayo | |
| 2012-03-20 09:52:04.826 DEBUG [XMPPService-t-32] #XMPP#: Forwarding Request #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][null] | |
| 2012-03-20 09:52:04.827 DEBUG [XMPPService-t-32] <iq from="usera@127.0.0.1/blmbp.home-28910" id="blather000a" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" type="set"><answer xmlns="urn:xmpp:rayo:1"/></iq> :: xmpps_l0328mignyvl | |
| 2012-03-20 09:52:04.827 DEBUG [XMPPService-t-32] Looking up call [4vg6dkqc-lx7-fxod8zouyy3mb] in registry: [com.rayo.server.DefaultCallRegistry@491a97] | |
| 2012-03-20 09:52:04.828 DEBUG [pool-21-thread-3] [IncomingCallActor[callId=4vg6dkqc-lx7-fxod8zouyy3mb]] : Request [AnswerCommand[callId=4vg6dkqc-lx7-fxod8zouyy3mb,headers={}]] | |
| 2012-03-20 09:52:04.828 DEBUG [pool-21-thread-3] Set ms id with call id :T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u | |
| 2012-03-20 09:52:04.828 INFO [pool-21-thread-3] #MSCTRL#: MS[MS-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] updates MEDIAOBJECT_ID, old:"ms2-5", new:"MS-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u" | |
| 2012-03-20 09:52:04.828 DEBUG [pool-21-thread-3] Set nc id with call id :T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u | |
| 2012-03-20 09:52:04.829 INFO [pool-21-thread-3] #MSCTRL#: MS[NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] updates MEDIAOBJECT_ID, old:"MS-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u", new:"NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u" | |
| 2012-03-20 09:52:04.829 INFO [pool-21-thread-3] #MSCTRL#: MS[NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] creates a MediaObject[BASIC, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, {MEDIAOBJECT_ID=NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u}] | |
| 2012-03-20 09:52:04.829 INFO [pool-21-thread-3] #MSCTRL#: SdpPort[IDLE, NC[NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] processes a SDP offer: v=0\r\no=- 3541225924 3541225924 IN IP4 127.0.0.1\r\ns=Blink 0.24.1 (MacOSX)\r\nc=IN IP4 127.0.0.1\r\nt=0 0\r\nm=audio 50068 RTP/AVP 9 104 103 102 3 101\r\na=rtcp:50069\r\na=rtpmap:9 G722/8000\r\na=rtpmap:104 speex/32000\r\na=rtpmap:103 speex/16000\r\na=rtpmap:102 speex/8000\r\na=rtpmap:3 GSM/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n | |
| 2012-03-20 09:52:04.831 DEBUG [pool-21-thread-3] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] moves state from [IDLE] to [UNDER_PROCESSING] | |
| 2012-03-20 09:52:04.832 INFO [msctrl/2-t-12] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer | |
| 2012-03-20 09:52:04.832 DEBUG [msctrl/2-t-12] #MRCP#: load configuration from {maxThreadPool=2147483647, minThreadPool=25, MEDIAOBJECT_ID=NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, com.voxeo.useLocalConfigurationOnGUTFailures=false} | |
| 2012-03-20 09:52:04.843 DEBUG [msctrl/2-t-12] #MRCP#: (o)SETUP rtsp://192.168.1.73:10074/recognizer/ RTSP/1.0\r\nCseq: 1\r\nTransport: RTP/AVP;unicast;\r\nContent-Type: application/sdp\r\nContent-Length: 342\r\n\r\nv=0\r\no=- 3541225924 3541225924 IN IP4 127.0.0.1\r\ns=Blink 0.24.1 (MacOSX)\r\nc=IN IP4 127.0.0.1\r\nt=0 0\r\nm=audio 50068 RTP/AVP 9 104 103 102 3 101\r\na=rtcp:50069\r\na=rtpmap:9 G722/8000\r\na=rtpmap:104 speex/32000\r\na=rtpmap:103 speex/16000\r\na=rtpmap:102 speex/8000\r\na=rtpmap:3 GSM/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n #[N/A][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:04.854 DEBUG [mrcp/2-t-13] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 797263084-a787590-01b1f470-00000002\r\nTransport: RTP/AVP;unicast;client_port=50068-50069;server_port=65535-65536\r\nCseq: 1\r\nContent-Type: application/sdp\r\nContent-Length: 193\r\n\r\nv=0\r\no=- 1896872 1896872 IN IP4 109.149.163.56\r\ns=voxeo\r\nc=IN IP4 109.149.163.56\r\nt=0 0\r\nm=audio 20002 RTP/AVP 101 103\r\na=rtpmap:101 telephone-event/8000\r\na=rtpmap:103 SPEEX/16000\r\na=ptime:20\r\n #[N/A][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:04.855 DEBUG [msctrl/2-t-12] #MSCTRL#: NC[NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] applies for the recognizer resource. #[797263084-a787590-01b1f470-00000002] | |
| 2012-03-20 09:52:04.856 DEBUG [msctrl/2-t-12] #MRCP#: (o)SETUP rtsp://192.168.1.73:10074/synthesizer/ RTSP/1.0\r\nCseq: 2\r\nTransport: RTP/AVP;unicast;\r\nSession: 797263084-a787590-01b1f470-00000002\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:04.867 DEBUG [mrcp/2-t-14] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 797263084-a787590-01b1f470-00000002\r\nTransport: RTP/AVP;unicast;client_port=50068-50069;server_port=65535-65536\r\nCseq: 2\r\nContent-Type: application/sdp\r\nContent-Length: 183\r\n\r\nv=0\r\no=- 1896883 1896883 IN IP4 127.0.0.1\r\ns=voxeo\r\nc=IN IP4 127.0.0.1\r\nt=0 0\r\nm=audio 20002 RTP/AVP 101 103\r\na=rtpmap:101 telephone-event/8000\r\na=rtpmap:103 SPEEX/16000\r\na=ptime:20\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:04.867 DEBUG [msctrl/2-t-12] #MSCTRL#: NC[NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] applies for the synthesizer resource. #[797263084-a787590-01b1f470-00000002] | |
| 2012-03-20 09:52:04.868 DEBUG [msctrl/2-t-12] #MSCTRL#: SdpPort[SDP_NEGOTIATED, NC[NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATED] | |
| 2012-03-20 09:52:04.869 DEBUG [msctrl/2-t-13] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATED, NC[NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]], ANSWER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 1896872 1896872 IN IP4 109.149.163.56\r\ns=voxeo\r\nc=IN IP4 109.149.163.56\r\nt=0 0\r\nm=audio 20002 RTP/AVP 101 103\r\na=rtpmap:101 telephone-event/8000\r\na=rtpmap:103 SPEEX/16000\r\na=ptime:20\r\n] to the application | |
| 2012-03-20 09:52:04.872 DEBUG [msctrl/2-t-13] #SIP#: SessionManagementLayer send response: INVITE/200 #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.874 DEBUG [msctrl/2-t-13] #SIP#: (o)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:usera@127.0.0.1>;tag=dhgn9s9mk146\r\nVia: SIP/2.0/UDP 192.168.1.72:59615;rport=59615;branch=z9hG4bKPjE.KMjdg80mb40oy1nHXQiQ.unbXxr31K;received=127.0.0.1\r\nCSeq: 22123 INVITE\r\nContent-Length: 193\r\nCall-ID: T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u\r\nFrom: "Ben Langfeld" <sip:rwbqgpia@192.168.1.73>;tag=c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL\r\nContact: <sip:192.168.1.73:5060;transport=udp>\r\n\r\nv=0\r\no=- 1896872 1896872 IN IP4 109.149.163.56\r\ns=voxeo\r\nc=IN IP4 109.149.163.56\r\nt=0 0\r\nm=audio 20002 RTP/AVP 101 103\r\na=rtpmap:101 telephone-event/8000\r\na=rtpmap:103 SPEEX/16000\r\na=ptime:20\r\n] #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.874 DEBUG [msctrl/2-t-13] #SIP#: Send message to: /127.0.0.1:59615 by udp #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.875 DEBUG [msctrl/2-t-13] #SIP#: Connected to 127.0.0.1:59615/udp #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.875 DEBUG [msctrl/2-t-13] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1i1a8cbvif5iarayo], invalidateWhenReady: true | |
| 2012-03-20 09:52:04.875 DEBUG [msctrl/2-t-13] #SIP#: processInvalidationWhenReady [ss_1hrqgtdr2wdid], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.875 DEBUG [msctrl/2-t-13] #SIP#: processInvalidationWhenReady [sas_2-15-sm1i1a8cbvif5iarayo], invalidateWhenReady: true | |
| 2012-03-20 09:52:04.903 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[ACK sip:192.168.1.73:5060;transport=udp SIP/2.0\r\nTo: <sip:usera@127.0.0.1>;tag=dhgn9s9mk146\r\nVia: SIP/2.0/UDP 192.168.1.72:59615;rport;branch=z9hG4bKPjHhRrlkPgd8Fj8wgaxGEacxiijevp3aRD\r\nCSeq: 22123 ACK\r\nContent-Length: 0\r\nCall-ID: T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u\r\nUser-Agent: Blink 0.24.1 (MacOSX)\r\nFrom: "Ben Langfeld" <sip:rwbqgpia@192.168.1.73>;tag=c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL\r\nMax-Forwards: 70\r\n\r\n] #[N/A][N/A][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][N/A][sip:rwbqgpia@192.168.1.73(192.168.1.73:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.905 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Find Path[ id=T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u-c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL-dhgn9s9mk146, path=ApplicationPath[_id=T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u-c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL-dhgn9s9mk146, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_1hrqgtdr2wdid, appSessionId=sas_2-15-sm1i1a8cbvif5iarayo, ], ]], ], ]] #[N/A][N/A][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][N/A][sip:rwbqgpia@192.168.1.73(192.168.1.73:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.905 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv request: ACK #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(192.168.1.73:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.906 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ApplicationDispatchLayer invoke application: Controller with ACK #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(192.168.1.73:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.906 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(192.168.1.73:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.907 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1i1a8cbvif5iarayo], invalidateWhenReady: true | |
| 2012-03-20 09:52:04.908 INFO [pool-21-thread-3] Reply [null] | |
| 2012-03-20 09:52:04.908 DEBUG [MOHO-22] Dispatching Event to listener:[Event class=com.voxeo.moho.common.event.MohoJoinCompleteEvent sourceClass=SIPIncomingCall id=24248381] | |
| 2012-03-20 09:52:04.908 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_1hrqgtdr2wdid], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:04.910 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1i1a8cbvif5iarayo], invalidateWhenReady: true | |
| 2012-03-20 09:52:04.908 DEBUG [pool-21-thread-3] #XMPP#: (o)<iq from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather000a" to="usera@127.0.0.1/blmbp.home-28910" type="result"/> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:04.915 DEBUG [pool-21-thread-3] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:04.916 DEBUG [pool-21-thread-2] [IncomingCallActor[callId=4vg6dkqc-lx7-fxod8zouyy3mb]] : Request [[Event class=com.voxeo.moho.common.event.MohoJoinCompleteEvent sourceClass=SIPIncomingCall id=24248381]] | |
| 2012-03-20 09:52:04.916 DEBUG [pool-21-thread-2] Received Join Complete Event. Is initiator: [true] | |
| 2012-03-20 09:52:04.920 DEBUG [pool-21-thread-2] Join Complete Event source: [SIPCallImpl[SipSessionAdaptor[sessionid=ss_1hrqgtdr2wdid, appSessionId=sas_2-15-sm1i1a8cbvif5iarayo, ],ANSWERED]]. Peer: [null] | |
| 2012-03-20 09:52:04.922 DEBUG [pool-21-thread-2] Validating media on join | |
| 2012-03-20 09:52:04.922 DEBUG [pool-21-thread-2] Joined Event not fired. Join cause [JOINED]. Joinees: [[]] | |
| 2012-03-20 09:52:04.922 INFO [pool-21-thread-2] Reply [null] | |
| 2012-03-20 09:52:05.159 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq id="blather000c" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" type="set"><output xmlns="urn:xmpp:rayo:output:1">digits/3</output></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:05.160 DEBUG [XMPPService-t-33] #XMPP#: Invoke application:rayo rayo | |
| 2012-03-20 09:52:05.160 DEBUG [XMPPService-t-33] #XMPP#: Forwarding Request #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][null] | |
| 2012-03-20 09:52:05.161 DEBUG [XMPPService-t-33] <iq from="usera@127.0.0.1/blmbp.home-28910" id="blather000c" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" type="set"><output xmlns="urn:xmpp:rayo:output:1">digits/3</output></iq> :: xmpps_l0328mignyvl | |
| 2012-03-20 09:52:05.161 DEBUG [XMPPService-t-33] Looking up call [4vg6dkqc-lx7-fxod8zouyy3mb] in registry: [com.rayo.server.DefaultCallRegistry@491a97] | |
| 2012-03-20 09:52:05.162 DEBUG [pool-21-thread-2] [IncomingCallActor[callId=4vg6dkqc-lx7-fxod8zouyy3mb]] : Request [Output[callId=4vg6dkqc-lx7-fxod8zouyy3mb,verbId=1ef345cc-b9df-455f-bbd5-08ba025de3b2,interrupt-on=<null>,start-offset=<null>,start-paused=<null>,repeatInterval=<null>,repeatTimes=<null>,maxTime=<null>,voice=<null>,prompt=Ssml[ssml=digits/3,voice=<null>,uri=data:application%2Fssml%2Bxml%2C%3Cspeak%3Edigits%2F3%3C%2Fspeak%3E]]] | |
| 2012-03-20 09:52:05.162 DEBUG [pool-21-thread-2] Creating instance of bean 'outputHandler' | |
| 2012-03-20 09:52:05.164 DEBUG [pool-21-thread-2] Returning cached instance of singleton bean 'ssmlValidator' | |
| 2012-03-20 09:52:05.165 DEBUG [pool-21-thread-2] Finished creating instance of bean 'outputHandler' | |
| 2012-03-20 09:52:05.166 DEBUG [pool-21-thread-2] Set mg id with call id :T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u | |
| 2012-03-20 09:52:05.166 INFO [pool-21-thread-2] #MSCTRL#: MS[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] updates MEDIAOBJECT_ID, old:"NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u", new:"MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u" | |
| 2012-03-20 09:52:05.166 INFO [pool-21-thread-2] #MSCTRL#: MS[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] creates a MediaObject[PLAYER_RECORDER_SIGNALDETECTOR, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, {MEDIAOBJECT_ID=MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u}] | |
| 2012-03-20 09:52:05.167 INFO [pool-21-thread-2] SIPCallImpl[SipSessionAdaptor[sessionid=ss_1hrqgtdr2wdid, appSessionId=sas_2-15-sm1i1a8cbvif5iarayo, ],ANSWERED] joins to MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] in DUPLEX | |
| 2012-03-20 09:52:05.167 INFO [pool-21-thread-2] #MSCTRL#: NC[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] joins to MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] in DUPLEX | |
| 2012-03-20 09:52:05.168 DEBUG [pool-21-thread-2] #MSCTRL#: MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] adds JoineeMrcpContext[mscontrol://192.168.1.73:10074/MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u/NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, 797263084-a787590-01b1f470-00000002, 797263084-a787590-01b1f470-00000002] #[797263084-a787590-01b1f470-00000002] | |
| 2012-03-20 09:52:05.169 DEBUG [pool-21-thread-2] #MSCTRL#: MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] adds JoinCompleteDector[MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u], NC[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] #[797263084-a787590-01b1f470-00000002] | |
| 2012-03-20 09:52:05.169 DEBUG [pool-21-thread-2] #MSCTRL#: NC[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] adds(MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null]) | |
| 2012-03-20 09:52:05.169 DEBUG [pool-21-thread-2] #MSCTRL#: MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] adds(NC[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null]) | |
| 2012-03-20 09:52:05.170 DEBUG [pool-21-thread-2] #MSCTRL#: Add PlayListItem[gi:0, pi:0, ei:0, null, rtcs=null, optargs={PLAYER_MAX_DURATION=-1, PLAYER_START_OFFSET=0, JUMP_PLAYLIST_INCREMENT=1, PLAYER_ENABLED_EVENTS=[Ljavax.media.mscontrol.EventType;@120bd9a, BARGE_IN_ENABLED=false, PLAYER_AUDIO_CODEC=CODEC_INFERRED, VOLUME_CHANGE=3, PLAYER_JUMP_TIME=5000, VOICE_NAME=null, BEHAVIOUR_IF_BUSY=STOP_IF_BUSY, PLAYER_START_PAUSED=false, PLAYER_FILE_FORMAT=FORMAT_INFERRED, TTS_SPEECH_LANGUAGE=null},"<speak>digits/3</speak>"] | |
| 2012-03-20 09:52:05.170 DEBUG [pool-21-thread-2] #MSCTRL#: Find PlayListItem[IDLE, gi=0, pi=0, ei=0, null] | |
| 2012-03-20 09:52:05.170 DEBUG [pool-21-thread-2] #MSCTRL#: Player[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] starts playing PlayListItem[IDLE, gi=0, pi=0, ei=0, null] | |
| 2012-03-20 09:52:05.170 DEBUG [pool-21-thread-2] #MSCTRL#: Player[ACTIVE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] moves state from [IDLE] to [ACTIVE] | |
| 2012-03-20 09:52:05.170 DEBUG [pool-21-thread-2] #MSCTRL#: PlayListItem[0, 0, 0] moves state from [IDLE] to [PLAYING] | |
| 2012-03-20 09:52:05.171 DEBUG [pool-21-thread-2] #MSCTRL#: MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] added MrcpSpeakListener[Player[ACTIVE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]], ACTIVE] #[797263084-a787590-01b1f470-00000002] | |
| 2012-03-20 09:52:05.172 DEBUG [pool-21-thread-2] #MRCP#: (o)ANNOUNCE rtsp://192.168.1.73:10074/synthesizer/ RTSP/1.0\r\nCseq: 3\r\nSession: 797263084-a787590-01b1f470-00000002\r\nContent-Type: application/mrcp\r\nContent-Length: 251\r\n\r\nSPEAK 37000 MRCP/1.0\r\nKill-On-Barge-In: false\r\nSpeech-Language: en-us\r\nVendor-Specific-Parameters: Voxeo-Playback-Mode=JSR309;Voxeo-Speed-Out=100;Voxeo-Gain-Out=0\r\nContent-Type: application/synthesis+ssml\r\nContent-Length: 23\r\n\r\n<speak>digits/3</speak> #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:05.174 DEBUG [mrcp/2-t-15] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 797263084-a787590-01b1f470-00000002\r\nCseq: 3\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 37000 200 IN-PROGRESS\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:05.175 DEBUG [pool-21-thread-2] #MSCTRL#: PlayListItem[0, 0, 0] added (37000, 797263084-a787590-01b1f470-00000002) | |
| 2012-03-20 09:52:05.175 INFO [pool-21-thread-2] Reply [com.rayo.core.verb.VerbRef@1fff962] | |
| 2012-03-20 09:52:05.176 DEBUG [pool-21-thread-2] #XMPP#: (o)<iq from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather000c" to="usera@127.0.0.1/blmbp.home-28910" type="result"><ref id="eb5f6969-d096-4e40-97be-4fbece5c1c43" xmlns="urn:xmpp:rayo:1"/></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:05.176 DEBUG [pool-21-thread-2] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:05.658 DEBUG [Timer-15] #SIP#: InviteServerTransaction[, , _state=ACCEPTED, _id=z9hG4bKPjEo3epd5w.R0rkPDgJJT2579z7lsQqeIJ, ] timerRemoveTransaction is fired. #[rayo][sas_2-14-sm5mhpdz1ouph4rayo][-dv.4n1E0.TiySTTyyv-bY2C.yxUhwF-][ss_1wzw1mez634cw][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:05.658 DEBUG [Timer-15] #SIP#: InviteServerTransaction[, , _state=TERMINATED, _id=z9hG4bKPjEo3epd5w.R0rkPDgJJT2579z7lsQqeIJ, ] is released. #[rayo][sas_2-14-sm5mhpdz1ouph4rayo][-dv.4n1E0.TiySTTyyv-bY2C.yxUhwF-][ss_1wzw1mez634cw][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:06.589 DEBUG [mrcp/2-t-16] #MRCP#: (i)ANNOUNCE rtsp://192.168.1.73:10074/synthesizer/ RTSP/1.0\r\nCseq: 1\r\nSession: 797263084-a787590-01b1f470-00000002\r\nContent-Type: application/mrcp\r\nContent-Length: 72\r\n\r\nSPEAK-COMPLETE 37000 COMPLETE MRCP/1.0\r\ncompletion-cause: 000 normal\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:06.589 DEBUG [mrcp/2-t-16] #MRCP#: (o)RTSP/1.0 200 OK\r\nSession: 797263084-a787590-01b1f470-00000002\r\nCseq: 1\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:06.590 DEBUG [mrcp/2-t-17] #MRCP#: Handling SPEAK-COMPLETE[37000] #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:06.591 DEBUG [mrcp/2-t-17] #MSCTRL#: Find PlayListItem[PLAYING, gi=0, pi=0, ei=0, null, speakIds=[37000]] | |
| 2012-03-20 09:52:06.592 DEBUG [mrcp/2-t-17] #MSCTRL#: MrcpSpeakListener[Player[ACTIVE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]], ACTIVE] handling with MrcpSpeakCompleteEvent[originalId:37000, requestId:37000, rc:0, duration:1421] #[797263084-a787590-01b1f470-00000002] | |
| 2012-03-20 09:52:06.592 DEBUG [mrcp/2-t-17] #MSCTRL#: PlayListItem[0, 0, 0] removed (37000, 797263084-a787590-01b1f470-00000002) | |
| 2012-03-20 09:52:06.592 DEBUG [mrcp/2-t-17] #MSCTRL#: PlayListItem[0, 0, 0] moves state from [PLAYING] to [IDLE] | |
| 2012-03-20 09:52:06.592 DEBUG [mrcp/2-t-17] #MSCTRL#: Find [PlayListItem[IDLE, gi=0, pi=0, ei=0, null]] | |
| 2012-03-20 09:52:06.593 DEBUG [mrcp/2-t-17] #MSCTRL#: Player[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] moves state from [ACTIVE] to [IDLE] | |
| 2012-03-20 09:52:06.593 DEBUG [mrcp/2-t-17] #MSCTRL#: clear up playList=[PlayListItem[IDLE, gi=0, pi=0, ei=0, null]] | |
| 2012-03-20 09:52:06.594 DEBUG [msctrl/2-t-14] #MSCTRL#: Return PlayerEvent[Player[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]], PLAY_COMPLETED, NO_ERROR, null, END_OF_PLAY_LIST, null, null, 0, 1421] to the application | |
| 2012-03-20 09:52:06.595 DEBUG [MOHO-24] Dispatching Event to listener:[Event class=com.voxeo.moho.common.event.MohoOutputCompleteEvent sourceClass=SIPIncomingCall id=1057446] | |
| 2012-03-20 09:52:06.595 DEBUG [pool-21-thread-2] [IncomingCallActor[callId=4vg6dkqc-lx7-fxod8zouyy3mb]] : Request [[Event class=com.voxeo.moho.common.event.MohoOutputCompleteEvent sourceClass=SIPIncomingCall id=1057446]] | |
| 2012-03-20 09:52:06.596 INFO [pool-21-thread-2] Queued Event [OutputCompleteEvent[callId=4vg6dkqc-lx7-fxod8zouyy3mb,verbId=eb5f6969-d096-4e40-97be-4fbece5c1c43,reason=SUCCESS,errorText=<null>]] | |
| 2012-03-20 09:52:06.596 INFO [pool-21-thread-2] Reply [null] | |
| 2012-03-20 09:52:06.596 INFO [pool-21-thread-2] Event [OutputCompleteEvent[callId=4vg6dkqc-lx7-fxod8zouyy3mb,verbId=eb5f6969-d096-4e40-97be-4fbece5c1c43,reason=SUCCESS,errorText=<null>]] | |
| 2012-03-20 09:52:06.599 DEBUG [pool-21-thread-2] #XMPP#: (o)<presence from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home/eb5f6969-d096-4e40-97be-4fbece5c1c43" id="579ced25-c02c-4e2a-8dae-8ea3b9f13b86" to="usera@127.0.0.1"><complete xmlns="urn:xmpp:rayo:ext:1"><success xmlns="urn:xmpp:rayo:output:complete:1"/></complete></presence> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:06.599 DEBUG [pool-21-thread-2] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:06.692 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq id="blather000e" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" type="set"><output xmlns="urn:xmpp:rayo:output:1"><speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"><audio src="http://static1.grsites.com/archive/sounds/aircraft/aircraft001.mp3"/></speak></output></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:06.693 DEBUG [XMPPService-t-34] #XMPP#: Invoke application:rayo rayo | |
| 2012-03-20 09:52:06.693 DEBUG [XMPPService-t-34] #XMPP#: Forwarding Request #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][null] | |
| 2012-03-20 09:52:06.694 DEBUG [XMPPService-t-34] <iq from="usera@127.0.0.1/blmbp.home-28910" id="blather000e" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" type="set"><output xmlns="urn:xmpp:rayo:output:1"><speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"><audio src="http://static1.grsites.com/archive/sounds/aircraft/aircraft001.mp3"/></speak></output></iq> :: xmpps_l0328mignyvl | |
| 2012-03-20 09:52:06.695 DEBUG [XMPPService-t-34] Looking up call [4vg6dkqc-lx7-fxod8zouyy3mb] in registry: [com.rayo.server.DefaultCallRegistry@491a97] | |
| 2012-03-20 09:52:06.696 DEBUG [pool-21-thread-2] [IncomingCallActor[callId=4vg6dkqc-lx7-fxod8zouyy3mb]] : Request [Output[callId=4vg6dkqc-lx7-fxod8zouyy3mb,verbId=e504c5e2-b230-4f9e-aad2-bbd87f361d7d,interrupt-on=<null>,start-offset=<null>,start-paused=<null>,repeatInterval=<null>,repeatTimes=<null>,maxTime=<null>,voice=<null>,prompt=Ssml[ssml=<speak version="1.0" xmlns:xml="" xml:xml:lang="en-US"><audio src="http://static1.grsites.com/archive/sounds/aircraft/aircraft001.mp3"/></speak>,voice=<null>,uri=data:application%2Fssml%2Bxml%2C%3Cspeak+version%3D%221.0%22+xmlns%3Axml%3D%22%22+xml%3Axml%3Alang%3D%22en-US%22%3E%3Caudio+src%3D%22http%3A%2F%2Fstatic1.grsites.com%2Farchive%2Fsounds%2Faircraft%2Faircraft001.mp3%22%2F%3E%3C%2Fspeak%3E]]] | |
| 2012-03-20 09:52:06.696 DEBUG [pool-21-thread-2] Creating instance of bean 'outputHandler' | |
| 2012-03-20 09:52:06.696 DEBUG [pool-21-thread-2] Returning cached instance of singleton bean 'ssmlValidator' | |
| 2012-03-20 09:52:06.697 DEBUG [pool-21-thread-2] Finished creating instance of bean 'outputHandler' | |
| 2012-03-20 09:52:06.698 DEBUG [pool-21-thread-2] #MSCTRL#: Add PlayListItem[gi:0, pi:1, ei:0, null, rtcs=null, optargs={PLAYER_MAX_DURATION=-1, PLAYER_START_OFFSET=0, JUMP_PLAYLIST_INCREMENT=1, PLAYER_ENABLED_EVENTS=[Ljavax.media.mscontrol.EventType;@e134e6, BARGE_IN_ENABLED=false, PLAYER_AUDIO_CODEC=CODEC_INFERRED, VOLUME_CHANGE=3, PLAYER_JUMP_TIME=5000, VOICE_NAME=null, BEHAVIOUR_IF_BUSY=STOP_IF_BUSY, PLAYER_START_PAUSED=false, PLAYER_FILE_FORMAT=FORMAT_INFERRED, TTS_SPEECH_LANGUAGE=null},"<speak version="1.0" xmlns:xml="" xml:xml:lang="en-US"><audio src="http://static1.grsites.com/archive/sounds/aircraft/aircraft001.mp3"/></speak>"] | |
| 2012-03-20 09:52:06.698 DEBUG [pool-21-thread-2] #MSCTRL#: Find PlayListItem[IDLE, gi=0, pi=1, ei=0, null] | |
| 2012-03-20 09:52:06.698 DEBUG [pool-21-thread-2] #MSCTRL#: Player[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] starts playing PlayListItem[IDLE, gi=0, pi=1, ei=0, null] | |
| 2012-03-20 09:52:06.698 DEBUG [pool-21-thread-2] #MSCTRL#: Player[ACTIVE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] moves state from [IDLE] to [ACTIVE] | |
| 2012-03-20 09:52:06.698 DEBUG [pool-21-thread-2] #MSCTRL#: PlayListItem[0, 0, 1] moves state from [IDLE] to [PLAYING] | |
| 2012-03-20 09:52:06.699 DEBUG [pool-21-thread-2] #MRCP#: (o)ANNOUNCE rtsp://192.168.1.73:10074/synthesizer/ RTSP/1.0\r\nCseq: 4\r\nSession: 797263084-a787590-01b1f470-00000002\r\nContent-Type: application/mrcp\r\nContent-Length: 373\r\n\r\nSPEAK 37001 MRCP/1.0\r\nKill-On-Barge-In: false\r\nSpeech-Language: en-us\r\nVendor-Specific-Parameters: Voxeo-Playback-Mode=JSR309;Voxeo-Speed-Out=100;Voxeo-Gain-Out=0\r\nContent-Type: application/synthesis+ssml\r\nContent-Length: 144\r\n\r\n<speak version="1.0" xmlns:xml="" xml:xml:lang="en-US"><audio src="http://static1.grsites.com/archive/sounds/aircraft/aircraft001.mp3"/></speak> #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:06.701 DEBUG [mrcp/2-t-18] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 797263084-a787590-01b1f470-00000002\r\nCseq: 4\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 37001 200 IN-PROGRESS\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:06.702 DEBUG [pool-21-thread-2] #MSCTRL#: PlayListItem[0, 0, 1] added (37001, 797263084-a787590-01b1f470-00000002) | |
| 2012-03-20 09:52:06.702 INFO [pool-21-thread-2] Reply [com.rayo.core.verb.VerbRef@89178b] | |
| 2012-03-20 09:52:06.703 DEBUG [pool-21-thread-2] #XMPP#: (o)<iq from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather000e" to="usera@127.0.0.1/blmbp.home-28910" type="result"><ref id="92f9a63d-6783-40b8-b076-0a9d44871f91" xmlns="urn:xmpp:rayo:1"/></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:06.703 DEBUG [pool-21-thread-2] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:09.850 DEBUG [Timer-12] #SIP#: NonInviteServerTransaction[, , _state=COMPLETED, _id=z9hG4bKPjx2u1RiCyEK7uQrmRKDBb7.zOmXeO0bMD, ] timerRemoveTransaction is fired. #[rayo][sas_2-14-smpyhzn6od27p5rayo][pYlJZAj4MIMZu1XYAFr9HhXvrzeEzlYv][ss_19egmrp6jom40][sip:1234@127.0.0.1(127.0.0.1:59615)][sip:1234@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:09.851 DEBUG [Timer-12] #SIP#: NonInviteServerTransaction[, , _state=TERMINATED, _id=z9hG4bKPjx2u1RiCyEK7uQrmRKDBb7.zOmXeO0bMD, ] is released. #[rayo][sas_2-14-smpyhzn6od27p5rayo][pYlJZAj4MIMZu1XYAFr9HhXvrzeEzlYv][ss_19egmrp6jom40][sip:1234@127.0.0.1(127.0.0.1:59615)][sip:1234@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:09.854 DEBUG [Timer-13] #SIP#: SipSessionImpl[_id=ss_19egmrp6jom40, _parentId=sas_2-14-smpyhzn6od27p5rayo, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=REGISTER, _callId=pYlJZAj4MIMZu1XYAFr9HhXvrzeEzlYv, ] is invalidating. (s) #[rayo][sas_2-14-smpyhzn6od27p5rayo][pYlJZAj4MIMZu1XYAFr9HhXvrzeEzlYv][ss_19egmrp6jom40][sip:1234@127.0.0.1(127.0.0.1:59615)][sip:1234@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:09.855 DEBUG [Timer-13] #SIP#: Remove Path[ id=pYlJZAj4MIMZu1XYAFr9HhXvrzeEzlYv-nesE.K.G.uYf94A3BNn.Q3q2Ld-ljpYZ-1lggtz9ydxcxk, session=SipSessionImpl[_id=ss_19egmrp6jom40, _parentId=sas_2-14-smpyhzn6od27p5rayo, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=true, _role=UAS, _method=REGISTER, _callId=pYlJZAj4MIMZu1XYAFr9HhXvrzeEzlYv, ]] #[rayo][sas_2-14-smpyhzn6od27p5rayo][pYlJZAj4MIMZu1XYAFr9HhXvrzeEzlYv][ss_19egmrp6jom40][sip:1234@127.0.0.1(127.0.0.1:59615)][sip:1234@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:09.855 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [sas_2-14-smpyhzn6od27p5rayo], invalidateWhenReady: true | |
| 2012-03-20 09:52:09.855 DEBUG [Timer-13] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-14-smpyhzn6od27p5rayo] | |
| 2012-03-20 09:52:09.856 DEBUG [Timer-13] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-14-smpyhzn6od27p5rayo, ] is invalidating. (as) | |
| 2012-03-20 09:52:11.407 DEBUG [mrcp/2-t-19] #MRCP#: (i)ANNOUNCE rtsp://192.168.1.73:10074/synthesizer/ RTSP/1.0\r\nCseq: 2\r\nSession: 797263084-a787590-01b1f470-00000002\r\nContent-Type: application/mrcp\r\nContent-Length: 72\r\n\r\nSPEAK-COMPLETE 37001 COMPLETE MRCP/1.0\r\ncompletion-cause: 000 normal\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:11.407 DEBUG [mrcp/2-t-19] #MRCP#: (o)RTSP/1.0 200 OK\r\nSession: 797263084-a787590-01b1f470-00000002\r\nCseq: 2\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:11.409 DEBUG [mrcp/2-t-20] #MRCP#: Handling SPEAK-COMPLETE[37001] #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:11.409 DEBUG [mrcp/2-t-20] #MSCTRL#: Find PlayListItem[PLAYING, gi=0, pi=1, ei=0, null, speakIds=[37001]] | |
| 2012-03-20 09:52:11.410 DEBUG [mrcp/2-t-20] #MSCTRL#: MrcpSpeakListener[Player[ACTIVE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]], ACTIVE] handling with MrcpSpeakCompleteEvent[originalId:37001, requestId:37001, rc:0, duration:4711] #[797263084-a787590-01b1f470-00000002] | |
| 2012-03-20 09:52:11.410 DEBUG [mrcp/2-t-20] #MSCTRL#: PlayListItem[0, 0, 1] removed (37001, 797263084-a787590-01b1f470-00000002) | |
| 2012-03-20 09:52:11.410 DEBUG [mrcp/2-t-20] #MSCTRL#: PlayListItem[0, 0, 1] moves state from [PLAYING] to [IDLE] | |
| 2012-03-20 09:52:11.410 DEBUG [mrcp/2-t-20] #MSCTRL#: Find [PlayListItem[IDLE, gi=0, pi=1, ei=0, null]] | |
| 2012-03-20 09:52:11.410 DEBUG [mrcp/2-t-20] #MSCTRL#: Player[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] moves state from [ACTIVE] to [IDLE] | |
| 2012-03-20 09:52:11.410 DEBUG [mrcp/2-t-20] #MSCTRL#: clear up playList=[PlayListItem[IDLE, gi=0, pi=1, ei=0, null]] | |
| 2012-03-20 09:52:11.411 DEBUG [msctrl/2-t-15] #MSCTRL#: Return PlayerEvent[Player[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]], PLAY_COMPLETED, NO_ERROR, null, END_OF_PLAY_LIST, null, null, 0, 4711] to the application | |
| 2012-03-20 09:52:11.412 DEBUG [MOHO-26] Dispatching Event to listener:[Event class=com.voxeo.moho.common.event.MohoOutputCompleteEvent sourceClass=SIPIncomingCall id=28009984] | |
| 2012-03-20 09:52:11.412 DEBUG [pool-21-thread-2] [IncomingCallActor[callId=4vg6dkqc-lx7-fxod8zouyy3mb]] : Request [[Event class=com.voxeo.moho.common.event.MohoOutputCompleteEvent sourceClass=SIPIncomingCall id=28009984]] | |
| 2012-03-20 09:52:11.413 INFO [pool-21-thread-2] Queued Event [OutputCompleteEvent[callId=4vg6dkqc-lx7-fxod8zouyy3mb,verbId=92f9a63d-6783-40b8-b076-0a9d44871f91,reason=SUCCESS,errorText=<null>]] | |
| 2012-03-20 09:52:11.413 INFO [pool-21-thread-2] Reply [null] | |
| 2012-03-20 09:52:11.413 INFO [pool-21-thread-2] Event [OutputCompleteEvent[callId=4vg6dkqc-lx7-fxod8zouyy3mb,verbId=92f9a63d-6783-40b8-b076-0a9d44871f91,reason=SUCCESS,errorText=<null>]] | |
| 2012-03-20 09:52:11.415 DEBUG [pool-21-thread-2] #XMPP#: (o)<presence from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home/92f9a63d-6783-40b8-b076-0a9d44871f91" id="05a322d7-a2ce-4c72-8d76-ed8dad54680f" to="usera@127.0.0.1"><complete xmlns="urn:xmpp:rayo:ext:1"><success xmlns="urn:xmpp:rayo:output:complete:1"/></complete></presence> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:11.416 DEBUG [pool-21-thread-2] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:11.509 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq id="blather0010" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" type="set"><output xmlns="urn:xmpp:rayo:output:1"><speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"><audio src="digits/3"/></speak></output></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:11.510 DEBUG [XMPPService-t-35] #XMPP#: Invoke application:rayo rayo | |
| 2012-03-20 09:52:11.510 DEBUG [XMPPService-t-35] #XMPP#: Forwarding Request #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][null] | |
| 2012-03-20 09:52:11.510 DEBUG [XMPPService-t-35] <iq from="usera@127.0.0.1/blmbp.home-28910" id="blather0010" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" type="set"><output xmlns="urn:xmpp:rayo:output:1"><speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"><audio src="digits/3"/></speak></output></iq> :: xmpps_l0328mignyvl | |
| 2012-03-20 09:52:11.511 DEBUG [XMPPService-t-35] Looking up call [4vg6dkqc-lx7-fxod8zouyy3mb] in registry: [com.rayo.server.DefaultCallRegistry@491a97] | |
| 2012-03-20 09:52:11.512 DEBUG [pool-21-thread-2] [IncomingCallActor[callId=4vg6dkqc-lx7-fxod8zouyy3mb]] : Request [Output[callId=4vg6dkqc-lx7-fxod8zouyy3mb,verbId=8069306f-7b3a-401d-803e-4020adf1862e,interrupt-on=<null>,start-offset=<null>,start-paused=<null>,repeatInterval=<null>,repeatTimes=<null>,maxTime=<null>,voice=<null>,prompt=Ssml[ssml=<speak version="1.0" xmlns:xml="" xml:xml:lang="en-US"><audio src="digits/3"/></speak>,voice=<null>,uri=data:application%2Fssml%2Bxml%2C%3Cspeak+version%3D%221.0%22+xmlns%3Axml%3D%22%22+xml%3Axml%3Alang%3D%22en-US%22%3E%3Caudio+src%3D%22digits%2F3%22%2F%3E%3C%2Fspeak%3E]]] | |
| 2012-03-20 09:52:11.512 DEBUG [pool-21-thread-2] Creating instance of bean 'outputHandler' | |
| 2012-03-20 09:52:11.513 DEBUG [pool-21-thread-2] Returning cached instance of singleton bean 'ssmlValidator' | |
| 2012-03-20 09:52:11.513 DEBUG [pool-21-thread-2] Finished creating instance of bean 'outputHandler' | |
| 2012-03-20 09:52:11.514 DEBUG [pool-21-thread-2] #MSCTRL#: Add PlayListItem[gi:0, pi:2, ei:0, null, rtcs=null, optargs={PLAYER_MAX_DURATION=-1, PLAYER_START_OFFSET=0, JUMP_PLAYLIST_INCREMENT=1, PLAYER_ENABLED_EVENTS=[Ljavax.media.mscontrol.EventType;@14ab6b5, BARGE_IN_ENABLED=false, PLAYER_AUDIO_CODEC=CODEC_INFERRED, VOLUME_CHANGE=3, PLAYER_JUMP_TIME=5000, VOICE_NAME=null, BEHAVIOUR_IF_BUSY=STOP_IF_BUSY, PLAYER_START_PAUSED=false, PLAYER_FILE_FORMAT=FORMAT_INFERRED, TTS_SPEECH_LANGUAGE=null},"<speak version="1.0" xmlns:xml="" xml:xml:lang="en-US"><audio src="digits/3"/></speak>"] | |
| 2012-03-20 09:52:11.514 DEBUG [pool-21-thread-2] #MSCTRL#: Find PlayListItem[IDLE, gi=0, pi=2, ei=0, null] | |
| 2012-03-20 09:52:11.514 DEBUG [pool-21-thread-2] #MSCTRL#: Player[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] starts playing PlayListItem[IDLE, gi=0, pi=2, ei=0, null] | |
| 2012-03-20 09:52:11.515 DEBUG [pool-21-thread-2] #MSCTRL#: Player[ACTIVE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] moves state from [IDLE] to [ACTIVE] | |
| 2012-03-20 09:52:11.515 DEBUG [pool-21-thread-2] #MSCTRL#: PlayListItem[0, 0, 2] moves state from [IDLE] to [PLAYING] | |
| 2012-03-20 09:52:11.516 DEBUG [pool-21-thread-2] #MRCP#: (o)ANNOUNCE rtsp://192.168.1.73:10074/synthesizer/ RTSP/1.0\r\nCseq: 5\r\nSession: 797263084-a787590-01b1f470-00000002\r\nContent-Type: application/mrcp\r\nContent-Length: 314\r\n\r\nSPEAK 37002 MRCP/1.0\r\nKill-On-Barge-In: false\r\nSpeech-Language: en-us\r\nVendor-Specific-Parameters: Voxeo-Playback-Mode=JSR309;Voxeo-Speed-Out=100;Voxeo-Gain-Out=0\r\nContent-Type: application/synthesis+ssml\r\nContent-Length: 86\r\n\r\n<speak version="1.0" xmlns:xml="" xml:xml:lang="en-US"><audio src="digits/3"/></speak> #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:11.517 DEBUG [mrcp/2-t-21] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 797263084-a787590-01b1f470-00000002\r\nCseq: 5\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 37002 200 IN-PROGRESS\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:11.518 DEBUG [pool-21-thread-2] #MSCTRL#: PlayListItem[0, 0, 2] added (37002, 797263084-a787590-01b1f470-00000002) | |
| 2012-03-20 09:52:11.518 DEBUG [mrcp/2-t-21] #MRCP#: (i)ANNOUNCE rtsp://192.168.1.73:10074/synthesizer/ RTSP/1.0\r\nCseq: 3\r\nSession: 797263084-a787590-01b1f470-00000002\r\nContent-Type: application/mrcp\r\nContent-Length: 77\r\n\r\nSPEAK-COMPLETE 37002 COMPLETE MRCP/1.0\r\ncompletion-cause: 003 uri-failure\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:11.518 INFO [pool-21-thread-2] Reply [com.rayo.core.verb.VerbRef@1cb9b56] | |
| 2012-03-20 09:52:11.519 DEBUG [mrcp/2-t-21] #MRCP#: (o)RTSP/1.0 200 OK\r\nSession: 797263084-a787590-01b1f470-00000002\r\nCseq: 3\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:11.519 DEBUG [pool-21-thread-2] #XMPP#: (o)<iq from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather0010" to="usera@127.0.0.1/blmbp.home-28910" type="result"><ref id="f8440d4f-464b-43d9-b48c-3ec686268457" xmlns="urn:xmpp:rayo:1"/></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:11.519 DEBUG [pool-21-thread-2] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:11.520 DEBUG [mrcp/2-t-22] #MRCP#: Handling SPEAK-COMPLETE[37002] #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:11.521 DEBUG [mrcp/2-t-22] #MSCTRL#: Find PlayListItem[PLAYING, gi=0, pi=2, ei=0, null, speakIds=[37002]] | |
| 2012-03-20 09:52:11.521 DEBUG [mrcp/2-t-22] #MSCTRL#: MrcpSpeakListener[Player[ACTIVE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]], ACTIVE] handling with MrcpSpeakCompleteEvent[originalId:37002, requestId:37002, rc:3, duration:6] #[797263084-a787590-01b1f470-00000002] | |
| 2012-03-20 09:52:11.521 DEBUG [mrcp/2-t-22] #MSCTRL#: PlayListItem[0, 0, 2] removed (37002, 797263084-a787590-01b1f470-00000002) | |
| 2012-03-20 09:52:11.521 DEBUG [mrcp/2-t-22] #MSCTRL#: PlayListItem[0, 0, 2] moves state from [PLAYING] to [IDLE] | |
| 2012-03-20 09:52:11.522 ERROR [mrcp/2-t-22] #MSCTRL#: SPEAK[37002] is complete with uri-failure@T: javax.media.mscontrol.MsControlException: SPEAK[37002] is complete with uri-failure\n at com.voxeo.mscontrol.mediagroup.AsyncMrcpPlayer$MrcpSpeakListener.handleEvent(AsyncMrcpPlayer.java:1320)\n at com.voxeo.sipmethod.mrcp.client.impl.MrcpSessionImpl.postMrcpEvent(MrcpSessionImpl.java:261)\n at com.voxeo.sipmethod.mrcp.client.impl.MrcpTtsSessionImpl.handleEvent(MrcpTtsSessionImpl.java:537)\n at com.mot.mrcp.ec.motomrcpv1.MotV1MRCPConnection.postMrcpEvent(MotV1MRCPConnection.java:177)\n at com.mot.mrcp.ec.motomrcpv1.MotV1MRCPTTSConnection.handleSpeakComplete(MotV1MRCPTTSConnection.java:121)\n at com.voxeo.motorola.mrcp.VMotV1MRCPTTSConnection.handleSpeakComplete(VMotV1MRCPTTSConnection.java:54)\n at com.mot.mrcp.ec.motomrcpv1.MotV1MRCPTTSConnection.handleEventMessage(MotV1MRCPTTSConnection.java:61)\n at com.mot.mrcp.ec.motomrcpv1.MotV1MRCPConnection$QueueDispatcher.run(MotV1MRCPConnection.java:92)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n | |
| 2012-03-20 09:52:11.522 DEBUG [mrcp/2-t-22] #MSCTRL#: Player[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] moves state from [ACTIVE] to [IDLE] | |
| 2012-03-20 09:52:11.522 DEBUG [mrcp/2-t-22] #MSCTRL#: clear up playList=[PlayListItem[IDLE, gi=0, pi=2, ei=0, null]] | |
| 2012-03-20 09:52:11.523 DEBUG [msctrl/2-t-16] #MSCTRL#: Return PlayerEvent[Player[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]], PLAY_COMPLETED, NOT_FOUND, SPEAK[37002] is complete with uri-failure, NO_QUALIFIER, null, null, 0, -1] to the application | |
| 2012-03-20 09:52:11.524 DEBUG [MOHO-28] Dispatching Event to listener:[Event class=com.voxeo.moho.common.event.MohoOutputCompleteEvent sourceClass=SIPIncomingCall id=6992979] | |
| 2012-03-20 09:52:11.524 DEBUG [pool-21-thread-2] [IncomingCallActor[callId=4vg6dkqc-lx7-fxod8zouyy3mb]] : Request [[Event class=com.voxeo.moho.common.event.MohoOutputCompleteEvent sourceClass=SIPIncomingCall id=6992979]] | |
| 2012-03-20 09:52:11.526 INFO [pool-21-thread-2] Queued Event [OutputCompleteEvent[callId=4vg6dkqc-lx7-fxod8zouyy3mb,verbId=f8440d4f-464b-43d9-b48c-3ec686268457,reason=ERROR,errorText=Invalid SSML: The prefix "xml" cannot be bound to any namespace other than its usual namespace; neither can the namespace for "xml" be bound to any prefix other than "xml".]] | |
| 2012-03-20 09:52:11.526 INFO [pool-21-thread-2] Reply [null] | |
| 2012-03-20 09:52:11.526 INFO [pool-21-thread-2] Event [OutputCompleteEvent[callId=4vg6dkqc-lx7-fxod8zouyy3mb,verbId=f8440d4f-464b-43d9-b48c-3ec686268457,reason=ERROR,errorText=Invalid SSML: The prefix "xml" cannot be bound to any namespace other than its usual namespace; neither can the namespace for "xml" be bound to any prefix other than "xml".]] | |
| 2012-03-20 09:52:11.529 DEBUG [pool-21-thread-2] #XMPP#: (o)<presence from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home/f8440d4f-464b-43d9-b48c-3ec686268457" id="53797fbe-284b-4138-8f41-7886a7f64b0d" to="usera@127.0.0.1"><complete xmlns="urn:xmpp:rayo:ext:1"><error xmlns="urn:xmpp:rayo:ext:complete:1">Invalid SSML: The prefix "xml" cannot be bound to any namespace other than its usual namespace; neither can the namespace for "xml" be bound to any prefix other than "xml".</error></complete></presence> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:11.529 DEBUG [pool-21-thread-2] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:11.622 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq id="blather0012" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" type="set"><hangup xmlns="urn:xmpp:rayo:1"/></iq> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:11.623 DEBUG [XMPPService-t-36] #XMPP#: Invoke application:rayo rayo | |
| 2012-03-20 09:52:11.624 DEBUG [XMPPService-t-36] #XMPP#: Forwarding Request #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][null] | |
| 2012-03-20 09:52:11.624 DEBUG [XMPPService-t-36] <iq from="usera@127.0.0.1/blmbp.home-28910" id="blather0012" to="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" type="set"><hangup xmlns="urn:xmpp:rayo:1"/></iq> :: xmpps_l0328mignyvl | |
| 2012-03-20 09:52:11.624 DEBUG [XMPPService-t-36] Looking up call [4vg6dkqc-lx7-fxod8zouyy3mb] in registry: [com.rayo.server.DefaultCallRegistry@491a97] | |
| 2012-03-20 09:52:11.625 DEBUG [pool-21-thread-2] [IncomingCallActor[callId=4vg6dkqc-lx7-fxod8zouyy3mb]] : Request [HangupCommand[callId=4vg6dkqc-lx7-fxod8zouyy3mb,headers={}]] | |
| 2012-03-20 09:52:11.625 DEBUG [pool-21-thread-2] destroyNetworkConnection | |
| 2012-03-20 09:52:11.625 DEBUG [pool-21-thread-2] #MSCTRL#: NC[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] moves state from [INITIALIZED] to [RELEASED] | |
| 2012-03-20 09:52:11.626 INFO [pool-21-thread-2] #MSCTRL#: MS[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] removes a MediaObject[mscontrol://192.168.1.73:10074/MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u/NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] | |
| 2012-03-20 09:52:11.626 DEBUG [pool-21-thread-2] #MSCTRL#: MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] removes JoinCompleteDector[MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u], NC[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] #[797263084-a787590-01b1f470-00000002] | |
| 2012-03-20 09:52:11.626 DEBUG [pool-21-thread-2] #MSCTRL#: MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] removes JoineeMrcpContext[mscontrol://192.168.1.73:10074/MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u/NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, 797263084-a787590-01b1f470-00000002, 797263084-a787590-01b1f470-00000002] #[797263084-a787590-01b1f470-00000002] | |
| 2012-03-20 09:52:11.626 DEBUG [pool-21-thread-2] #MSCTRL#: MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] removed MrcpSpeakListener[Player[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]], ACTIVE] #[797263084-a787590-01b1f470-00000002] | |
| 2012-03-20 09:52:11.626 DEBUG [pool-21-thread-2] #MSCTRL#: Remove MrcpSpeakListener[Player[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]], ACTIVE] #[797263084-a787590-01b1f470-00000002] | |
| 2012-03-20 09:52:11.626 DEBUG [pool-21-thread-2] #MSCTRL#: MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] removes(NC[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, NC-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null]) | |
| 2012-03-20 09:52:11.627 DEBUG [pool-21-thread-2] #MRCP#: (o)TEARDOWN rtsp://192.168.1.73:10074/recognizer/ RTSP/1.0\r\nCseq: 6\r\nSession: 797263084-a787590-01b1f470-00000002\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:11.630 DEBUG [mrcp/2-t-23] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 797263084-a787590-01b1f470-00000002\r\nCseq: 6\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:11.631 DEBUG [pool-21-thread-2] #MRCP#: (o)TEARDOWN rtsp://192.168.1.73:10074/synthesizer/ RTSP/1.0\r\nCseq: 7\r\nSession: 797263084-a787590-01b1f470-00000002\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:11.640 DEBUG [mrcp/2-t-24] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 797263084-a787590-01b1f470-00000002\r\nCseq: 7\r\n\r\n #[797263084-a787590-01b1f470-00000002][192.168.1.73:10074][192.168.1.73:59747] | |
| 2012-03-20 09:52:11.641 DEBUG [pool-21-thread-2] #MSCTRL#: MS[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] moves state from [INITIALIZED] to [RELEASED] | |
| 2012-03-20 09:52:11.641 DEBUG [pool-21-thread-2] #MSCTRL#: MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u] moves state from [INITIALIZED] to [RELEASED] | |
| 2012-03-20 09:52:11.641 DEBUG [pool-21-thread-2] #MSCTRL#: Stopping Player[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]], isStopAll:true | |
| 2012-03-20 09:52:11.641 DEBUG [pool-21-thread-2] #MSCTRL#: Stopping SigDet[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] | |
| 2012-03-20 09:52:11.642 DEBUG [pool-21-thread-2] #MSCTRL#: Stopping Recorder[IDLE, MG[MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, MG-T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u]] | |
| 2012-03-20 09:52:11.642 DEBUG [pool-21-thread-2] #SIP#: SessionManagementLayer send request: BYE sip:rwbqgpia@127.0.0.1:59615 #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73][sip:usera@127.0.0.1] | |
| 2012-03-20 09:52:11.642 DEBUG [MOHO-29] Dispatching Event to listener:[Event class=com.voxeo.moho.common.event.MohoCallCompleteEvent sourceClass=SIPIncomingCall id=9690828] | |
| 2012-03-20 09:52:11.643 DEBUG [pool-21-thread-2] #SIP#: The transaction was created: z9hG4bKycje8bq2eyat #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.643 DEBUG [pool-21-thread-2] #SIP#: (o)[BYE sip:rwbqgpia@127.0.0.1:59615 SIP/2.0\r\nTo: "Ben Langfeld" <sip:rwbqgpia@192.168.1.73>;tag=c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL\r\nVia: SIP/2.0/UDP 192.168.1.73:5060;branch=z9hG4bKycje8bq2eyat;rport;x-sm-sid=27c0bbf0-53f7-44e4-8635-7062778d5903;x-sm-nid=ss_1hrqgtdr2wdid\r\nCSeq: 1 BYE\r\nContent-Length: 0\r\nCall-ID: T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u\r\nMax-Forwards: 70\r\nFrom: <sip:usera@127.0.0.1>;tag=dhgn9s9mk146\r\n\r\n] #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.643 DEBUG [pool-21-thread-2] #SIP#: Send message to: /127.0.0.1:59615 by udp #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.644 DEBUG [pool-21-thread-2] #SIP#: Connected to 127.0.0.1:59615/udp #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.644 INFO [pool-21-thread-2] Reply [null] | |
| 2012-03-20 09:52:11.644 DEBUG [pool-21-thread-2] #XMPP#: (o)<iq from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="blather0012" to="usera@127.0.0.1/blmbp.home-28910" type="result"/> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:11.645 DEBUG [pool-21-thread-2] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:11.645 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[SIP/2.0 200 OK\r\nTo: "Ben Langfeld" <sip:rwbqgpia@192.168.1.73>;tag=c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL\r\nVia: SIP/2.0/UDP 192.168.1.73:5060;rport=5060;received=127.0.0.1;branch=z9hG4bKycje8bq2eyat;x-sm-sid=27c0bbf0-53f7-44e4-8635-7062778d5903;x-sm-nid=ss_1hrqgtdr2wdid\r\nCSeq: 1 BYE\r\nContent-Length: 0\r\nCall-ID: T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u\r\nServer: Blink 0.24.1 (MacOSX)\r\nFrom: <sip:usera@127.0.0.1>;tag=dhgn9s9mk146\r\n\r\n] #[N/A][N/A][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][N/A][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.646 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Receive 200/BYE, branch=z9hG4bKycje8bq2eyat #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.648 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: NonInviteClientTransaction[, , _state=COMPLETED, _id=z9hG4bKycje8bq2eyat, ] is ready to release. #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.648 DEBUG [pool-21-thread-3] [IncomingCallActor[callId=4vg6dkqc-lx7-fxod8zouyy3mb]] : Request [[Event class=com.voxeo.moho.common.event.MohoCallCompleteEvent sourceClass=SIPIncomingCall id=9690828]] | |
| 2012-03-20 09:52:11.648 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv response: BYE/200 #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.650 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.651 DEBUG [udp/0.0.0.0/5060-t-3] SIPCallImpl[SipSessionAdaptor[sessionid=ss_1hrqgtdr2wdid, appSessionId=sas_2-15-sm1i1a8cbvif5iarayo, ],DISCONNECTED] is already terminated. | |
| 2012-03-20 09:52:11.651 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1i1a8cbvif5iarayo], invalidateWhenReady: true | |
| 2012-03-20 09:52:11.652 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_1hrqgtdr2wdid], current State = TERMINATED, Vaild:true, Role:UAS, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.652 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: server will automatically invalidate sipsession [ss_1hrqgtdr2wdid] #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.652 INFO [pool-21-thread-3] Queued Event [EndEvent[callId=4vg6dkqc-lx7-fxod8zouyy3mb,reason=HANGUP,errorText=<null>,headers=<null>]] | |
| 2012-03-20 09:52:11.654 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipSessionImpl[_id=ss_1hrqgtdr2wdid, _parentId=sas_2-15-sm1i1a8cbvif5iarayo, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=INVITE, _callId=T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, ] is invalidating. (s) #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.654 INFO [pool-21-thread-3] Call cleanup [call=SIPCallImpl[SipSessionAdaptor[sessionid=ss_1hrqgtdr2wdid, appSessionId=sas_2-15-sm1i1a8cbvif5iarayo, ],DISCONNECTED]] | |
| 2012-03-20 09:52:11.655 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Remove Path[ id=T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u-c9hgQjuQkAKpYJSoYBa1ZJFVuQq.M-iL-dhgn9s9mk146, session=SipSessionImpl[_id=ss_1hrqgtdr2wdid, _parentId=sas_2-15-sm1i1a8cbvif5iarayo, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=true, _role=UAS, _method=INVITE, _callId=T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u, ]] #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:11.655 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1i1a8cbvif5iarayo], invalidateWhenReady: true | |
| 2012-03-20 09:52:11.656 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-15-sm1i1a8cbvif5iarayo] | |
| 2012-03-20 09:52:11.656 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-15-sm1i1a8cbvif5iarayo, ] is invalidating. (as) | |
| 2012-03-20 09:52:11.655 DEBUG [pool-21-thread-3] Removing call [4vg6dkqc-lx7-fxod8zouyy3mb] from registry [com.rayo.server.DefaultCallRegistry@491a97] | |
| 2012-03-20 09:52:11.657 DEBUG [pool-21-thread-3] Removing call id 4vg6dkqc-lx7-fxod8zouyy3mb from the JID registry | |
| 2012-03-20 09:52:11.660 INFO [pool-21-thread-3] Reply [null] | |
| 2012-03-20 09:52:11.661 INFO [pool-21-thread-3] Event [EndEvent[callId=4vg6dkqc-lx7-fxod8zouyy3mb,reason=HANGUP,errorText=<null>,headers=<null>]] | |
| 2012-03-20 09:52:11.661 DEBUG [pool-21-thread-3] Storing CDR record for call id [4vg6dkqc-lx7-fxod8zouyy3mb] | |
| 2012-03-20 09:52:11.661 DEBUG [pool-21-thread-3] Removing CDR record from memory for call id [4vg6dkqc-lx7-fxod8zouyy3mb] | |
| 2012-03-20 09:52:11.665 DEBUG [pool-21-thread-3] #XMPP#: (o)<presence from="4vg6dkqc-lx7-fxod8zouyy3mb@blmbp.home" id="417b829a-1af7-4de2-94ce-b43134d08e15" to="usera@127.0.0.1"><end xmlns="urn:xmpp:rayo:1"><hangup/></end></presence> #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:11.665 DEBUG [pool-21-thread-3] #XMPP#: Send message to: 127.0.0.1:59745 by xmpp #[rayo][null][xmpps_l0328mignyvl][CLIENT][usera@127.0.0.1/blmbp.home-28910, 127.0.0.1][127.0.0.1:59745][127.0.0.1:5222][xmpp][N/A] | |
| 2012-03-20 09:52:16.646 DEBUG [Timer-15] #SIP#: NonInviteClientTransaction[, , _state=COMPLETED, _id=z9hG4bKycje8bq2eyat, ] timerRemoveTransaction is fired. #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] | |
| 2012-03-20 09:52:16.647 DEBUG [Timer-15] #SIP#: NonInviteClientTransaction[, , _state=TERMINATED, _id=z9hG4bKycje8bq2eyat, ] is released. #[rayo][sas_2-15-sm1i1a8cbvif5iarayo][T49vPNRHCy5ZvdAUueM3DJcXR5uU6z-u][ss_1hrqgtdr2wdid][sip:rwbqgpia@192.168.1.73(127.0.0.1:59615)][sip:usera@127.0.0.1(192.168.1.73:5060)] |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment