Created
August 3, 2011 20:07
-
-
Save zlu/1123634 to your computer and use it in GitHub Desktop.
dialing multiple endpoints with join
This file contains 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
| Use case: | |
| incoming offer to usera@127.0.0.1 (prism server) with tropo2 build 323. | |
| i issue two dials nested with join to zlu@iptel.org and openvoice@iptel.org | |
| neither endpoint rings and an error presence is returned. | |
| =========== START OF CONNFU LOG | |
| D, [2011-08-03T13:07:17.815233 #31271] DEBUG -- : Established @connection to Connfu Server with JID: jid://usera:1@127.0.0.1 | |
| D, [2011-08-03T13:07:17.834454 #31271] DEBUG -- : Queue implementation: #<Connfu::Queue::InProcess:0x00000100bfbc50 @queues={}> | |
| D, [2011-08-03T13:07:24.605770 #31271] DEBUG -- : Receiving presence from server | |
| D, [2011-08-03T13:07:24.606079 #31271] DEBUG -- : <presence from="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" to="usera@127.0.0.1/voxeo"> | |
| <offer xmlns="urn:xmpp:rayo:1" to="sip:usera@127.0.0.1" from="sip:hzrtuisw@192.168.0.196"> | |
| <header name="Max-Forwards" value="70"/> | |
| <header name="Content-Length" value="371"/> | |
| <header name="Contact" value="<sip:hzrtuisw@127.0.0.1:57638>"/> | |
| <header name="Supported" value="100rel"/> | |
| <header name="Allow" value="SUBSCRIBE"/> | |
| <header name="To" value="<sip:usera@127.0.0.1>"/> | |
| <header name="CSeq" value="9913 INVITE"/> | |
| <header name="User-Agent" value="Blink Lite 1.1.1 (MacOSX)"/> | |
| <header name="Via" value="SIP/2.0/UDP 192.168.0.196:57638;rport=57638;branch=z9hG4bKPjTeM8BPmnRbPBFO6FLWG5DK721CP7hUQw;received=127.0.0.1"/> | |
| <header name="Call-ID" value="pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0"/> | |
| <header name="Content-Type" value="application/sdp"/> | |
| <header name="From" value=""zhao lu" <sip:hzrtuisw@192.168.0.196>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM"/> | |
| </offer> | |
| </presence> | |
| D, [2011-08-03T13:07:24.615765 #31271] DEBUG -- : Handling event: #<Connfu::Event::Offer:0x00000100bcbde8 @presence_from="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1", @presence_to="usera@127.0.0.1/voxeo", @call_id="01eabcf8-a372-4572-9834-21beabc46f01", @from="\"zhao lu\" <sip:hzrtuisw@192.168.0.196>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM", @to={:address=>"sip:usera@127.0.0.1", :scheme=>"sip", :username=>"usera", :host=>"127.0.0.1"}> | |
| D, [2011-08-03T13:07:24.632068 #31271] DEBUG -- : <iq type="set" to="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" id="blather0008" from="usera@127.0.0.1/voxeo"> | |
| <answer xmlns="urn:xmpp:rayo:1"/> | |
| </iq> | |
| D, [2011-08-03T13:07:24.632499 #31271] DEBUG -- : Sent command: #<Connfu::Commands::Answer:0x000001009b8650> | |
| D, [2011-08-03T13:07:24.744085 #31271] DEBUG -- : Receiving iq from server | |
| D, [2011-08-03T13:07:24.744212 #31271] DEBUG -- : <iq type="result" id="blather0008" from="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" to="usera@127.0.0.1/voxeo"/> | |
| D, [2011-08-03T13:07:24.744609 #31271] DEBUG -- : Handling event: #<Connfu::Event::Result:0x0000010097fbe8 @call_id="01eabcf8-a372-4572-9834-21beabc46f01", @ref_id=nil, @command_id=nil> | |
| D, [2011-08-03T13:07:24.744739 #31271] DEBUG -- : Result from command #<Connfu::Event::Result:0x0000010097fbe8> | |
| D, [2011-08-03T13:07:24.744925 #31271] DEBUG -- : <iq type="set" to="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" id="blather000a" from="usera@127.0.0.1/voxeo"> | |
| <say xmlns="urn:xmpp:tropo:say:1">transferring</say> | |
| </iq> | |
| D, [2011-08-03T13:07:24.745248 #31271] DEBUG -- : Sent command: #<Connfu::Commands::Say:0x0000010097bf48> | |
| D, [2011-08-03T13:07:24.765688 #31271] DEBUG -- : Receiving iq from server | |
| D, [2011-08-03T13:07:24.765831 #31271] DEBUG -- : <iq type="result" id="blather000a" from="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" to="usera@127.0.0.1/voxeo"> | |
| <ref xmlns="urn:xmpp:rayo:1" id="92a715f6-ffa5-46fd-9ece-836a685b940b"/> | |
| </iq> | |
| D, [2011-08-03T13:07:24.766167 #31271] DEBUG -- : Handling event: #<Connfu::Event::Result:0x00000100954a38 @call_id="01eabcf8-a372-4572-9834-21beabc46f01", @ref_id="92a715f6-ffa5-46fd-9ece-836a685b940b", @command_id=nil> | |
| D, [2011-08-03T13:07:24.766293 #31271] DEBUG -- : Result from command #<Connfu::Event::Result:0x00000100954a38> | |
| D, [2011-08-03T13:07:25.474294 #31271] DEBUG -- : Receiving presence from server | |
| D, [2011-08-03T13:07:25.474458 #31271] DEBUG -- : <presence from="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1/92a715f6-ffa5-46fd-9ece-836a685b940b" to="usera@127.0.0.1/voxeo"> | |
| <complete xmlns="urn:xmpp:rayo:ext:1"> | |
| <success xmlns="urn:xmpp:tropo:say:complete:1"/> | |
| </complete> | |
| </presence> | |
| D, [2011-08-03T13:07:25.474750 #31271] DEBUG -- : Handling event: #<Connfu::Event::SayComplete:0x00000100918588 @call_id="01eabcf8-a372-4572-9834-21beabc46f01"> | |
| D, [2011-08-03T13:07:25.475042 #31271] DEBUG -- : <iq type="set" to="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" id="blather000c" from="usera@127.0.0.1/voxeo"> | |
| <dial xmlns="urn:xmpp:rayo:1" to="sip:openvoice@iptel.org" from="sip:zlu@iptel.org"> | |
| <join xmlns="urn:xmpp:rayo:join:1" direction="duplex" media="bridge" call-id="01eabcf8-a372-4572-9834-21beabc46f01"/> | |
| </dial> | |
| </iq> | |
| D, [2011-08-03T13:07:25.475427 #31271] DEBUG -- : Sent command: #<Connfu::Commands::NestedJoin:0x000001009162b0> | |
| D, [2011-08-03T13:07:25.483089 #31271] DEBUG -- : Receiving iq from server | |
| D, [2011-08-03T13:07:25.483233 #31271] DEBUG -- : <iq type="result" id="blather000c" from="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" to="usera@127.0.0.1/voxeo"> | |
| <ref xmlns="urn:xmpp:rayo:1" id="c4ccb713-9cb3-4e54-b0af-ad4f8509147c"/> | |
| </iq> | |
| D, [2011-08-03T13:07:25.483604 #31271] DEBUG -- : Handling event: #<Connfu::Event::Result:0x000001008daf30 @call_id="01eabcf8-a372-4572-9834-21beabc46f01", @ref_id="c4ccb713-9cb3-4e54-b0af-ad4f8509147c", @command_id=nil> | |
| D, [2011-08-03T13:07:25.483845 #31271] DEBUG -- : Result from command #<Connfu::Event::Result:0x000001008daf30> | |
| /Users/zlu/projects/thelab/play/lib/connfu/rayo/parser.rb:43:in `parse_event_from': Stanza not recognised: <presence from="c4ccb713-9cb3-4e54-b0af-ad4f8509147c@127.0.0.1" to="usera@127.0.0.1/voxeo"> (RuntimeError) | |
| <end xmlns="urn:xmpp:rayo:1"> | |
| <error/> | |
| </end> | |
| </presence> | |
| from /Users/zlu/projects/thelab/play/lib/connfu.rb:25:in `handle_stanza' | |
| from /Users/zlu/projects/thelab/play/lib/connfu/connection.rb:29:in `block (3 levels) in establish_connection' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:285:in `call' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:285:in `call_handler' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:276:in `block (2 levels) in call_handler_for' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:276:in `catch' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:276:in `block in call_handler_for' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:275:in `each' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:275:in `find' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:275:in `call_handler_for' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:268:in `block in handle_stanza' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:267:in `each' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:267:in `handle_stanza' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:186:in `block in receive_data' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:184:in `catch' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/client/client.rb:184:in `receive_data' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/stream.rb:200:in `receive' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/stream/parser.rb:97:in `deliver' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/stream/parser.rb:77:in `end_element_namespace' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/nokogiri-1.5.0/lib/nokogiri/xml/sax/push_parser.rb:47:in `native_write' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/nokogiri-1.5.0/lib/nokogiri/xml/sax/push_parser.rb:47:in `write' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/stream/parser.rb:23:in `receive_data' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/blather-0.5.3/lib/blather/stream.rb:149:in `receive_data' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run_machine' | |
| from /Users/zlu/.rvm/gems/ruby-1.9.2-p180/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run' | |
| from /Users/zlu/projects/thelab/play/lib/connfu.rb:32:in `start' | |
| from /Users/zlu/projects/thelab/play/examples/transfer_using_join.rb:4:in `<top (required)>' | |
| from -e:1:in `load' | |
| from -e:1:in `<main>' | |
| D, [2011-08-03T13:07:25.911587 #31271] DEBUG -- : Receiving presence from server | |
| D, [2011-08-03T13:07:25.911727 #31271] DEBUG -- : <presence from="c4ccb713-9cb3-4e54-b0af-ad4f8509147c@127.0.0.1" to="usera@127.0.0.1/voxeo"> | |
| <end xmlns="urn:xmpp:rayo:1"> | |
| <error/> | |
| </end> | |
| </presence> | |
| Process finished with exit code 1 | |
| =========== END OF CONNFU LOG | |
| 2011-08-03 13:07:17.771 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: Creating xmpp session with app: ApplicationImpl[_symbolicName=tropo2-0, _state=STARTED] #[N/A][N/A][N/A][?, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.772 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: Created session: XMPPSessionImpl: _id=xmpps_2050wl4ymix4, _direction=RECEIVEStream, _sessionType=CLIENT, _remotJID=null, _state=INITIAL, _remoteAddr=/127.0.0.1, _remotePort=55650, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo2-0, _state=STARTED] #[N/A][N/A][N/A][?, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.772 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"> #[tropo2][null][xmpps_2050wl4ymix4][?, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.773 DEBUG [XMPPService-t-40] #XMPP#: (o)<stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" xmlns:db="jabber:server:dialback" version="1.0" from="127.0.0.1" id="xmpps_2050wl4ymix4" xml:lang="en"> #[tropo2][null][xmpps_2050wl4ymix4][?, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.773 DEBUG [XMPPService-t-40] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][?, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.773 DEBUG [XMPPService-t-40] #XMPP#: (o)<stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism></mechanisms></stream:features> #[tropo2][null][xmpps_2050wl4ymix4][?, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.774 DEBUG [XMPPService-t-40] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][?, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.778 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">dXNlcmFAMTI3LjAuMC4xAHVzZXJhADE=</auth> #[tropo2][null][xmpps_2050wl4ymix4][?, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.785 DEBUG [XMPPService-t-40] #XMPP#: (o)<success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/> #[tropo2][null][xmpps_2050wl4ymix4][?, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.785 DEBUG [XMPPService-t-40] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][?, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.803 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"> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.803 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo | |
| 2011-08-03 13:07:17.803 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][null] | |
| 2011-08-03 13:07:17.804 DEBUG [XMPPService-t-40] #XMPP#: (o)<stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" xmlns:db="jabber:server:dialback" version="1.0" from="127.0.0.1" id="xmpps_2050wl4ymix4" xml:lang="en"> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.804 DEBUG [XMPPService-t-40] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.804 DEBUG [XMPPService-t-40] #XMPP#: (o)<stream:features><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></stream:features> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.804 DEBUG [XMPPService-t-40] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.806 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq type="set" id="blather0002">\n <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/>\n</iq> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.806 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo | |
| 2011-08-03 13:07:17.807 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][null] | |
| 2011-08-03 13:07:17.807 DEBUG [XMPPService-t-40] <iq type="set" id="blather0002" to="127.0.0.1" from="usera@127.0.0.1"> | |
| <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/> | |
| </iq> :: xmpps_2050wl4ymix4 | |
| 2011-08-03 13:07:17.807 DEBUG [XMPPService-t-40] #XMPP#: Intercept iq bind result, set full jid usera@127.0.0.1/voxeo to session XMPPSessionImpl: _id=xmpps_2050wl4ymix4, _direction=RECEIVEStream, _sessionType=CLIENT, _remotJID=usera@127.0.0.1/voxeo, _state=CONFIRMED, _remoteAddr=/127.0.0.1, _remotePort=55650, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo2-0, _state=STARTED] #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.808 DEBUG [XMPPService-t-40] #XMPP#: (o)<iq type="result" id="blather0002" from="127.0.0.1" to="usera@127.0.0.1"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>usera@127.0.0.1/voxeo</jid></bind></iq> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.808 DEBUG [XMPPService-t-40] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.808 INFO [XMPPService-t-40] Bound client resource [jid=usera@127.0.0.1/voxeo] | |
| 2011-08-03 13:07:17.810 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq type="set" id="blather0004" to="127.0.0.1">\n <session xmlns="urn:ietf:params:xml:ns:xmpp-session"/>\n</iq> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.811 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo | |
| 2011-08-03 13:07:17.811 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][null] | |
| 2011-08-03 13:07:17.811 DEBUG [XMPPService-t-40] <iq type="set" id="blather0004" to="127.0.0.1" from="usera@127.0.0.1/voxeo"> | |
| <session xmlns="urn:ietf:params:xml:ns:xmpp-session"/> | |
| </iq> :: xmpps_2050wl4ymix4 | |
| 2011-08-03 13:07:17.811 DEBUG [XMPPService-t-40] #XMPP#: (o)<iq type="result" id="blather0004" from="127.0.0.1" to="usera@127.0.0.1/voxeo"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.811 DEBUG [XMPPService-t-40] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.812 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq type="get" id="blather0006">\n <query xmlns="jabber:iq:roster"/>\n</iq> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.813 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo | |
| 2011-08-03 13:07:17.813 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][null] | |
| 2011-08-03 13:07:17.813 DEBUG [XMPPService-t-40] <iq type="get" id="blather0006" to="127.0.0.1" from="usera@127.0.0.1/voxeo"> | |
| <query xmlns="jabber:iq:roster"/> | |
| </iq> :: xmpps_2050wl4ymix4 | |
| 2011-08-03 13:07:17.813 DEBUG [XMPPService-t-40] #XMPP#: (o)<iq type="error" id="blather0006" to="usera@127.0.0.1/voxeo" from="127.0.0.1">\n <query xmlns="jabber:iq:roster"/>\n<error type="cancel"><feature-not-implemented xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.813 DEBUG [XMPPService-t-40] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.834 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<presence/> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:17.835 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo | |
| 2011-08-03 13:07:17.835 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][null] | |
| 2011-08-03 13:07:24.581 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.0.196:57638;rport;branch=z9hG4bKPjTeM8BPmnRbPBFO6FLWG5DK721CP7hUQw\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nCSeq: 9913 INVITE\r\nContent-Length: 371\r\nSupported: 100rel, norefersub\r\nCall-ID: pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0\r\nUser-Agent: Blink Lite 1.1.1 (MacOSX)\r\nFrom: "zhao lu" <sip:hzrtuisw@192.168.0.196>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\nMax-Forwards: 70\r\nContact: <sip:hzrtuisw@127.0.0.1:57638>\r\n\r\nv=0\r\no=- 3521390844 3521390844 IN IP4 127.0.0.1\r\ns=Blink Lite 1.1.1 (MacOSX)\r\nc=IN IP4 127.0.0.1\r\nt=0 0\r\nm=audio 50012 RTP/AVP 9 104 103 102 0 8 101\r\na=rtcp:50013\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:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n] #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.582 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: The transaction was created: z9hG4bKPjTeM8BPmnRbPBFO6FLWG5DK721CP7hUQw #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.582 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.0.196:57638;rport=57638;branch=z9hG4bKPjTeM8BPmnRbPBFO6FLWG5DK721CP7hUQw;received=127.0.0.1\r\nCSeq: 9913 INVITE\r\nContent-Length: 0\r\nCall-ID: pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0\r\nFrom: "zhao lu" <sip:hzrtuisw@192.168.0.196>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\n\r\n] #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:usera@127.0.0.1(127.0.0.1:57638)][sip:hzrtuisw@192.168.0.196(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.582 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Send message to: /127.0.0.1:57638 by udp #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:usera@127.0.0.1(127.0.0.1:57638)][sip:hzrtuisw@192.168.0.196(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.583 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Connected to 127.0.0.1:57638/udp #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:usera@127.0.0.1(127.0.0.1:57638)][sip:hzrtuisw@192.168.0.196(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.583 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Found [tropo2] to handle the request by alphabet. | |
| 2011-08-03 13:07:24.584 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipApplicationInfo: SipApplicationRouterInfo[ApplicationName=tropo2, RouteModifier=NO_ROUTE, RouteRegion=null, SubscriberURI=sip:usera@127.0.0.1, StateInfo=tropo2] #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.585 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Session creating: ss_17xx8ycfew2y2 #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.586 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Session created:SipSessionImpl[_id=ss_17xx8ycfew2y2, _parentId=sas_2-15-sm1v8gyoyy16n50tropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UNKNOW, _method=INVITE, _callId=pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.586 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv request: INVITE #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.586 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ApplicationDispatchLayer invoke application: Controller with INVITE #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.586 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.588 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1v8gyoyy16n50tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:24.589 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_17xx8ycfew2y2], current State = INITIAL, Vaild:true, Role:UNKNOW, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.589 DEBUG [MOHO-23] Received incoming call | |
| 2011-08-03 13:07:24.590 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1v8gyoyy16n50tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:24.593 INFO [pool-16-thread-7] Message [SIPCallImpl[SipSessionAdaptor[sessionid=ss_17xx8ycfew2y2, appSessionId=sas_2-15-sm1v8gyoyy16n50tropo2],INVITING]] | |
| 2011-08-03 13:07:24.593 INFO [pool-16-thread-7] Incoming Call [SIPCallImpl[SipSessionAdaptor[sessionid=ss_17xx8ycfew2y2, appSessionId=sas_2-15-sm1v8gyoyy16n50tropo2],INVITING]] | |
| 2011-08-03 13:07:24.597 INFO [pool-16-thread-8] Message [SIPCallImpl[SipSessionAdaptor[sessionid=ss_17xx8ycfew2y2, appSessionId=sas_2-15-sm1v8gyoyy16n50tropo2],INVITING]] | |
| 2011-08-03 13:07:24.602 INFO [pool-16-thread-8] Queued Event [OfferEvent[from=sip:hzrtuisw@192.168.0.196,to=sip:usera@127.0.0.1,headers={Max-Forwards=70, Content-Length=371, Contact=<sip:hzrtuisw@127.0.0.1:57638>, Supported=100rel, Allow=SUBSCRIBE, To=<sip:usera@127.0.0.1>, CSeq=9913 INVITE, User-Agent=Blink Lite 1.1.1 (MacOSX), Via=SIP/2.0/UDP 192.168.0.196:57638;rport=57638;branch=z9hG4bKPjTeM8BPmnRbPBFO6FLWG5DK721CP7hUQw;received=127.0.0.1, Call-ID=pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, Content-Type=application/sdp, From="zhao lu" <sip:hzrtuisw@192.168.0.196>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM}]] | |
| 2011-08-03 13:07:24.602 INFO [pool-16-thread-8] Event [OfferEvent[from=sip:hzrtuisw@192.168.0.196,to=sip:usera@127.0.0.1,headers={Max-Forwards=70, Content-Length=371, Contact=<sip:hzrtuisw@127.0.0.1:57638>, Supported=100rel, Allow=SUBSCRIBE, To=<sip:usera@127.0.0.1>, CSeq=9913 INVITE, User-Agent=Blink Lite 1.1.1 (MacOSX), Via=SIP/2.0/UDP 192.168.0.196:57638;rport=57638;branch=z9hG4bKPjTeM8BPmnRbPBFO6FLWG5DK721CP7hUQw;received=127.0.0.1, Call-ID=pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, Content-Type=application/sdp, From="zhao lu" <sip:hzrtuisw@192.168.0.196>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM}]] | |
| 2011-08-03 13:07:24.603 DEBUG [pool-16-thread-8] #XMPP#: (o)<presence from="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" to="usera@127.0.0.1/voxeo"><offer xmlns="urn:xmpp:rayo:1" to="sip:usera@127.0.0.1" from="sip:hzrtuisw@192.168.0.196"><header name="Max-Forwards" value="70"/><header name="Content-Length" value="371"/><header name="Contact" value="<sip:hzrtuisw@127.0.0.1:57638>"/><header name="Supported" value="100rel"/><header name="Allow" value="SUBSCRIBE"/><header name="To" value="<sip:usera@127.0.0.1>"/><header name="CSeq" value="9913 INVITE"/><header name="User-Agent" value="Blink Lite 1.1.1 (MacOSX)"/><header name="Via" value="SIP/2.0/UDP 192.168.0.196:57638;rport=57638;branch=z9hG4bKPjTeM8BPmnRbPBFO6FLWG5DK721CP7hUQw;received=127.0.0.1"/><header name="Call-ID" value="pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0"/><header name="Content-Type" value="application/sdp"/><header name="From" value=""zhao lu" <sip:hzrtuisw@192.168.0.196>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM"/></offer></presence> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:24.603 DEBUG [pool-16-thread-8] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:24.633 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq type="set" to="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" id="blather0008" from="usera@127.0.0.1/voxeo">\n <answer xmlns="urn:xmpp:rayo:1"/>\n</iq> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:24.634 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo | |
| 2011-08-03 13:07:24.634 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][null] | |
| 2011-08-03 13:07:24.634 DEBUG [XMPPService-t-40] <iq type="set" to="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" id="blather0008" from="usera@127.0.0.1/voxeo"> | |
| <answer xmlns="urn:xmpp:rayo:1"/> | |
| </iq> :: xmpps_2050wl4ymix4 | |
| 2011-08-03 13:07:24.635 INFO [pool-16-thread-8] Request [AnswerCommand[callId=01eabcf8-a372-4572-9834-21beabc46f01,headers={}]] | |
| 2011-08-03 13:07:24.635 DEBUG [pool-16-thread-8] #SIP#: SessionManagementLayer send response: INVITE/180 #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.636 DEBUG [pool-16-thread-8] #SIP#: Add Path[ id=pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0-aae42w5hPaSi52Li3Cx3ISYbjG5f69YM-jzv9jycn3ikx, session=SipSessionImpl[_id=ss_17xx8ycfew2y2, _parentId=sas_2-15-sm1v8gyoyy16n50tropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=INVITE, _callId=pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0], party= CALLER] #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.636 DEBUG [pool-16-thread-8] #SIP#: (o)[SIP/2.0 180 Ringing\r\nTo: <sip:usera@127.0.0.1>;tag=jzv9jycn3ikx\r\nVia: SIP/2.0/UDP 192.168.0.196:57638;rport=57638;branch=z9hG4bKPjTeM8BPmnRbPBFO6FLWG5DK721CP7hUQw;received=127.0.0.1\r\nCSeq: 9913 INVITE\r\nContent-Length: 0\r\nCall-ID: pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0\r\nFrom: "zhao lu" <sip:hzrtuisw@192.168.0.196>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\n\r\n] #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.637 DEBUG [pool-16-thread-8] #SIP#: Send message to: /127.0.0.1:57638 by udp #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.637 DEBUG [pool-16-thread-8] #SIP#: Connected to 127.0.0.1:57638/udp #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.637 DEBUG [pool-16-thread-8] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1v8gyoyy16n50tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:24.637 DEBUG [pool-16-thread-8] #SIP#: processInvalidationWhenReady [ss_17xx8ycfew2y2], current State = EARLY, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.638 DEBUG [pool-16-thread-8] #SIP#: processInvalidationWhenReady [sas_2-15-sm1v8gyoyy16n50tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:24.640 DEBUG [MOHO-24] Set ms id with call id :pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0 | |
| 2011-08-03 13:07:24.641 INFO [MOHO-24] #MSCTRL#: MS[MS-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] updates MEDIAOBJECT_ID, old:"ms2-6", new:"MS-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0" | |
| 2011-08-03 13:07:24.641 DEBUG [MOHO-24] Set nc id with call id :pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0 | |
| 2011-08-03 13:07:24.641 INFO [MOHO-24] #MSCTRL#: MS[NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] updates MEDIAOBJECT_ID, old:"MS-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0", new:"NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0" | |
| 2011-08-03 13:07:24.641 INFO [MOHO-24] #MSCTRL#: MS[NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] creates a MediaObject[BASIC, NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, {MEDIAOBJECT_ID=NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0}] | |
| 2011-08-03 13:07:24.641 INFO [MOHO-24] #MSCTRL#: SdpPort[IDLE, NC[NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]] processes a SDP offer \nv=0\r\no=- 3521390844 3521390844 IN IP4 127.0.0.1\r\ns=Blink Lite 1.1.1 (MacOSX)\r\nc=IN IP4 127.0.0.1\r\nt=0 0\r\nm=audio 50012 RTP/AVP 9 104 103 102 0 8 101\r\na=rtcp:50013\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:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n | |
| 2011-08-03 13:07:24.645 DEBUG [MOHO-24] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]] moves state from [IDLE] to [UNDER_PROCESSING] | |
| 2011-08-03 13:07:24.645 DEBUG [MOHO-24] Start wait joinDelegate. CallID:pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0 | |
| 2011-08-03 13:07:24.646 INFO [msctrl/2-t-6] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer | |
| 2011-08-03 13:07:24.647 DEBUG [msctrl/2-t-6] #MRCP#: load configuration from {maxThreadPool=2147483647, minThreadPool=25, MEDIAOBJECT_ID=NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, com.voxeo.useLocalConfigurationOnGUTFailures=false} | |
| 2011-08-03 13:07:24.660 DEBUG [msctrl/2-t-6] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/recognizer/ RTSP/1.0\r\nCseq: 1\r\nTransport: RTP/AVP;unicast;\r\nContent-Type: application/sdp\r\nContent-Length: 371\r\n\r\nv=0\r\no=- 3521390844 3521390844 IN IP4 127.0.0.1\r\ns=Blink Lite 1.1.1 (MacOSX)\r\nc=IN IP4 127.0.0.1\r\nt=0 0\r\nm=audio 50012 RTP/AVP 9 104 103 102 0 8 101\r\na=rtcp:50013\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:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n #[N/A][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:24.669 DEBUG [mrcp/2-t-24] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2437019367-2a44e00-0ac46f50-00000006\r\nTransport: RTP/AVP;unicast;client_port=50012-50013;server_port=20010-20011\r\nCseq: 1\r\nContent-Type: application/sdp\r\nContent-Length: 167\r\n\r\nv=0\r\no=- 15 15 IN IP4 127.0.0.1\r\ns=voxeo\r\nc=IN IP4 127.0.0.1\r\nt=0 0\r\nm=audio 20010 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n #[N/A][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:24.670 DEBUG [msctrl/2-t-6] #MSCTRL#: NC[NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] initializes the ASR session. #[2437019367-2a44e00-0ac46f50-00000006] | |
| 2011-08-03 13:07:24.672 DEBUG [msctrl/2-t-6] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/synthesizer/ RTSP/1.0\r\nCseq: 2\r\nTransport: RTP/AVP;unicast;\r\nSession: 2437019367-2a44e00-0ac46f50-00000006\r\n\r\n #[2437019367-2a44e00-0ac46f50-00000006][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:24.680 DEBUG [mrcp/2-t-24] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2437019367-2a44e00-0ac46f50-00000006\r\nTransport: RTP/AVP;unicast;client_port=50012-50013;server_port=20010-20011\r\nCseq: 2\r\n\r\n #[2437019367-2a44e00-0ac46f50-00000006][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:24.680 DEBUG [msctrl/2-t-6] #MSCTRL#: NC[NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] initializes the TTS session. #[2437019367-2a44e00-0ac46f50-00000006] | |
| 2011-08-03 13:07:24.680 DEBUG [msctrl/2-t-6] #MSCTRL#: SdpPort[SDP_NEGOTIATED, NC[NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATED] | |
| 2011-08-03 13:07:24.680 DEBUG [msctrl/2-t-6] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATED, NC[NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]], ANSWER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 15 15 IN IP4 127.0.0.1\r\ns=voxeo\r\nc=IN IP4 127.0.0.1\r\nt=0 0\r\nm=audio 20010 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n] to the application | |
| 2011-08-03 13:07:24.681 DEBUG [msctrl/2-t-6] #SIP#: SessionManagementLayer send response: INVITE/200 #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.682 DEBUG [msctrl/2-t-6] #SIP#: (o)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:usera@127.0.0.1>;tag=jzv9jycn3ikx\r\nVia: SIP/2.0/UDP 192.168.0.196:57638;rport=57638;branch=z9hG4bKPjTeM8BPmnRbPBFO6FLWG5DK721CP7hUQw;received=127.0.0.1\r\nCSeq: 9913 INVITE\r\nContent-Length: 167\r\nCall-ID: pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0\r\nFrom: "zhao lu" <sip:hzrtuisw@192.168.0.196>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\nContact: <sip:192.168.0.196:5060;transport=udp>\r\n\r\nv=0\r\no=- 15 15 IN IP4 127.0.0.1\r\ns=voxeo\r\nc=IN IP4 127.0.0.1\r\nt=0 0\r\nm=audio 20010 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n] #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.682 DEBUG [msctrl/2-t-6] #SIP#: Send message to: /127.0.0.1:57638 by udp #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.682 DEBUG [msctrl/2-t-6] #SIP#: Connected to 127.0.0.1:57638/udp #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.682 DEBUG [msctrl/2-t-6] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1v8gyoyy16n50tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:24.682 DEBUG [msctrl/2-t-6] #SIP#: processInvalidationWhenReady [ss_17xx8ycfew2y2], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.683 DEBUG [msctrl/2-t-6] #SIP#: processInvalidationWhenReady [sas_2-15-sm1v8gyoyy16n50tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:24.684 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[ACK sip:192.168.0.196:5060;transport=udp SIP/2.0\r\nTo: <sip:usera@127.0.0.1>;tag=jzv9jycn3ikx\r\nVia: SIP/2.0/UDP 192.168.0.196:57638;rport;branch=z9hG4bKPjhwZHTWrv9iCvygT5KM1ynvtOhHW1vr6P\r\nCSeq: 9913 ACK\r\nContent-Length: 0\r\nCall-ID: pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0\r\nUser-Agent: Blink Lite 1.1.1 (MacOSX)\r\nFrom: "zhao lu" <sip:hzrtuisw@192.168.0.196>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\nMax-Forwards: 70\r\n\r\n] #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.692 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Find Path[ id=pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0-aae42w5hPaSi52Li3Cx3ISYbjG5f69YM-jzv9jycn3ikx, path=ApplicationPath[_id=pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0-aae42w5hPaSi52Li3Cx3ISYbjG5f69YM-jzv9jycn3ikx, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_17xx8ycfew2y2, appSessionId=sas_2-15-sm1v8gyoyy16n50tropo2]]]]]] #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.693 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv request: ACK #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.693 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ApplicationDispatchLayer invoke application: Controller with ACK #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.693 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.693 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1v8gyoyy16n50tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:24.694 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_17xx8ycfew2y2], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:24.694 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1v8gyoyy16n50tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:24.697 INFO [pool-16-thread-8] Reply [null] | |
| 2011-08-03 13:07:24.702 DEBUG [pool-16-thread-8] #XMPP#: (o)<iq type="result" id="blather0008" from="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" to="usera@127.0.0.1/voxeo"/> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:24.702 DEBUG [pool-16-thread-8] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:24.722 INFO [pool-16-thread-7] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPIncomingCall]] | |
| 2011-08-03 13:07:24.746 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq type="set" to="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" id="blather000a" from="usera@127.0.0.1/voxeo">\n <say xmlns="urn:xmpp:tropo:say:1">transferring</say>\n</iq> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:24.746 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo | |
| 2011-08-03 13:07:24.746 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][null] | |
| 2011-08-03 13:07:24.746 DEBUG [XMPPService-t-40] <iq type="set" to="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" id="blather000a" from="usera@127.0.0.1/voxeo"> | |
| <say xmlns="urn:xmpp:tropo:say:1">transferring</say> | |
| </iq> :: xmpps_2050wl4ymix4 | |
| 2011-08-03 13:07:24.748 INFO [pool-16-thread-7] Request [Say[callId=01eabcf8-a372-4572-9834-21beabc46f01,verbId=1d5e2a8a-afe4-4c66-9ab0-9d66f674579b,prompt=Ssml[ssml=transferring,voice=<null>,uri=data:application%2Fssml%2Bxml%2C%3Cspeak%3Etransferring%3C%2Fspeak%3E]]] | |
| 2011-08-03 13:07:24.748 DEBUG [pool-16-thread-7] Creating instance of bean 'sayHandler' | |
| 2011-08-03 13:07:24.748 DEBUG [pool-16-thread-7] Returning cached instance of singleton bean 'ssmlValidator' | |
| 2011-08-03 13:07:24.749 DEBUG [pool-16-thread-7] Finished creating instance of bean 'sayHandler' | |
| 2011-08-03 13:07:24.751 DEBUG [pool-16-thread-7] Set mg id with call id :pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0 | |
| 2011-08-03 13:07:24.752 INFO [pool-16-thread-7] #MSCTRL#: MS[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] updates MEDIAOBJECT_ID, old:"NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0", new:"MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0" | |
| 2011-08-03 13:07:24.752 INFO [pool-16-thread-7] #MSCTRL#: MS[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] creates a MediaObject[PLAYER_RECORDER_SIGNALDETECTOR, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, {MEDIAOBJECT_ID=MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0}] | |
| 2011-08-03 13:07:24.752 INFO [pool-16-thread-7] #MSCTRL#: MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] joins to NC[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] in DUPLEX | |
| 2011-08-03 13:07:24.753 DEBUG [pool-16-thread-7] #MSCTRL#: MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] adds JoineeMrcpContext[mscontrol://192.168.0.196:10074/MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0/NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, 2437019367-2a44e00-0ac46f50-00000006, 2437019367-2a44e00-0ac46f50-00000006] #[2437019367-2a44e00-0ac46f50-00000006] | |
| 2011-08-03 13:07:24.753 DEBUG [pool-16-thread-7] #MSCTRL#: NC[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] adds(MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null]) | |
| 2011-08-03 13:07:24.753 DEBUG [pool-16-thread-7] #MSCTRL#: MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] adds(NC[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null]) | |
| 2011-08-03 13:07:24.753 DEBUG [pool-16-thread-7] #MSCTRL#: Add PlayListItem[0, 0, false, rtcs=null, optargs={PLAYER_START_PAUSED=false, JUMP_PLAYLIST_INCREMENT=1, PLAYER_START_OFFSET=0, PLAYER_JUMP_TIME=5000, VOLUME_CHANGE=3, PLAYER_MAX_DURATION=-1, PLAYER_FILE_FORMAT=FORMAT_INFERRED, BARGE_IN_ENABLED=false, BEHAVIOUR_IF_BUSY=QUEUE_IF_BUSY, PLAYER_AUDIO_CODEC=CODEC_INFERRED, VOICE_NAME=null, PLAYER_ENABLED_EVENTS=[Ljavax.media.mscontrol.EventType;@95c1ab},"<speak>transferring</speak>"] | |
| 2011-08-03 13:07:24.754 DEBUG [pool-16-thread-7] #MSCTRL#: Find PlayListItem[IDLE, 0, 0, false] | |
| 2011-08-03 13:07:24.755 DEBUG [pool-16-thread-7] #MSCTRL#: Player[IDLE, MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]] starts playing PlayListItem[IDLE, 0, 0, false] | |
| 2011-08-03 13:07:24.755 DEBUG [pool-16-thread-7] #MSCTRL#: Player[ACTIVE, MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]] moves state from [IDLE] to [ACTIVE] | |
| 2011-08-03 13:07:24.755 DEBUG [pool-16-thread-7] #MSCTRL#: PlayListItem[0, 0] moves state from [IDLE] to [PLAYING] | |
| 2011-08-03 13:07:24.755 DEBUG [pool-16-thread-7] #MSCTRL#: MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] added MrcpSpeakListener[Player[ACTIVE, MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]], ACTIVE] #[2437019367-2a44e00-0ac46f50-00000006] | |
| 2011-08-03 13:07:24.758 DEBUG [pool-16-thread-7] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.196:10074/synthesizer/ RTSP/1.0\r\nCseq: 3\r\nSession: 2437019367-2a44e00-0ac46f50-00000006\r\nContent-Type: application/mrcp\r\nContent-Length: 218\r\n\r\nSPEAK 53000 MRCP/1.0\r\nKill-On-Barge-In: false\r\nSpeech-Language: en-US\r\nVendor-Specific-Parameters: Voxeo-Playback-Mode=JSR309\r\nContent-Type: application/synthesis+ssml\r\nContent-Length: 27\r\n\r\n<speak>transferring</speak> #[2437019367-2a44e00-0ac46f50-00000006][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:24.761 DEBUG [mrcp/2-t-24] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2437019367-2a44e00-0ac46f50-00000006\r\nCseq: 3\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 53000 200 IN-PROGRESS\r\n\r\n #[2437019367-2a44e00-0ac46f50-00000006][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:24.762 DEBUG [pool-16-thread-7] #MSCTRL#: PlayListItem[0, 0] added (53000, 2437019367-2a44e00-0ac46f50-00000006) | |
| 2011-08-03 13:07:24.764 INFO [pool-16-thread-7] Reply [com.tropo.core.verb.VerbRef@1eff444] | |
| 2011-08-03 13:07:24.764 DEBUG [pool-16-thread-7] #XMPP#: (o)<iq type="result" id="blather000a" from="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" to="usera@127.0.0.1/voxeo"><ref xmlns="urn:xmpp:rayo:1" id="92a715f6-ffa5-46fd-9ece-836a685b940b"/></iq> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:24.764 DEBUG [pool-16-thread-7] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:25.468 DEBUG [mrcp/2-t-24] #MRCP#: (i)ANNOUNCE rtsp://192.168.0.196:10074/synthesizer/ RTSP/1.0\r\nCseq: 1\r\nSession: 2437019367-2a44e00-0ac46f50-00000006\r\nContent-Type: application/mrcp\r\nContent-Length: 72\r\n\r\nSPEAK-COMPLETE 53000 COMPLETE MRCP/1.0\r\ncompletion-cause: 000 normal\r\n\r\n #[2437019367-2a44e00-0ac46f50-00000006][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:25.468 DEBUG [mrcp/2-t-24] #MRCP#: (o)RTSP/1.0 200 OK\r\nSession: 2437019367-2a44e00-0ac46f50-00000006\r\nCseq: 1\r\n\r\n #[2437019367-2a44e00-0ac46f50-00000006][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:25.469 DEBUG [mrcp/2-t-25] #MRCP#: Handling SPEAK-COMPLETE[53000] #[2437019367-2a44e00-0ac46f50-00000006][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:25.470 DEBUG [mrcp/2-t-25] #MSCTRL#: Find PlayListItem[PLAYING, 0, 0, false, speakIds=[53000]] | |
| 2011-08-03 13:07:25.470 DEBUG [mrcp/2-t-25] #MSCTRL#: MrcpSpeakListener[Player[ACTIVE, MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]], ACTIVE] handling with MrcpSpeakCompleteEvent[originalId:53000, requestId:53000, rc:0, duration:715] #[2437019367-2a44e00-0ac46f50-00000006] | |
| 2011-08-03 13:07:25.470 DEBUG [mrcp/2-t-25] #MSCTRL#: PlayListItem[0, 0] removed (53000, 2437019367-2a44e00-0ac46f50-00000006) | |
| 2011-08-03 13:07:25.470 DEBUG [mrcp/2-t-25] #MSCTRL#: PlayListItem[0, 0] moves state from [PLAYING] to [IDLE] | |
| 2011-08-03 13:07:25.470 DEBUG [mrcp/2-t-25] #MSCTRL#: Player[IDLE, MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]] moves state from [ACTIVE] to [IDLE] | |
| 2011-08-03 13:07:25.471 DEBUG [mrcp/2-t-25] #MSCTRL#: clear up playList=[PlayListItem[IDLE, 0, 0, false]] | |
| 2011-08-03 13:07:25.471 DEBUG [mrcp/2-t-25] #MSCTRL#: Return PlayerEvent[Player[IDLE, MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]], PLAY_COMPLETED, NO_ERROR, null, END_OF_PLAY_LIST, null, null, 0, 715] to the application | |
| 2011-08-03 13:07:25.472 INFO [pool-16-thread-7] Message [[Event class=com.voxeo.moho.event.MohoOutputCompleteEvent sourceClass=SIPIncomingCall]] | |
| 2011-08-03 13:07:25.472 INFO [pool-16-thread-7] Queued Event [SayCompleteEvent[callId=01eabcf8-a372-4572-9834-21beabc46f01,verbId=92a715f6-ffa5-46fd-9ece-836a685b940b,reason=SUCCESS,errorText=<null>]] | |
| 2011-08-03 13:07:25.472 INFO [pool-16-thread-7] Event [SayCompleteEvent[callId=01eabcf8-a372-4572-9834-21beabc46f01,verbId=92a715f6-ffa5-46fd-9ece-836a685b940b,reason=SUCCESS,errorText=<null>]] | |
| 2011-08-03 13:07:25.472 DEBUG [pool-16-thread-7] #XMPP#: (o)<presence from="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1/92a715f6-ffa5-46fd-9ece-836a685b940b" to="usera@127.0.0.1/voxeo"><complete xmlns="urn:xmpp:rayo:ext:1"><success xmlns="urn:xmpp:tropo:say:complete:1"/></complete></presence> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:25.473 DEBUG [pool-16-thread-7] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:25.476 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq type="set" to="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" id="blather000c" from="usera@127.0.0.1/voxeo">\n <dial xmlns="urn:xmpp:rayo:1" to="sip:openvoice@iptel.org" from="sip:zlu@iptel.org">\n <join xmlns="urn:xmpp:rayo:join:1" direction="duplex" media="bridge" call-id="01eabcf8-a372-4572-9834-21beabc46f01"/>\n </dial>\n</iq> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:25.476 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo | |
| 2011-08-03 13:07:25.477 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][null] | |
| 2011-08-03 13:07:25.477 DEBUG [XMPPService-t-40] <iq type="set" to="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" id="blather000c" from="usera@127.0.0.1/voxeo"> | |
| <dial xmlns="urn:xmpp:rayo:1" to="sip:openvoice@iptel.org" from="sip:zlu@iptel.org"> | |
| <join xmlns="urn:xmpp:rayo:join:1" direction="duplex" media="bridge" call-id="01eabcf8-a372-4572-9834-21beabc46f01"/> | |
| </dial> | |
| </iq> :: xmpps_2050wl4ymix4 | |
| 2011-08-03 13:07:25.478 INFO [pool-16-thread-7] Request [DialCommand[from=sip:zlu@iptel.org,to=sip:openvoice@iptel.org,headers={},join=JoinCommand[callId=<null>,direction=DUPLEX,media=BRIDGE,to=01eabcf8-a372-4572-9834-21beabc46f01,type=CALL]]] | |
| 2011-08-03 13:07:25.481 INFO [pool-16-thread-7] Reply [com.tropo.core.CallRef@142b716] | |
| 2011-08-03 13:07:25.481 DEBUG [pool-16-thread-7] #XMPP#: (o)<iq type="result" id="blather000c" from="01eabcf8-a372-4572-9834-21beabc46f01@127.0.0.1" to="usera@127.0.0.1/voxeo"><ref xmlns="urn:xmpp:rayo:1" id="c4ccb713-9cb3-4e54-b0af-ad4f8509147c"/></iq> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:25.481 DEBUG [pool-16-thread-7] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:25.485 INFO [pool-16-thread-9] Message [SIPCallImpl[null,INITIALIZED]] | |
| 2011-08-03 13:07:25.488 INFO [MOHO-27] #MSCTRL#: MS[ms2-7] creates a MediaObject[BASIC, nc1, null] | |
| 2011-08-03 13:07:25.488 INFO [MOHO-27] #MSCTRL#: SdpPort[IDLE, NC[ms2-7, nc1]] generates a SDP offer | |
| 2011-08-03 13:07:25.488 DEBUG [MOHO-27] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-7, nc1]] moves state from [IDLE] to [UNDER_PROCESSING] | |
| 2011-08-03 13:07:25.489 DEBUG [msctrl/2-t-7] #MRCP#: load configuration from {maxThreadPool=2147483647, minThreadPool=25, MEDIAOBJECT_ID=nc1, com.voxeo.useLocalConfigurationOnGUTFailures=false} | |
| 2011-08-03 13:07:25.500 DEBUG [msctrl/2-t-7] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 1\r\n\r\n #[N/A][192.168.0.196:10074][192.168.0.196:55658] | |
| 2011-08-03 13:07:25.511 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2437020209-2b3f200-0ac46f50-00000007\r\nTransport: RTP/AVP;unicast;client_port=65535-65536;server_port=20012-20013\r\nCseq: 1\r\nContent-Type: application/sdp\r\nContent-Length: 421\r\n\r\nv=0\r\no=- 11 11 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20012 RTP/AVP 0 8 101 115 116 111 9 3 117 112 113\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r\na=rtpmap:115 SPEEX/8000\r\na=rtpmap:116 SPEEX/16000\r\na=rtpmap:111 G726-32/8000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:3 GSM/8000\r\na=rtpmap:117 SPEEX/32000\r\na=rtpmap:112 L16/8000\r\na=rtpmap:113 L16/16000\r\na=ptime:20\r\n #[N/A][192.168.0.196:10074][192.168.0.196:55658] | |
| 2011-08-03 13:07:25.511 DEBUG [msctrl/2-t-7] #MSCTRL#: NC[ms2-7, nc1] initializes the ASR session. #[2437020209-2b3f200-0ac46f50-00000007] | |
| 2011-08-03 13:07:25.511 INFO [msctrl/2-t-7] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer | |
| 2011-08-03 13:07:25.512 DEBUG [msctrl/2-t-7] #MSCTRL#: SdpPort[SDP_NEGOTIATING, NC[ms2-7, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATING] | |
| 2011-08-03 13:07:25.512 DEBUG [msctrl/2-t-7] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATING, NC[ms2-7, nc1]], OFFER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 11 11 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20012 RTP/AVP 0 8 101 115 116 111 9 3 117 112 113\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r\na=rtpmap:115 SPEEX/8000\r\na=rtpmap:116 SPEEX/16000\r\na=rtpmap:111 G726-32/8000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:3 GSM/8000\r\na=rtpmap:117 SPEEX/32000\r\na=rtpmap:112 L16/8000\r\na=rtpmap:113 L16/16000\r\na=ptime:20\r\n] to the application | |
| 2011-08-03 13:07:25.513 DEBUG [msctrl/2-t-7] #SIP#: Session creating: ss_1k2rzt1grsoon #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org][sip:zlu@iptel.org] | |
| 2011-08-03 13:07:25.513 DEBUG [msctrl/2-t-7] #SIP#: SetRoutingDirective: NEW #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org][sip:zlu@iptel.org] | |
| 2011-08-03 13:07:25.514 DEBUG [msctrl/2-t-7] #SIP#: SessionManagementLayer send request: INVITE sip:openvoice@iptel.org #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org][sip:zlu@iptel.org] | |
| 2011-08-03 13:07:25.602 DEBUG [msctrl/2-t-7] #SIP#: The transaction was created: z9hG4bKs4zr30exj7y1 #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org][sip:zlu@iptel.org(192.168.0.196:5060)] | |
| 2011-08-03 13:07:25.602 DEBUG [msctrl/2-t-7] #SIP#: (o)[INVITE sip:openvoice@iptel.org SIP/2.0\r\nContent-Type: application/sdp\r\nTo: sip:openvoice@iptel.org\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bKs4zr30exj7y1\r\nCSeq: 1 INVITE\r\nContent-Length: 421\r\nCall-ID: 1p6brugj9c5yu\r\nMax-Forwards: 70\r\nFrom: <sip:zlu@iptel.org>;tag=a1nr9041p52\r\nContact: <sip:192.168.0.196:5060;transport=tcp>\r\n\r\nv=0\r\no=- 11 11 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20012 RTP/AVP 0 8 101 115 116 111 9 3 117 112 113\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r\na=rtpmap:115 SPEEX/8000\r\na=rtpmap:116 SPEEX/16000\r\na=rtpmap:111 G726-32/8000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:3 GSM/8000\r\na=rtpmap:117 SPEEX/32000\r\na=rtpmap:112 L16/8000\r\na=rtpmap:113 L16/16000\r\na=ptime:20\r\n] #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org][sip:zlu@iptel.org(192.168.0.196:5060)] | |
| 2011-08-03 13:07:25.633 DEBUG [msctrl/2-t-7] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org][sip:zlu@iptel.org(192.168.0.196:5060)] | |
| 2011-08-03 13:07:25.634 DEBUG [msctrl/2-t-7] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org(213.192.59.75:5060)][sip:zlu@iptel.org(192.168.0.196:5060)] | |
| 2011-08-03 13:07:25.860 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: (i)[SIP/2.0 407 Proxy Authentication Required\r\nTo: sip:openvoice@iptel.org;tag=ab7f724f44d6a86dac492bd71f480906-87fd\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bKs4zr30exj7y1;rport=55613;received=71.198.132.91\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nProxy-Authenticate: Digest realm="iptel.org", nonce="TjmqiU45qn9qAtA0OEVKIp0Dof0pHFvx"\r\nCall-ID: 1p6brugj9c5yu\r\nServer: ser (3.2.0-dev2 (i386/linux))\r\nFrom: <sip:zlu@iptel.org>;tag=a1nr9041p52\r\nWarning: 392 213.192.59.75:5060 "Noisy feedback tells: pid=14936 req_src_ip=71.198.132.91 req_src_port=55613 in_uri=sip:openvoice@iptel.org out_uri=sip:openvoice@iptel.org via_cnt==1"\r\n\r\n] #[N/A][N/A][1p6brugj9c5yu][N/A][sip:openvoice@iptel.org(213.192.59.75:5060)][sip:zlu@iptel.org(192.168.0.196:55613)] | |
| 2011-08-03 13:07:25.861 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: Receive 407/INVITE, branch=z9hG4bKs4zr30exj7y1 #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org(213.192.59.75:5060)][sip:zlu@iptel.org(192.168.0.196:5060)] | |
| 2011-08-03 13:07:25.863 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: (o)[ACK sip:openvoice@iptel.org SIP/2.0\r\nTo: <sip:openvoice@iptel.org>;tag=ab7f724f44d6a86dac492bd71f480906-87fd\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bKs4zr30exj7y1\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nCall-ID: 1p6brugj9c5yu\r\nMax-Forwards: 70\r\nFrom: <sip:zlu@iptel.org>;tag=a1nr9041p52\r\n\r\n] #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org][sip:zlu@iptel.org] | |
| 2011-08-03 13:07:25.895 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org][sip:zlu@iptel.org] | |
| 2011-08-03 13:07:25.896 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org(213.192.59.75:5060)][sip:zlu@iptel.org] | |
| 2011-08-03 13:07:25.896 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: InviteClientTransaction[_state=TERMINATED, _id=z9hG4bKs4zr30exj7y1] is released. #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org(213.192.59.75:5060)][sip:zlu@iptel.org(192.168.0.196:5060)] | |
| 2011-08-03 13:07:25.896 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-smp1j7yvbv11c0tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:25.897 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [ss_1k2rzt1grsoon], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org(213.192.59.75:5060)][sip:zlu@iptel.org(192.168.0.196:5060)] | |
| 2011-08-03 13:07:25.897 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: server will automatically invalidate sipsession [ss_1k2rzt1grsoon] #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org(213.192.59.75:5060)][sip:zlu@iptel.org(192.168.0.196:5060)] | |
| 2011-08-03 13:07:25.898 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: SipSessionImpl[_id=ss_1k2rzt1grsoon, _parentId=sas_2-14-smp1j7yvbv11c0tropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=1p6brugj9c5yu] is invalidating. (s) #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org(213.192.59.75:5060)][sip:zlu@iptel.org(192.168.0.196:5060)] | |
| 2011-08-03 13:07:25.898 DEBUG [tcp/0.0.0.0/5060-t-4] destroyNetworkConnection | |
| 2011-08-03 13:07:25.898 DEBUG [tcp/0.0.0.0/5060-t-4] #MSCTRL#: NC[ms2-7, nc1] moves state from [INITIALIZED] to [RELEASED] | |
| 2011-08-03 13:07:25.898 INFO [tcp/0.0.0.0/5060-t-4] #MSCTRL#: MS[ms2-7] removes a MediaObject[mscontrol://192.168.0.196:10074/ms2-7/nc1] | |
| 2011-08-03 13:07:25.899 DEBUG [tcp/0.0.0.0/5060-t-4] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 2\r\nSession: 2437020209-2b3f200-0ac46f50-00000007\r\n\r\n #[2437020209-2b3f200-0ac46f50-00000007][192.168.0.196:10074][192.168.0.196:55658] | |
| 2011-08-03 13:07:25.900 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2437020209-2b3f200-0ac46f50-00000007\r\nCseq: 2\r\n\r\n #[2437020209-2b3f200-0ac46f50-00000007][192.168.0.196:10074][192.168.0.196:55658] | |
| 2011-08-03 13:07:25.901 DEBUG [tcp/0.0.0.0/5060-t-4] #MSCTRL#: MS[ms2-7] moves state from [INITIALIZED] to [RELEASED] | |
| 2011-08-03 13:07:25.902 DEBUG [tcp/0.0.0.0/5060-t-4] terminating call. Notifying joinDelegate conditaion. callID:1p6brugj9c5yu | |
| 2011-08-03 13:07:25.902 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [sas_2-14-smp1j7yvbv11c0tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:25.902 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: SessionManagementLayer recv response: INVITE/407 #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org(213.192.59.75:5060)][sip:zlu@iptel.org(192.168.0.196:5060)] | |
| 2011-08-03 13:07:25.902 DEBUG [tcp/0.0.0.0/5060-t-4] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org(213.192.59.75:5060)][sip:zlu@iptel.org(192.168.0.196:55613)] | |
| 2011-08-03 13:07:25.905 INFO [pool-16-thread-9] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPOutgoingCall]] | |
| 2011-08-03 13:07:25.905 INFO [pool-16-thread-9] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPIncomingCall]] | |
| 2011-08-03 13:07:25.905 ERROR [tcp/0.0.0.0/5060-t-4] #SIP#: Servlet Error@T: java.lang.IllegalStateException: SipSessionImpl[_id=ss_1k2rzt1grsoon, _parentId=sas_2-14-smp1j7yvbv11c0tropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=false, _unavailable=false, _role=UAC, _method=INVITE, _callId=1p6brugj9c5yu] is already invalidated.\n at com.micromethod.sipmethod.server.sip.session.SipSessionImpl.checkState(SipSessionImpl.java:526)\n at com.micromethod.sipmethod.server.sip.session.SipSessionImpl.getAttribute(SipSessionImpl.java:872)\n at com.micromethod.sipmethod.server.sip.session.SipSessionAdaptor.getAttribute(SipSessionAdaptor.java:134)\n at com.voxeo.moho.util.SessionUtils.getEventSource(SessionUtils.java:62)\n at com.voxeo.moho.util.SessionUtils.getEventSource(SessionUtils.java:66)\n at com.voxeo.moho.sip.SIPDriverImpl.doResponse(SIPDriverImpl.java:341)\n at com.voxeo.moho.sip.SIPController.doResponse(SIPController.java:118)\n at javax.servlet.sip.SipServlet.service(SipServlet.java:39)\n at com.micromethod.sipmethod.server.container.impl.sip.SipServletWrapper.forward(SipServletWrapper.java:145)\n at com.micromethod.sipmethod.server.container.impl.ApplicationSupport.invokeSip(ApplicationSupport.java:360)\n at com.micromethod.sipmethod.server.container.impl.ApplicationImpl.handleSip(ApplicationImpl.java:569)\n at com.micromethod.sipmethod.server.sip.impl.ApplicationDispatchLayer.in(ApplicationDispatchLayer.java:108)\n at com.micromethod.sipmethod.server.sip.session.SessionManagementLayer._in(SessionManagementLayer.java:144)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorChainImpl.invokeNextPreApplication(SipInterceptorChainImpl.java:71)\n at com.micromethod.sipmethod.server.sip.interceptor.GenericAuthenticator.preApplication(GenericAuthenticator.java:112)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorChainImpl.invokeNextPreApplication(SipInterceptorChainImpl.java:61)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorPipelineImpl.preInvokeApplication(SipInterceptorPipelineImpl.java:28)\n at com.micromethod.sipmethod.server.sip.session.SessionManagementLayer.in(SessionManagementLayer.java:72)\n at com.micromethod.sipmethod.server.sip.session.ApplicationSelectionLayer.in(ApplicationSelectionLayer.java:234)\n at com.micromethod.sipmethod.server.sip.impl.ResolverLayer.in(ResolverLayer.java:44)\n at com.micromethod.sipmethod.server.sip.transaction.TransactionManagementLayer.in(TransactionManagementLayer.java:148)\n at com.micromethod.sipmethod.server.sip.impl.NetworkManagementLayer.in(NetworkManagementLayer.java:90)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl._handle(SIPServiceImpl.java:659)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorChainImpl.invokeNextPreService(SipInterceptorChainImpl.java:42)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorSupport.preService(SipInterceptorSupport.java:19)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorChainImpl.invokeNextPreService(SipInterceptorChainImpl.java:36)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorPipelineImpl.preInvokeService(SipInterceptorPipelineImpl.java:24)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:480)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.tcp.TcpServerConnection.handleMessage(TcpServerConnection.java:445)\n at com.micromethod.sipmethod.server.connector.message.impl.tcp.TcpServerConnection$InnerProcesser.run(TcpServerConnection.java:499)\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 | |
| 2011-08-03 13:07:25.907 ERROR [tcp/0.0.0.0/5060-t-4] #SIP#: The Servlet[Controller] response throws exception: @T: javax.servlet.ServletException: Servlet execution threw an exception.\n at com.micromethod.sipmethod.server.container.impl.sip.SipServletWrapper.forward(SipServletWrapper.java:165)\n at com.micromethod.sipmethod.server.container.impl.ApplicationSupport.invokeSip(ApplicationSupport.java:360)\n at com.micromethod.sipmethod.server.container.impl.ApplicationImpl.handleSip(ApplicationImpl.java:569)\n at com.micromethod.sipmethod.server.sip.impl.ApplicationDispatchLayer.in(ApplicationDispatchLayer.java:108)\n at com.micromethod.sipmethod.server.sip.session.SessionManagementLayer._in(SessionManagementLayer.java:144)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorChainImpl.invokeNextPreApplication(SipInterceptorChainImpl.java:71)\n at com.micromethod.sipmethod.server.sip.interceptor.GenericAuthenticator.preApplication(GenericAuthenticator.java:112)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorChainImpl.invokeNextPreApplication(SipInterceptorChainImpl.java:61)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorPipelineImpl.preInvokeApplication(SipInterceptorPipelineImpl.java:28)\n at com.micromethod.sipmethod.server.sip.session.SessionManagementLayer.in(SessionManagementLayer.java:72)\n at com.micromethod.sipmethod.server.sip.session.ApplicationSelectionLayer.in(ApplicationSelectionLayer.java:234)\n at com.micromethod.sipmethod.server.sip.impl.ResolverLayer.in(ResolverLayer.java:44)\n at com.micromethod.sipmethod.server.sip.transaction.TransactionManagementLayer.in(TransactionManagementLayer.java:148)\n at com.micromethod.sipmethod.server.sip.impl.NetworkManagementLayer.in(NetworkManagementLayer.java:90)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl._handle(SIPServiceImpl.java:659)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorChainImpl.invokeNextPreService(SipInterceptorChainImpl.java:42)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorSupport.preService(SipInterceptorSupport.java:19)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorChainImpl.invokeNextPreService(SipInterceptorChainImpl.java:36)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorPipelineImpl.preInvokeService(SipInterceptorPipelineImpl.java:24)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:480)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.tcp.TcpServerConnection.handleMessage(TcpServerConnection.java:445)\n at com.micromethod.sipmethod.server.connector.message.impl.tcp.TcpServerConnection$InnerProcesser.run(TcpServerConnection.java:499)\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 #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:openvoice@iptel.org(213.192.59.75:5060)][sip:zlu@iptel.org(192.168.0.196:5060)] | |
| 2011-08-03 13:07:25.908 INFO [pool-16-thread-9] Message [[Event class=com.voxeo.moho.event.MohoCallCompleteEvent sourceClass=SIPOutgoingCall]] | |
| 2011-08-03 13:07:25.909 INFO [pool-16-thread-9] Queued Event [EndEvent[callId=c4ccb713-9cb3-4e54-b0af-ad4f8509147c,reason=ERROR,errorText=<null>,headers=<null>]] | |
| 2011-08-03 13:07:25.909 INFO [pool-16-thread-9] Call cleanup [call=SIPCallImpl[SipSessionAdaptor[sessionid=ss_1k2rzt1grsoon, appSessionId=sas_2-14-smp1j7yvbv11c0tropo2],FAILED]] | |
| 2011-08-03 13:07:25.909 INFO [pool-16-thread-9] Event [EndEvent[callId=c4ccb713-9cb3-4e54-b0af-ad4f8509147c,reason=ERROR,errorText=<null>,headers=<null>]] | |
| 2011-08-03 13:07:25.910 DEBUG [pool-16-thread-9] #XMPP#: (o)<presence from="c4ccb713-9cb3-4e54-b0af-ad4f8509147c@127.0.0.1" to="usera@127.0.0.1/voxeo"><end xmlns="urn:xmpp:rayo:1"><error/></end></presence> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:25.910 DEBUG [pool-16-thread-9] #XMPP#: Send message to: 127.0.0.1:55650 by xmpp #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:25.913 DEBUG [SocketAcceptorIoProcessor-0.1] #CONNECTOR#: NIOTCPOutgoingConnection[/127.0.0.1:5222-->/127.0.0.1:55650] is closed. | |
| 2011-08-03 13:07:25.913 ERROR [SocketAcceptorIoProcessor-0.1] #CONNECTOR#: XMPPTcpConnector[/0.0.0.0] can not found ClientConnection: /127.0.0.1:55650 srcPort: 5222 | |
| 2011-08-03 13:07:25.913 DEBUG [SocketAcceptorIoProcessor-0.1] #CONNECTOR#: NIOTCPIncomingConnection[/127.0.0.1:55650-->/127.0.0.1:5222] is closed. | |
| 2011-08-03 13:07:25.914 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)</stream:stream> #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][N/A] | |
| 2011-08-03 13:07:25.915 DEBUG [XMPPService-t-40] #XMPP#: XMPPSessionImpl: _id=xmpps_2050wl4ymix4, _direction=RECEIVEStream, _sessionType=CLIENT, _remotJID=usera@127.0.0.1/voxeo, _state=TERMINATED, _remoteAddr=/127.0.0.1, _remotePort=55650, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo2-0, _state=STARTED] is invalidating. (s) #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][null] | |
| 2011-08-03 13:07:25.916 DEBUG [XMPPService-t-40] #XMPP#: Close underlizing connection for session:XMPPSessionImpl: _id=xmpps_2050wl4ymix4, _direction=RECEIVEStream, _sessionType=CLIENT, _remotJID=usera@127.0.0.1/voxeo, _state=TERMINATED, _remoteAddr=/127.0.0.1, _remotePort=55650, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo2-0, _state=STARTED] | |
| 2011-08-03 13:07:25.916 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo | |
| 2011-08-03 13:07:25.916 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_2050wl4ymix4][usera@127.0.0.1/voxeo, 127.0.0.1][127.0.0.1:55650][127.0.0.1:5222][xmpp][null] | |
| 2011-08-03 13:07:27.442 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[BYE sip:192.168.0.196:5060;transport=udp SIP/2.0\r\nTo: <sip:usera@127.0.0.1>;tag=jzv9jycn3ikx\r\nVia: SIP/2.0/UDP 192.168.0.196:57638;rport;branch=z9hG4bKPjtqo5Z2WonKiJ9v8W2OZ--Qtxfi1msEay\r\nCSeq: 9914 BYE\r\nContent-Length: 0\r\nCall-ID: pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0\r\nUser-Agent: Blink Lite 1.1.1 (MacOSX)\r\nFrom: "zhao lu" <sip:hzrtuisw@192.168.0.196>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\nMax-Forwards: 70\r\n\r\n] #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.445 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: The transaction was created: z9hG4bKPjtqo5Z2WonKiJ9v8W2OZ--Qtxfi1msEay #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.445 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Find Path[ id=pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0-aae42w5hPaSi52Li3Cx3ISYbjG5f69YM-jzv9jycn3ikx, path=ApplicationPath[_id=pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0-aae42w5hPaSi52Li3Cx3ISYbjG5f69YM-jzv9jycn3ikx, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_17xx8ycfew2y2, appSessionId=sas_2-15-sm1v8gyoyy16n50tropo2]]]]]] #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.445 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv request: BYE #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.451 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ApplicationDispatchLayer invoke application: Controller with BYE #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.451 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.451 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1v8gyoyy16n50tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:27.451 DEBUG [MOHO-31] destroyNetworkConnection | |
| 2011-08-03 13:07:27.453 DEBUG [MOHO-31] #MSCTRL#: NC[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] moves state from [INITIALIZED] to [RELEASED] | |
| 2011-08-03 13:07:27.454 INFO [MOHO-31] #MSCTRL#: MS[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] removes a MediaObject[mscontrol://192.168.0.196:10074/MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0/NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] | |
| 2011-08-03 13:07:27.454 DEBUG [MOHO-31] #MSCTRL#: MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] removes JoineeMrcpContext[mscontrol://192.168.0.196:10074/MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0/NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, 2437019367-2a44e00-0ac46f50-00000006, 2437019367-2a44e00-0ac46f50-00000006] #[2437019367-2a44e00-0ac46f50-00000006] | |
| 2011-08-03 13:07:27.454 DEBUG [MOHO-31] #MSCTRL#: MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] removed MrcpSpeakListener[Player[IDLE, MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]], ACTIVE] #[2437019367-2a44e00-0ac46f50-00000006] | |
| 2011-08-03 13:07:27.454 DEBUG [MOHO-31] #MSCTRL#: Remove MrcpSpeakListener[Player[IDLE, MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]], ACTIVE] #[2437019367-2a44e00-0ac46f50-00000006] | |
| 2011-08-03 13:07:27.454 DEBUG [MOHO-31] #MSCTRL#: MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] removes(NC[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, NC-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null]) | |
| 2011-08-03 13:07:27.455 DEBUG [MOHO-31] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/recognizer/ RTSP/1.0\r\nCseq: 4\r\nSession: 2437019367-2a44e00-0ac46f50-00000006\r\n\r\n #[2437019367-2a44e00-0ac46f50-00000006][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:27.452 INFO [pool-16-thread-9] Message [[Event class=com.voxeo.moho.sip.SIPHangupEventImpl sourceClass=SIPIncomingCall]] | |
| 2011-08-03 13:07:27.452 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_17xx8ycfew2y2], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.455 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1v8gyoyy16n50tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:27.457 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2437019367-2a44e00-0ac46f50-00000006\r\nCseq: 4\r\n\r\n #[2437019367-2a44e00-0ac46f50-00000006][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:27.458 DEBUG [MOHO-31] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/synthesizer/ RTSP/1.0\r\nCseq: 5\r\nSession: 2437019367-2a44e00-0ac46f50-00000006\r\n\r\n #[2437019367-2a44e00-0ac46f50-00000006][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:27.467 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2437019367-2a44e00-0ac46f50-00000006\r\nCseq: 5\r\n\r\n #[2437019367-2a44e00-0ac46f50-00000006][192.168.0.196:10074][192.168.0.196:55657] | |
| 2011-08-03 13:07:27.468 DEBUG [MOHO-31] #MSCTRL#: MS[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] moves state from [INITIALIZED] to [RELEASED] | |
| 2011-08-03 13:07:27.468 DEBUG [MOHO-31] #MSCTRL#: MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] moves state from [INITIALIZED] to [RELEASED] | |
| 2011-08-03 13:07:27.468 DEBUG [MOHO-31] #MSCTRL#: Stopping Player[IDLE, MG[MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0, MG-pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]], isStopAll:true | |
| 2011-08-03 13:07:27.469 DEBUG [MOHO-31] terminating call. Notifying this. callID:pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0 | |
| 2011-08-03 13:07:27.470 DEBUG [MOHO-31] #SIP#: SessionManagementLayer send response: BYE/200 #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.470 DEBUG [MOHO-31] #SIP#: (o)[SIP/2.0 200 OK\r\nTo: <sip:usera@127.0.0.1>;tag=jzv9jycn3ikx\r\nVia: SIP/2.0/UDP 192.168.0.196:57638;rport=57638;branch=z9hG4bKPjtqo5Z2WonKiJ9v8W2OZ--Qtxfi1msEay\r\nCSeq: 9914 BYE\r\nContent-Length: 0\r\nCall-ID: pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0\r\nFrom: "zhao lu" <sip:hzrtuisw@192.168.0.196>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\n\r\n] #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.471 DEBUG [MOHO-31] #SIP#: Send message to: /192.168.0.196:57638 by udp #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.471 DEBUG [MOHO-31] #SIP#: Connected to 192.168.0.196:57638/udp #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(192.168.0.196:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.471 DEBUG [MOHO-31] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1v8gyoyy16n50tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:27.471 DEBUG [MOHO-31] #SIP#: processInvalidationWhenReady [ss_17xx8ycfew2y2], current State = TERMINATED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.472 DEBUG [MOHO-31] #SIP#: server will automatically invalidate sipsession [ss_17xx8ycfew2y2] #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.474 DEBUG [MOHO-31] #SIP#: SipSessionImpl[_id=ss_17xx8ycfew2y2, _parentId=sas_2-15-sm1v8gyoyy16n50tropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=INVITE, _callId=pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0] is invalidating. (s) #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.476 DEBUG [MOHO-31] #SIP#: Remove Path[ id=pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0-aae42w5hPaSi52Li3Cx3ISYbjG5f69YM-jzv9jycn3ikx, session=SipSessionImpl[_id=ss_17xx8ycfew2y2, _parentId=sas_2-15-sm1v8gyoyy16n50tropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=true, _role=UAS, _method=INVITE, _callId=pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0]] #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:hzrtuisw@192.168.0.196(127.0.0.1:57638)][sip:usera@127.0.0.1(192.168.0.196:5060)] | |
| 2011-08-03 13:07:27.477 DEBUG [MOHO-31] #SIP#: processInvalidationWhenReady [sas_2-15-sm1v8gyoyy16n50tropo2], invalidateWhenReady: true | |
| 2011-08-03 13:07:27.477 DEBUG [MOHO-31] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-15-sm1v8gyoyy16n50tropo2] | |
| 2011-08-03 13:07:27.477 DEBUG [MOHO-31] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-15-sm1v8gyoyy16n50tropo2] is invalidating. (as) | |
| 2011-08-03 13:07:27.479 INFO [pool-16-thread-9] Message [[Event class=com.voxeo.moho.event.MohoCallCompleteEvent sourceClass=SIPIncomingCall]] | |
| 2011-08-03 13:07:27.480 INFO [pool-16-thread-9] Queued Event [EndEvent[callId=01eabcf8-a372-4572-9834-21beabc46f01,reason=HANGUP,errorText=<null>,headers=<null>]] | |
| 2011-08-03 13:07:27.481 INFO [pool-16-thread-9] Call cleanup [call=SIPCallImpl[SipSessionAdaptor[sessionid=ss_17xx8ycfew2y2, appSessionId=sas_2-15-sm1v8gyoyy16n50tropo2],DISCONNECTED]] | |
| 2011-08-03 13:07:27.481 INFO [pool-16-thread-9] Event [EndEvent[callId=01eabcf8-a372-4572-9834-21beabc46f01,reason=HANGUP,errorText=<null>,headers=<null>]] | |
| 2011-08-03 13:07:27.482 ERROR [pool-16-thread-9] Failed to dispatch event [jid=usera@127.0.0.1/voxeo, event=EndEvent[callId=01eabcf8-a372-4572-9834-21beabc46f01,reason=HANGUP,errorText=<null>,headers=<null>]] | |
| java.lang.IllegalStateException: XMPPSessionImpl: _id=xmpps_2050wl4ymix4, _direction=RECEIVEStream, _sessionType=CLIENT, _remotJID=usera@127.0.0.1/voxeo, _state=TERMINATED, _remoteAddr=/127.0.0.1, _remotePort=55650, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo2-0, _state=STARTED] is already invalidated. | |
| at com.micromethod.sipmethod.server.xmpp.session.XmppSessionImpl.checkState(XmppSessionImpl.java:495) | |
| at com.micromethod.sipmethod.server.xmpp.session.XmppSessionImpl.createStanzaRequest(XmppSessionImpl.java:508) | |
| at com.tropo.server.RayoServlet.sendToSession(RayoServlet.java:196) | |
| at com.tropo.server.RayoServlet.event(RayoServlet.java:165) | |
| at com.tropo.server.RayoServlet$1.handle(RayoServlet.java:99) | |
| at com.tropo.server.ReflectiveActor.flushEvents(ReflectiveActor.java:215) | |
| at com.tropo.server.ReflectiveActor.onMessage(ReflectiveActor.java:102) | |
| at org.jetlang.channels.ChannelSubscription$1.run(ChannelSubscription.java:31) | |
| at org.jetlang.core.BatchExecutorImpl.execute(BatchExecutorImpl.java:11) | |
| at org.jetlang.fibers.PoolFiber.flush(PoolFiber.java:63) | |
| at org.jetlang.fibers.PoolFiber.access$000(PoolFiber.java:19) | |
| at org.jetlang.fibers.PoolFiber$1.run(PoolFiber.java:36) | |
| at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) | |
| at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) | |
| at java.lang.Thread.run(Thread.java:680) |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment