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 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
| Use case: | |
| incoming offer to [email protected] (prism server) with tropo2 build 323. | |
| i issue two dials nested with join to [email protected] and [email protected] | |
| 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:[email protected] | |
| 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="[email protected]" to="[email protected]/voxeo"> | |
| <offer xmlns="urn:xmpp:rayo:1" to="sip:[email protected]" from="sip:[email protected]"> | |
| <header name="Max-Forwards" value="70"/> | |
| <header name="Content-Length" value="371"/> | |
| <header name="Contact" value="<sip:[email protected]:57638>"/> | |
| <header name="Supported" value="100rel"/> | |
| <header name="Allow" value="SUBSCRIBE"/> | |
| <header name="To" value="<sip:[email protected]>"/> | |
| <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:[email protected]>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM"/> | |
| </offer> | |
| </presence> | |
| D, [2011-08-03T13:07:24.615765 #31271] DEBUG -- : Handling event: #<Connfu::Event::Offer:0x00000100bcbde8 @presence_from="[email protected]", @presence_to="[email protected]/voxeo", @call_id="01eabcf8-a372-4572-9834-21beabc46f01", @from="\"zhao lu\" <sip:[email protected]>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM", @to={:address=>"sip:[email protected]", :scheme=>"sip", :username=>"usera", :host=>"127.0.0.1"}> | |
| D, [2011-08-03T13:07:24.632068 #31271] DEBUG -- : <iq type="set" to="[email protected]" id="blather0008" from="[email protected]/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="[email protected]" to="[email protected]/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="[email protected]" id="blather000a" from="[email protected]/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="[email protected]" to="[email protected]/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="[email protected]/92a715f6-ffa5-46fd-9ece-836a685b940b" to="[email protected]/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="[email protected]" id="blather000c" from="[email protected]/voxeo"> | |
| <dial xmlns="urn:xmpp:rayo:1" to="sip:[email protected]" from="sip:[email protected]"> | |
| <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="[email protected]" to="[email protected]/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="[email protected]" to="[email protected]/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="[email protected]" to="[email protected]/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][[email protected], 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][[email protected], 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][[email protected], 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][[email protected], 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][[email protected], 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][[email protected], 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][[email protected], 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][[email protected], 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="[email protected]"> | |
| <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 [email protected]/voxeo to session XMPPSessionImpl: _id=xmpps_2050wl4ymix4, _direction=RECEIVEStream, _sessionType=CLIENT, [email protected]/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][[email protected]/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="[email protected]"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>[email protected]/voxeo</jid></bind></iq> #[tropo2][null][xmpps_2050wl4ymix4][[email protected]/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][[email protected]/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 [[email protected]/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][[email protected]/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][[email protected]/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="[email protected]/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="[email protected]/voxeo"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> #[tropo2][null][xmpps_2050wl4ymix4][[email protected]/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][[email protected]/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][[email protected]/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][[email protected]/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="[email protected]/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="[email protected]/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][[email protected]/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][[email protected]/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][[email protected]/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][[email protected]/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:[email protected] SIP/2.0\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>\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:[email protected]>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\nMax-Forwards: 70\r\nContact: <sip:[email protected]: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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected]>\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:[email protected]>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\n\r\n] #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected], StateInfo=tropo2] #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected],to=sip:[email protected],headers={Max-Forwards=70, Content-Length=371, Contact=<sip:[email protected]:57638>, Supported=100rel, Allow=SUBSCRIBE, To=<sip:[email protected]>, 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:[email protected]>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM}]] | |
| 2011-08-03 13:07:24.602 INFO [pool-16-thread-8] Event [OfferEvent[from=sip:[email protected],to=sip:[email protected],headers={Max-Forwards=70, Content-Length=371, Contact=<sip:[email protected]:57638>, Supported=100rel, Allow=SUBSCRIBE, To=<sip:[email protected]>, 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:[email protected]>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM}]] | |
| 2011-08-03 13:07:24.603 DEBUG [pool-16-thread-8] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><offer xmlns="urn:xmpp:rayo:1" to="sip:[email protected]" from="sip:[email protected]"><header name="Max-Forwards" value="70"/><header name="Content-Length" value="371"/><header name="Contact" value="<sip:[email protected]:57638>"/><header name="Supported" value="100rel"/><header name="Allow" value="SUBSCRIBE"/><header name="To" value="<sip:[email protected]>"/><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:[email protected]>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM"/></offer></presence> #[tropo2][null][xmpps_2050wl4ymix4][[email protected]/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][[email protected]/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="[email protected]" id="blather0008" from="[email protected]/voxeo">\n <answer xmlns="urn:xmpp:rayo:1"/>\n</iq> #[tropo2][null][xmpps_2050wl4ymix4][[email protected]/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][[email protected]/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="[email protected]" id="blather0008" from="[email protected]/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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected]>;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:[email protected]>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\n\r\n] #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected]>;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:[email protected]>;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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected]>;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:[email protected]>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\nMax-Forwards: 70\r\n\r\n] #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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="[email protected]" to="[email protected]/voxeo"/> #[tropo2][null][xmpps_2050wl4ymix4][[email protected]/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][[email protected]/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="[email protected]" id="blather000a" from="[email protected]/voxeo">\n <say xmlns="urn:xmpp:tropo:say:1">transferring</say>\n</iq> #[tropo2][null][xmpps_2050wl4ymix4][[email protected]/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][[email protected]/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="[email protected]" id="blather000a" from="[email protected]/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="[email protected]" to="[email protected]/voxeo"><ref xmlns="urn:xmpp:rayo:1" id="92a715f6-ffa5-46fd-9ece-836a685b940b"/></iq> #[tropo2][null][xmpps_2050wl4ymix4][[email protected]/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][[email protected]/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="[email protected]/92a715f6-ffa5-46fd-9ece-836a685b940b" to="[email protected]/voxeo"><complete xmlns="urn:xmpp:rayo:ext:1"><success xmlns="urn:xmpp:tropo:say:complete:1"/></complete></presence> #[tropo2][null][xmpps_2050wl4ymix4][[email protected]/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][[email protected]/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="[email protected]" id="blather000c" from="[email protected]/voxeo">\n <dial xmlns="urn:xmpp:rayo:1" to="sip:[email protected]" from="sip:[email protected]">\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][[email protected]/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][[email protected]/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="[email protected]" id="blather000c" from="[email protected]/voxeo"> | |
| <dial xmlns="urn:xmpp:rayo:1" to="sip:[email protected]" from="sip:[email protected]"> | |
| <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:[email protected],to=sip:[email protected],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="[email protected]" to="[email protected]/voxeo"><ref xmlns="urn:xmpp:rayo:1" id="c4ccb713-9cb3-4e54-b0af-ad4f8509147c"/></iq> #[tropo2][null][xmpps_2050wl4ymix4][[email protected]/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][[email protected]/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:[email protected]][sip:[email protected]] | |
| 2011-08-03 13:07:25.513 DEBUG [msctrl/2-t-7] #SIP#: SetRoutingDirective: NEW #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:[email protected]][sip:[email protected]] | |
| 2011-08-03 13:07:25.514 DEBUG [msctrl/2-t-7] #SIP#: SessionManagementLayer send request: INVITE sip:[email protected] #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:[email protected]][sip:[email protected]] | |
| 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:[email protected]][sip:[email protected](192.168.0.196:5060)] | |
| 2011-08-03 13:07:25.602 DEBUG [msctrl/2-t-7] #SIP#: (o)[INVITE sip:[email protected] SIP/2.0\r\nContent-Type: application/sdp\r\nTo: sip:[email protected]\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:[email protected]>;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:[email protected]][sip:[email protected](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:[email protected]][sip:[email protected](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:[email protected](213.192.59.75:5060)][sip:[email protected](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:[email protected];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:[email protected]>;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:[email protected] out_uri=sip:[email protected] via_cnt==1"\r\n\r\n] #[N/A][N/A][1p6brugj9c5yu][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](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:[email protected](213.192.59.75:5060)][sip:[email protected](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:[email protected] SIP/2.0\r\nTo: <sip:[email protected]>;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:[email protected]>;tag=a1nr9041p52\r\n\r\n] #[tropo2][sas_2-14-smp1j7yvbv11c0tropo2][1p6brugj9c5yu][ss_1k2rzt1grsoon][sip:[email protected]][sip:[email protected]] | |
| 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:[email protected]][sip:[email protected]] | |
| 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:[email protected](213.192.59.75:5060)][sip:[email protected]] | |
| 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:[email protected](213.192.59.75:5060)][sip:[email protected](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:[email protected](213.192.59.75:5060)][sip:[email protected](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:[email protected](213.192.59.75:5060)][sip:[email protected](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:[email protected](213.192.59.75:5060)][sip:[email protected](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:[email protected](213.192.59.75:5060)][sip:[email protected](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:[email protected](213.192.59.75:5060)][sip:[email protected](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:[email protected](213.192.59.75:5060)][sip:[email protected](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="[email protected]" to="[email protected]/voxeo"><end xmlns="urn:xmpp:rayo:1"><error/></end></presence> #[tropo2][null][xmpps_2050wl4ymix4][[email protected]/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][[email protected]/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][[email protected]/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, [email protected]/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][[email protected]/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, [email protected]/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][[email protected]/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:[email protected]>;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:[email protected]>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\nMax-Forwards: 70\r\n\r\n] #[N/A][N/A][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][N/A][sip:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected]>;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:[email protected]>;tag=aae42w5hPaSi52Li3Cx3ISYbjG5f69YM\r\n\r\n] #[tropo2][sas_2-15-sm1v8gyoyy16n50tropo2][pGJTRMOGKArRQ9QhxAYfOgg47AdQuhF0][ss_17xx8ycfew2y2][sip:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](192.168.0.196:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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:[email protected](127.0.0.1:57638)][sip:[email protected](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 [[email protected]/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, [email protected]/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