Skip to content

Instantly share code, notes, and snippets.

@zlu

zlu/sipmethod.log

Created June 16, 2011 10:00
Show Gist options
  • Save zlu/1028977 to your computer and use it in GitHub Desktop.
Save zlu/1028977 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
sipmethod.log
2011-06-16 10:53:53.208 DEBUG [SocketAcceptorIoProcessor-0.0] #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"> #[tropo][null][xmpps_v48rdx56b1cp][[email protected], 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.210 DEBUG [XMPPService-t-3] #XMPP#: Invoke application:tropo ozone
2011-06-16 10:53:53.211 DEBUG [XMPPService-t-3] #XMPP#: Forwarding Request #[tropo][null][xmpps_v48rdx56b1cp][[email protected], 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][null]
2011-06-16 10:53:53.213 DEBUG [XMPPService-t-3] #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_v48rdx56b1cp" xml:lang="en"> #[tropo][null][xmpps_v48rdx56b1cp][[email protected], 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.213 DEBUG [XMPPService-t-3] #XMPP#: Send message to: 127.0.0.1:49420 by xmpp #[tropo][null][xmpps_v48rdx56b1cp][[email protected], 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.214 DEBUG [XMPPService-t-3] #XMPP#: (o)<stream:features><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></stream:features> #[tropo][null][xmpps_v48rdx56b1cp][[email protected], 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.214 DEBUG [XMPPService-t-3] #XMPP#: Send message to: 127.0.0.1:49420 by xmpp #[tropo][null][xmpps_v48rdx56b1cp][[email protected], 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.231 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)<iq type="set" id="blather0002"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/></iq> #[tropo][null][xmpps_v48rdx56b1cp][[email protected], 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.244 DEBUG [XMPPService-t-4] #XMPP#: Invoke application:tropo ozone
2011-06-16 10:53:53.248 DEBUG [XMPPService-t-4] #XMPP#: Forwarding Request #[tropo][null][xmpps_v48rdx56b1cp][[email protected], 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][null]
2011-06-16 10:53:53.249 DEBUG [XMPPService-t-4] <iq type="set" id="blather0002" to="127.0.0.1" from="[email protected]"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/></iq> :: xmpps_v48rdx56b1cp
2011-06-16 10:53:53.260 DEBUG [XMPPService-t-4] #XMPP#: Intercept iq bind result, set full jid [email protected]/voxeo to session XMPPSessionImpl: _id=xmpps_v48rdx56b1cp, _direction=RECEIVEStream, _sessionType=CLIENT, [email protected]/voxeo, _state=CONFIRMED, _remoteAddr=/127.0.0.1, _remotePort=49420, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo-0, _state=STARTED] #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.260 DEBUG [XMPPService-t-4] #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> #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.260 DEBUG [XMPPService-t-4] #XMPP#: Send message to: 127.0.0.1:49420 by xmpp #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.261 INFO [XMPPService-t-4] Bound client resource [[email protected]/voxeo]
2011-06-16 10:53:53.271 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)<iq type="set" id="blather0004" to="127.0.0.1"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.272 DEBUG [XMPPService-t-5] #XMPP#: Invoke application:tropo ozone
2011-06-16 10:53:53.272 DEBUG [XMPPService-t-5] #XMPP#: Forwarding Request #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][null]
2011-06-16 10:53:53.273 DEBUG [XMPPService-t-5] <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_v48rdx56b1cp
2011-06-16 10:53:53.273 DEBUG [XMPPService-t-5] #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> #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.273 DEBUG [XMPPService-t-5] #XMPP#: Send message to: 127.0.0.1:49420 by xmpp #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.280 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)<iq type="get" id="blather0006"><query xmlns="jabber:iq:roster"/></iq> #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.281 DEBUG [XMPPService-t-6] #XMPP#: Invoke application:tropo ozone
2011-06-16 10:53:53.281 DEBUG [XMPPService-t-6] #XMPP#: Forwarding Request #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][null]
2011-06-16 10:53:53.282 DEBUG [XMPPService-t-6] <iq type="get" id="blather0006" to="127.0.0.1" from="[email protected]/voxeo"><query xmlns="jabber:iq:roster"/></iq> :: xmpps_v48rdx56b1cp
2011-06-16 10:53:53.282 DEBUG [XMPPService-t-6] #XMPP#: (o)<iq type="error" id="blather0006" to="[email protected]/voxeo" from="127.0.0.1"><query xmlns="jabber:iq:roster"/><error type="cancel"><feature-not-implemented xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq> #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.282 DEBUG [XMPPService-t-6] #XMPP#: Send message to: 127.0.0.1:49420 by xmpp #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.292 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)<presence/> #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:53:53.293 DEBUG [XMPPService-t-7] #XMPP#: Invoke application:tropo ozone
2011-06-16 10:53:53.293 DEBUG [XMPPService-t-7] #XMPP#: Forwarding Request #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][null]
2011-06-16 10:54:04.320 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: (i)[INVITE sip:[email protected]:5060 SIP/2.0\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]:5060>\r\nVia: SIP/2.0/UDP 127.0.0.1:21702;branch=z9hG4bK-d8754z-4342715b7820e428-1---d8754z-;rport\r\nAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO\r\nCSeq: 1 INVITE\r\nContent-Length: 422\r\nSupported: replaces\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nUser-Agent: Bria 3 release 3.2 stamp 61503\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nMax-Forwards: 70\r\nContact: <sip:[email protected]:21702>\r\n\r\nv=0\r\no=- 1308218044261196 1 IN IP4 192.168.0.44\r\ns=CounterPath Bria 3.2\r\nc=IN IP4 192.168.0.44\r\nt=0 0\r\na=ice-ufrag:e8a505\r\na=ice-pwd:435c0c173ab49f92708e39079d818711\r\nm=audio 49862 RTP/AVP 0 8 18 101\r\na=rtpmap:18 G729/8000\r\na=fmtp:18 annexb=yes\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\na=candidate:1 1 UDP 659136 192.168.0.44 49862 typ host\r\na=candidate:1 2 UDP 659134 192.168.0.44 49863 typ host\r\n] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.331 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: The transaction was created: z9hG4bK-d8754z-4342715b7820e428-1---d8754z- #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.339 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: (o)[SIP/2.0 100 Trying\r\nTo: <sip:[email protected]:5060>\r\nVia: SIP/2.0/UDP 127.0.0.1:21702;branch=z9hG4bK-d8754z-4342715b7820e428-1---d8754z-;rport=21702\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\n\r\n] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected]:5060(127.0.0.1:21702)][sip:[email protected](192.168.0.44:5060)]
2011-06-16 10:54:04.341 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Send message to: /127.0.0.1:21702 by udp #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected]:5060(127.0.0.1:21702)][sip:[email protected](192.168.0.44:5060)]
2011-06-16 10:54:04.341 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Connected to 127.0.0.1:21702/udp #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected]:5060(127.0.0.1:21702)][sip:[email protected](192.168.0.44:5060)]
2011-06-16 10:54:04.342 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: There is no appropriate application to handle the request, request will be processed by PrismDemoApp
2011-06-16 10:54:04.344 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SipApplicationInfo: SipApplicationRouterInfo[ApplicationName=PrismDemoApp, RouteModifier=NO_ROUTE, RouteRegion=null, SubscriberURI=sip:[email protected]:5060, StateInfo=PrismDemoApp] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.345 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-15-sm1bkkd6xcyonrgPrismDemoApp] will expired after 300000
2011-06-16 10:54:04.355 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Session creating: ss_qltdj9ypjpso #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.357 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Session created:SipSessionImpl[_id=ss_qltdj9ypjpso, _parentId=sas_2-15-sm1bkkd6xcyonrgPrismDemoApp, _handler=PrismSample, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UNKNOW, _method=INVITE, _callId=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.] #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.358 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SessionManagementLayer recv request: INVITE #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.358 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: ApplicationDispatchLayer invoke application: PrismSample with INVITE #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.359 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SipServletWrapper[PrismSample, com.voxeo.prism.sample.PrismServlet] is forwarding. #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.360 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SessionManagementLayer send response: INVITE/180 #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.362 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Add Path[ id=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.-2d6c7340-2yq63kdg5mrb, session=SipSessionImpl[_id=ss_qltdj9ypjpso, _parentId=sas_2-15-sm1bkkd6xcyonrgPrismDemoApp, _handler=PrismSample, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=INVITE, _callId=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.], party= CALLER] #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.365 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: (o)[SIP/2.0 180 Ringing\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 127.0.0.1:21702;branch=z9hG4bK-d8754z-4342715b7820e428-1---d8754z-;rport=21702\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\n\r\n] #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.366 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Send message to: /127.0.0.1:21702 by udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.366 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Connected to 127.0.0.1:21702/udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.367 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:04.367 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = EARLY, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: true, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.367 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:04.445 INFO [udp/0.0.0.0/5060-t-4] #MSCTRL#: MS[ms1-1] creates a MediaObject[BASIC, nc1, null]
2011-06-16 10:54:04.447 INFO [udp/0.0.0.0/5060-t-4] #MSCTRL#: SdpPort[IDLE, NC[ms1-1, nc1]] processes a SDP offer \nv=0\r\no=- 1308218044261196 1 IN IP4 192.168.0.44\r\ns=CounterPath Bria 3.2\r\nc=IN IP4 192.168.0.44\r\nt=0 0\r\na=ice-ufrag:e8a505\r\na=ice-pwd:435c0c173ab49f92708e39079d818711\r\nm=audio 49862 RTP/AVP 0 8 18 101\r\na=rtpmap:18 G729/8000\r\na=fmtp:18 annexb=yes\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\na=candidate:1 1 UDP 659136 192.168.0.44 49862 typ host\r\na=candidate:1 2 UDP 659134 192.168.0.44 49863 typ host\r\n
2011-06-16 10:54:04.509 DEBUG [udp/0.0.0.0/5060-t-4] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms1-1, nc1]] moves state from [IDLE] to [UNDER_PROCESSING]
2011-06-16 10:54:04.509 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:04.509 INFO [msctrl/1-t-1] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-06-16 10:54:04.510 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = EARLY, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.510 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:04.527 DEBUG [msctrl/1-t-1] #MRCP#: load configuration from {MEDIAOBJECT_ID=nc1}
2011-06-16 10:54:04.661 DEBUG [msctrl/1-t-1] #MRCP#: (o)SETUP rtsp://192.168.0.44:10074/recognizer/ RTSP/1.0\r\nCseq: 1\r\nTransport: RTP/AVP;unicast;\r\nContent-Type: application/sdp\r\nContent-Length: 422\r\n\r\nv=0\r\no=- 1308218044261196 1 IN IP4 192.168.0.44\r\ns=CounterPath Bria 3.2\r\nc=IN IP4 192.168.0.44\r\nt=0 0\r\na=ice-ufrag:e8a505\r\na=ice-pwd:435c0c173ab49f92708e39079d818711\r\nm=audio 49862 RTP/AVP 0 8 18 101\r\na=rtpmap:18 G729/8000\r\na=fmtp:18 annexb=yes\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\na=candidate:1 1 UDP 659136 192.168.0.44 49862 typ host\r\na=candidate:1 2 UDP 659134 192.168.0.44 49863 typ host\r\n #[N/A][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:04.679 DEBUG [mrcp/1-t-1] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nTransport: RTP/AVP;unicast;client_port=49862-49863;server_port=20000-20001\r\nCseq: 1\r\nContent-Type: application/sdp\r\nContent-Length: 173\r\n\r\nv=0\r\no=- 47 47 IN IP4 192.168.0.44\r\ns=voxeo\r\nc=IN IP4 192.168.0.44\r\nt=0 0\r\nm=audio 20000 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.44:10074][192.168.0.44:49423]
2011-06-16 10:54:04.689 DEBUG [msctrl/1-t-1] #MSCTRL#: NC[ms1-1, nc1] initializes the ASR session. #[2547986646-2001e00-0b06d070-00000001]
2011-06-16 10:54:04.696 DEBUG [msctrl/1-t-1] #MRCP#: (o)SETUP rtsp://192.168.0.44:10074/synthesizer/ RTSP/1.0\r\nCseq: 2\r\nTransport: RTP/AVP;unicast;\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:04.699 DEBUG [mrcp/1-t-2] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nTransport: RTP/AVP;unicast;client_port=49862-49863;server_port=20000-20001\r\nCseq: 2\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:04.704 DEBUG [msctrl/1-t-1] #MSCTRL#: NC[ms1-1, nc1] initializes the TTS session. #[2547986646-2001e00-0b06d070-00000001]
2011-06-16 10:54:04.705 DEBUG [msctrl/1-t-1] #MSCTRL#: SdpPort[SDP_NEGOTIATED, NC[ms1-1, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATED]
2011-06-16 10:54:04.709 DEBUG [msctrl/1-t-1] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATED, NC[ms1-1, nc1]], ANSWER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 47 47 IN IP4 192.168.0.44\r\ns=voxeo\r\nc=IN IP4 192.168.0.44\r\nt=0 0\r\nm=audio 20000 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-06-16 10:54:04.711 DEBUG [msctrl/1-t-1] #SIP#: SessionManagementLayer send response: INVITE/200 #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.714 DEBUG [msctrl/1-t-1] #SIP#: (o)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 127.0.0.1:21702;branch=z9hG4bK-d8754z-4342715b7820e428-1---d8754z-;rport=21702\r\nCSeq: 1 INVITE\r\nContent-Length: 173\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nContact: <sip:192.168.0.44:5060;transport=udp>\r\n\r\nv=0\r\no=- 47 47 IN IP4 192.168.0.44\r\ns=voxeo\r\nc=IN IP4 192.168.0.44\r\nt=0 0\r\nm=audio 20000 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n] #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.715 DEBUG [msctrl/1-t-1] #SIP#: Send message to: /127.0.0.1:21702 by udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.715 DEBUG [msctrl/1-t-1] #SIP#: Connected to 127.0.0.1:21702/udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.715 DEBUG [msctrl/1-t-1] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:04.716 DEBUG [msctrl/1-t-1] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:04.716 DEBUG [msctrl/1-t-1] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:05.217 DEBUG [Timer-13] #SIP#: (o)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 127.0.0.1:21702;branch=z9hG4bK-d8754z-4342715b7820e428-1---d8754z-;rport=21702\r\nCSeq: 1 INVITE\r\nContent-Length: 173\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nContact: <sip:192.168.0.44:5060;transport=udp>\r\n\r\nv=0\r\no=- 47 47 IN IP4 192.168.0.44\r\ns=voxeo\r\nc=IN IP4 192.168.0.44\r\nt=0 0\r\nm=audio 20000 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n] #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:05.219 DEBUG [Timer-13] #SIP#: Send message to: /127.0.0.1:21702 by udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:05.220 DEBUG [Timer-13] #SIP#: Connected to 127.0.0.1:21702/udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:05.220 DEBUG [Timer-13] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:05.220 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:05.221 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:05.722 DEBUG [Timer-13] #SIP#: (o)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 127.0.0.1:21702;branch=z9hG4bK-d8754z-4342715b7820e428-1---d8754z-;rport=21702\r\nCSeq: 1 INVITE\r\nContent-Length: 173\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nContact: <sip:192.168.0.44:5060;transport=udp>\r\n\r\nv=0\r\no=- 47 47 IN IP4 192.168.0.44\r\ns=voxeo\r\nc=IN IP4 192.168.0.44\r\nt=0 0\r\nm=audio 20000 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n] #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:05.723 DEBUG [Timer-13] #SIP#: Send message to: /127.0.0.1:21702 by udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:05.723 DEBUG [Timer-13] #SIP#: Connected to 127.0.0.1:21702/udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:05.723 DEBUG [Timer-13] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:05.723 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:05.724 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:06.725 DEBUG [Timer-13] #SIP#: (o)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 127.0.0.1:21702;branch=z9hG4bK-d8754z-4342715b7820e428-1---d8754z-;rport=21702\r\nCSeq: 1 INVITE\r\nContent-Length: 173\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nContact: <sip:192.168.0.44:5060;transport=udp>\r\n\r\nv=0\r\no=- 47 47 IN IP4 192.168.0.44\r\ns=voxeo\r\nc=IN IP4 192.168.0.44\r\nt=0 0\r\nm=audio 20000 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n] #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:06.726 DEBUG [Timer-13] #SIP#: Send message to: /127.0.0.1:21702 by udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:06.726 DEBUG [Timer-13] #SIP#: Connected to 127.0.0.1:21702/udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:06.726 DEBUG [Timer-13] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:06.726 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:06.727 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:08.729 DEBUG [Timer-13] #SIP#: (o)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 127.0.0.1:21702;branch=z9hG4bK-d8754z-4342715b7820e428-1---d8754z-;rport=21702\r\nCSeq: 1 INVITE\r\nContent-Length: 173\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nContact: <sip:192.168.0.44:5060;transport=udp>\r\n\r\nv=0\r\no=- 47 47 IN IP4 192.168.0.44\r\ns=voxeo\r\nc=IN IP4 192.168.0.44\r\nt=0 0\r\nm=audio 20000 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n] #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:08.730 DEBUG [Timer-13] #SIP#: Send message to: /127.0.0.1:21702 by udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:08.730 DEBUG [Timer-13] #SIP#: Connected to 127.0.0.1:21702/udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:08.731 DEBUG [Timer-13] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:08.731 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:08.731 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:12.732 DEBUG [Timer-13] #SIP#: (o)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 127.0.0.1:21702;branch=z9hG4bK-d8754z-4342715b7820e428-1---d8754z-;rport=21702\r\nCSeq: 1 INVITE\r\nContent-Length: 173\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nContact: <sip:192.168.0.44:5060;transport=udp>\r\n\r\nv=0\r\no=- 47 47 IN IP4 192.168.0.44\r\ns=voxeo\r\nc=IN IP4 192.168.0.44\r\nt=0 0\r\nm=audio 20000 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n] #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:12.733 DEBUG [Timer-13] #SIP#: Send message to: /127.0.0.1:21702 by udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:12.733 DEBUG [Timer-13] #SIP#: Connected to 127.0.0.1:21702/udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:12.734 DEBUG [Timer-13] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:12.734 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:12.734 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:16.735 DEBUG [Timer-13] #SIP#: (o)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 127.0.0.1:21702;branch=z9hG4bK-d8754z-4342715b7820e428-1---d8754z-;rport=21702\r\nCSeq: 1 INVITE\r\nContent-Length: 173\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nContact: <sip:192.168.0.44:5060;transport=udp>\r\n\r\nv=0\r\no=- 47 47 IN IP4 192.168.0.44\r\ns=voxeo\r\nc=IN IP4 192.168.0.44\r\nt=0 0\r\nm=audio 20000 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n] #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:16.736 DEBUG [Timer-13] #SIP#: Send message to: /127.0.0.1:21702 by udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:16.736 DEBUG [Timer-13] #SIP#: Connected to 127.0.0.1:21702/udp #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:16.736 DEBUG [Timer-13] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:16.737 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:16.737 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:19.482 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: (i)[ACK sip:192.168.0.44:5060;transport=udp SIP/2.0\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 192.168.0.44:21702;branch=z9hG4bK-d8754z-71a56e4bdb62bf47-1---d8754z-;rport\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nUser-Agent: Bria 3 release 3.2 stamp 61503\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nMax-Forwards: 70\r\nContact: <sip:[email protected]:21702>\r\n\r\n] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.485 DEBUG [udp/0.0.0.0/5060-t-5] #SIP#: (i)[ACK sip:192.168.0.44:5060;transport=udp SIP/2.0\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 192.168.0.44:21702;branch=z9hG4bK-d8754z-71a56e4bdb62bf47-1---d8754z-;rport\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nUser-Agent: Bria 3 release 3.2 stamp 61503\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nMax-Forwards: 70\r\nContact: <sip:[email protected]:21702>\r\n\r\n] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.484 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[ACK sip:192.168.0.44:5060;transport=udp SIP/2.0\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 192.168.0.44:21702;branch=z9hG4bK-d8754z-71a56e4bdb62bf47-1---d8754z-;rport\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nUser-Agent: Bria 3 release 3.2 stamp 61503\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nMax-Forwards: 70\r\nContact: <sip:[email protected]:21702>\r\n\r\n] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.490 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Find Path[ id=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.-2d6c7340-2yq63kdg5mrb, path=ApplicationPath[_id=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.-2d6c7340-2yq63kdg5mrb, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_qltdj9ypjpso, appSessionId=sas_2-15-sm1bkkd6xcyonrgPrismDemoApp]]]]]] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.491 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv request: ACK #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.491 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ApplicationDispatchLayer invoke application: PrismSample with ACK #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.492 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[PrismSample, com.voxeo.prism.sample.PrismServlet] is forwarding. #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.488 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Find Path[ id=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.-2d6c7340-2yq63kdg5mrb, path=ApplicationPath[_id=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.-2d6c7340-2yq63kdg5mrb, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_qltdj9ypjpso, appSessionId=sas_2-15-sm1bkkd6xcyonrgPrismDemoApp]]]]]] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.494 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SessionManagementLayer recv request: ACK #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.495 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:19.495 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: true, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.495 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:19.491 DEBUG [udp/0.0.0.0/5060-t-5] #SIP#: Find Path[ id=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.-2d6c7340-2yq63kdg5mrb, path=ApplicationPath[_id=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.-2d6c7340-2yq63kdg5mrb, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_qltdj9ypjpso, appSessionId=sas_2-15-sm1bkkd6xcyonrgPrismDemoApp]]]]]] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.498 DEBUG [udp/0.0.0.0/5060-t-5] #SIP#: SessionManagementLayer recv request: ACK #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.498 DEBUG [udp/0.0.0.0/5060-t-5] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:19.498 DEBUG [udp/0.0.0.0/5060-t-5] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: true, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.499 DEBUG [udp/0.0.0.0/5060-t-5] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:19.566 INFO [udp/0.0.0.0/5060-t-3] #MSCTRL#: MS[ms1-1] creates a MediaObject[PLAYER_RECORDER_SIGNALDETECTOR, mg2, null]
2011-06-16 10:54:19.571 INFO [udp/0.0.0.0/5060-t-3] #MSCTRL#: MG[ms1-1, mg2] joins to NC[ms1-1, nc1] in DUPLEX
2011-06-16 10:54:19.580 DEBUG [udp/0.0.0.0/5060-t-3] #MSCTRL#: MG[ms1-1, mg2] adds JoineeMrcpContext[mscontrol://192.168.0.44:10074/ms1-1/nc1, 2547986646-2001e00-0b06d070-00000001, 2547986646-2001e00-0b06d070-00000001] #[2547986646-2001e00-0b06d070-00000001]
2011-06-16 10:54:19.581 DEBUG [udp/0.0.0.0/5060-t-3] #MSCTRL#: NC[ms1-1, nc1] adds(MG[ms1-1, mg2], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-06-16 10:54:19.582 DEBUG [udp/0.0.0.0/5060-t-3] #MSCTRL#: MG[ms1-1, mg2] adds(NC[ms1-1, nc1], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-06-16 10:54:19.589 DEBUG [udp/0.0.0.0/5060-t-3] #MSCTRL#: Add PlayListItem[0, 0, false, rtcs=null, optargs=null,"<?xml version="1.0"?><speak><voice>Welcome to Voxeo Prism Test Application</voice></speak>"]
2011-06-16 10:54:19.589 DEBUG [udp/0.0.0.0/5060-t-3] #MSCTRL#: Find PlayListItem[IDLE, 0, 0, false]
2011-06-16 10:54:19.590 DEBUG [udp/0.0.0.0/5060-t-3] #MSCTRL#: Player[IDLE, MG[ms1-1, mg2]] starts playing PlayListItem[IDLE, 0, 0, false]
2011-06-16 10:54:19.590 DEBUG [udp/0.0.0.0/5060-t-3] #MSCTRL#: Player[ACTIVE, MG[ms1-1, mg2]] moves state from [IDLE] to [ACTIVE]
2011-06-16 10:54:19.590 DEBUG [udp/0.0.0.0/5060-t-3] #MSCTRL#: PlayListItem[0, 0] moves state from [IDLE] to [PLAYING]
2011-06-16 10:54:19.594 DEBUG [udp/0.0.0.0/5060-t-3] #MSCTRL#: MG[ms1-1, mg2] added MrcpSpeakListener[Player[ACTIVE, MG[ms1-1, mg2]], ACTIVE] #[2547986646-2001e00-0b06d070-00000001]
2011-06-16 10:54:19.662 DEBUG [udp/0.0.0.0/5060-t-3] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.44:10074/synthesizer/ RTSP/1.0\r\nCseq: 3\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 281\r\n\r\nSPEAK 54000 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: 90\r\n\r\n<?xml version="1.0"?><speak><voice>Welcome to Voxeo Prism Test Application</voice></speak> #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:19.674 DEBUG [mrcp/1-t-3] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nCseq: 3\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 54000 200 IN-PROGRESS\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:19.679 DEBUG [udp/0.0.0.0/5060-t-3] #MSCTRL#: PlayListItem[0, 0] added (54000, 2547986646-2001e00-0b06d070-00000001)
2011-06-16 10:54:19.679 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:19.680 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:19.680 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:22.601 DEBUG [mrcp/1-t-4] #MRCP#: (i)ANNOUNCE rtsp://192.168.0.44:10074/synthesizer/ RTSP/1.0\r\nCseq: 1\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 72\r\n\r\nSPEAK-COMPLETE 54000 COMPLETE MRCP/1.0\r\ncompletion-cause: 000 normal\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:22.603 DEBUG [mrcp/1-t-4] #MRCP#: (o)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nCseq: 1\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:22.608 DEBUG [mrcp/1-t-5] #MRCP#: Handling SPEAK-COMPLETE[54000] #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:22.611 DEBUG [mrcp/1-t-5] #MSCTRL#: Find PlayListItem[PLAYING, 0, 0, false, speakIds=[54000]]
2011-06-16 10:54:22.613 DEBUG [mrcp/1-t-5] #MSCTRL#: MrcpSpeakListener[Player[ACTIVE, MG[ms1-1, mg2]], ACTIVE] handling with MrcpSpeakCompleteEvent[originalId:54000, requestId:54000, rc:0, duration:3019] #[2547986646-2001e00-0b06d070-00000001]
2011-06-16 10:54:22.614 DEBUG [mrcp/1-t-5] #MSCTRL#: PlayListItem[0, 0] removed (54000, 2547986646-2001e00-0b06d070-00000001)
2011-06-16 10:54:22.614 DEBUG [mrcp/1-t-5] #MSCTRL#: PlayListItem[0, 0] moves state from [PLAYING] to [IDLE]
2011-06-16 10:54:22.616 DEBUG [mrcp/1-t-5] #MSCTRL#: Player[IDLE, MG[ms1-1, mg2]] moves state from [ACTIVE] to [IDLE]
2011-06-16 10:54:22.616 DEBUG [mrcp/1-t-5] #MSCTRL#: clear up playList=[PlayListItem[IDLE, 0, 0, false]]
2011-06-16 10:54:22.616 DEBUG [mrcp/1-t-5] #MSCTRL#: Return PlayerEvent[Player[IDLE, MG[ms1-1, mg2]], PLAY_COMPLETED, NO_ERROR, null, END_OF_PLAY_LIST, null, null, 0, 3019] to the application
2011-06-16 10:54:22.618 DEBUG [mrcp/1-t-5] #MSCTRL#: rtcs=null, sigDetRTCs=null, promptRTCs=null
2011-06-16 10:54:22.619 DEBUG [mrcp/1-t-5] #MSCTRL#: DetectionItem[DetectionItemIdx_0, -1, patternLabels={SD_PATTERN_0,SD_PATTERN_1}, rtcs=null, optargs={SD_PROMPT=data:application%2Fssml%2Bxml%2C%3C%3Fxml+version%3D%221.0%22%3F%3E%3Cspeak%3E%3Cvoice%3EPress+or+say++1+for+testing+TTS%2C+Press+or+say+2+for+testing+Recording%3C%2Fvoice%3E%3C%2Fspeak%3E, SD_PATTERN_1=2,two, SD_PATTERN_0=1,one}, null]
2011-06-16 10:54:22.619 DEBUG [mrcp/1-t-5] #MSCTRL#: Playing prompt on Player[IDLE, MG[ms1-1, mg2]]
2011-06-16 10:54:22.621 DEBUG [mrcp/1-t-5] #MSCTRL#: Add PlayListItem[0, 1, true, rtcs=null, optargs={PROMPT_BARGE_IN=false, PROMPT_FOR_SIGDET=true, PROMPT_FOR_RECORDER=false},"<?xml version="1.0"?><speak><voice>Press or say 1 for testing TTS, Press or say 2 for testing Recording</voice></speak>"]
2011-06-16 10:54:22.621 DEBUG [mrcp/1-t-5] #MSCTRL#: Find PlayListItem[IDLE, 0, 1, true]
2011-06-16 10:54:22.621 DEBUG [mrcp/1-t-5] #MSCTRL#: Player[IDLE, MG[ms1-1, mg2]] starts playing PlayListItem[IDLE, 0, 1, true]
2011-06-16 10:54:22.621 DEBUG [mrcp/1-t-5] #MSCTRL#: Player[ACTIVE, MG[ms1-1, mg2]] moves state from [IDLE] to [ACTIVE]
2011-06-16 10:54:22.621 DEBUG [mrcp/1-t-5] #MSCTRL#: PlayListItem[0, 1] moves state from [IDLE] to [PLAYING]
2011-06-16 10:54:22.624 DEBUG [mrcp/1-t-5] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.44:10074/synthesizer/ RTSP/1.0\r\nCseq: 4\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 312\r\n\r\nSPEAK 54001 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: 120\r\n\r\n<?xml version="1.0"?><speak><voice>Press or say 1 for testing TTS, Press or say 2 for testing Recording</voice></speak> #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:22.626 DEBUG [mrcp/1-t-6] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nCseq: 4\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 54001 200 IN-PROGRESS\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:22.628 DEBUG [mrcp/1-t-5] #MSCTRL#: PlayListItem[0, 1] added (54001, 2547986646-2001e00-0b06d070-00000001)
2011-06-16 10:54:22.628 DEBUG [mrcp/1-t-5] #MSCTRL#: signal buffer{}
2011-06-16 10:54:22.632 DEBUG [mrcp/1-t-5] #MSCTRL#: MG[ms1-1, mg2] added MrcpRecognizeListener[SigDet[IDLE, MG[ms1-1, mg2]], ACTIVE] #[2547986646-2001e00-0b06d070-00000001]
2011-06-16 10:54:22.705 DEBUG [mrcp/1-t-5] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.44:10074/recognizer/ RTSP/1.0\r\nCseq: 5\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 356\r\n\r\nDEFINE-GRAMMAR 54002 MRCP/1.0\r\nSpeech-Language: en-US\r\nVendor-Specific-Parameters: Voxeo-Input-Mode=dtmf voice\r\nContent-Type: application/x-jsgf\r\nContent-Length: 151\r\nContent-Id: [email protected]\r\n\r\n#JSGF 1.0;\ngrammar SIMPLE_GRAMMAR_353EF8108FB2AB27D14CA91626615210;\npublic <SIMPLE_GRAMMAR_353EF8108FB2AB27D14CA91626615210> = (/1.0/dtmf-2|/1.0/two);\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:22.709 DEBUG [mrcp/1-t-7] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nCseq: 5\r\nContent-Type: application/mrcp\r\nContent-Length: 31\r\n\r\nMRCP/1.0 54002 200 COMPLETE\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:22.709 DEBUG [mrcp/1-t-5] #MSCTRL#: define a Grammar[SD_PATTERN_1]-[[email protected]] #[2547986646-2001e00-0b06d070-00000001]
2011-06-16 10:54:22.712 DEBUG [mrcp/1-t-5] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.44:10074/recognizer/ RTSP/1.0\r\nCseq: 6\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 356\r\n\r\nDEFINE-GRAMMAR 54003 MRCP/1.0\r\nSpeech-Language: en-US\r\nVendor-Specific-Parameters: Voxeo-Input-Mode=dtmf voice\r\nContent-Type: application/x-jsgf\r\nContent-Length: 151\r\nContent-Id: [email protected]\r\n\r\n#JSGF 1.0;\ngrammar SIMPLE_GRAMMAR_DE20BB3EBED48FF24589F1C3016DC1F2;\npublic <SIMPLE_GRAMMAR_DE20BB3EBED48FF24589F1C3016DC1F2> = (/1.0/dtmf-1|/1.0/one);\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:22.720 DEBUG [mrcp/1-t-8] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nCseq: 6\r\nContent-Type: application/mrcp\r\nContent-Length: 31\r\n\r\nMRCP/1.0 54003 200 COMPLETE\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:22.721 DEBUG [mrcp/1-t-5] #MSCTRL#: define a Grammar[SD_PATTERN_0]-[[email protected]] #[2547986646-2001e00-0b06d070-00000001]
2011-06-16 10:54:22.729 DEBUG [mrcp/1-t-5] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.44:10074/recognizer/ RTSP/1.0\r\nCseq: 7\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 347\r\n\r\nRECOGNIZE 54004 MRCP/1.0\r\nDtmf-Interdigit-Timeout: 0\r\nConfidence-Threshold: 30\r\nClear-DTMF-Buffer: false\r\nSpeech-Language: en-US\r\nSensitivity-Level: 50\r\nDtmf-Term-Timeout: 0\r\nVendor-Specific-Parameters: Voxeo-Input-Mode=dtmf voice\r\nContent-Type: text/uri-list\r\nContent-Length: 64\r\n\r\nsession:[email protected]\r\nsession:[email protected]\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:22.811 DEBUG [mrcp/1-t-9] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nCseq: 7\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 54004 200 IN-PROGRESS\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:22.820 DEBUG [mrcp/1-t-5] #MSCTRL#: DetectionItem[DetectionItemIdx_0, -1, {SD_PATTERN_0,SD_PATTERN_1}, dtmf voice, null, recoId=54004, asrType=prophecy] #[2547986646-2001e00-0b06d070-00000001]
2011-06-16 10:54:22.821 DEBUG [mrcp/1-t-5] #MSCTRL#: SigDet[WAIT_FOR_PROMPT_DONE, MG[ms1-1, mg2]] moves state from [IDLE] to [WAIT_FOR_PROMPT_DONE]
2011-06-16 10:54:27.881 DEBUG [mrcp/1-t-10] #MRCP#: (i)ANNOUNCE rtsp://192.168.0.44:10074/synthesizer/ RTSP/1.0\r\nCseq: 2\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 72\r\n\r\nSPEAK-COMPLETE 54001 COMPLETE MRCP/1.0\r\ncompletion-cause: 000 normal\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:27.881 DEBUG [mrcp/1-t-10] #MRCP#: (o)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nCseq: 2\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:27.883 DEBUG [mrcp/1-t-11] #MRCP#: Handling SPEAK-COMPLETE[54001] #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:27.884 DEBUG [mrcp/1-t-11] #MSCTRL#: Find PlayListItem[PLAYING, 0, 1, true, speakIds=[54001]]
2011-06-16 10:54:27.884 DEBUG [mrcp/1-t-11] #MSCTRL#: MrcpSpeakListener[Player[ACTIVE, MG[ms1-1, mg2]], ACTIVE] handling with MrcpSpeakCompleteEvent[originalId:54001, requestId:54001, rc:0, duration:5262] #[2547986646-2001e00-0b06d070-00000001]
2011-06-16 10:54:27.884 DEBUG [mrcp/1-t-11] #MSCTRL#: PlayListItem[0, 1] removed (54001, 2547986646-2001e00-0b06d070-00000001)
2011-06-16 10:54:27.885 DEBUG [mrcp/1-t-11] #MSCTRL#: PlayListItem[0, 1] moves state from [PLAYING] to [IDLE]
2011-06-16 10:54:27.885 DEBUG [mrcp/1-t-11] #MSCTRL#: Player[IDLE, MG[ms1-1, mg2]] moves state from [ACTIVE] to [IDLE]
2011-06-16 10:54:27.885 DEBUG [mrcp/1-t-11] #MSCTRL#: clear up playList=[PlayListItem[IDLE, 0, 1, true]]
2011-06-16 10:54:27.887 DEBUG [msctrl/1-t-2] #MSCTRL#: Prompt for SigDet[WAIT_FOR_PROMPT_DONE, MG[ms1-1, mg2]] is complete.
2011-06-16 10:54:27.889 DEBUG [msctrl/1-t-2] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.44:10074/recognizer/ RTSP/1.0\r\nCseq: 8\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 102\r\n\r\nGET-PARAMS 54005 MRCP/1.0\r\nClear-DTMF-Buffer: false\r\nVendor-Specific-Parameters: Voxeo-DTMF-Buffer\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:27.892 DEBUG [mrcp/1-t-12] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nCseq: 8\r\nContent-Type: application/mrcp\r\nContent-Length: 80\r\n\r\nMRCP/1.0 54005 200 COMPLETE\r\nvendor-specific-parameters: Voxeo-DTMF-Buffer=;\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:27.894 DEBUG [msctrl/1-t-2] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.44:10074/recognizer/ RTSP/1.0\r\nCseq: 9\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 126\r\n\r\nRECOGNITION-START-TIMERS 54006 MRCP/1.0\r\nClear-DTMF-Buffer: false\r\nVendor-Specific-Parameters: Voxeo-Input-Mode=dtmf voice\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:27.902 DEBUG [mrcp/1-t-13] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nCseq: 9\r\nContent-Type: application/mrcp\r\nContent-Length: 31\r\n\r\nMRCP/1.0 54006 200 COMPLETE\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:27.903 DEBUG [msctrl/1-t-2] #MSCTRL#: SigDet[ACTIVE, MG[ms1-1, mg2]] moves state from [WAIT_FOR_PROMPT_DONE] to [ACTIVE]
2011-06-16 10:54:36.716 DEBUG [Timer-8] #SIP#: InviteServerTransaction[_state=ACCEPTED, _id=z9hG4bK-d8754z-4342715b7820e428-1---d8754z-] timerRemoveTransaction is fired. #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:36.716 DEBUG [Timer-8] #SIP#: InviteServerTransaction[_state=TERMINATED, _id=z9hG4bK-d8754z-4342715b7820e428-1---d8754z-] is released. #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:39.808 DEBUG [SocketAcceptorIoProcessor-0.0] #CONNECTOR#: NIOTCPOutgoingConnection[/127.0.0.1:5222-->/127.0.0.1:49420] is closed.
2011-06-16 10:54:39.808 ERROR [SocketAcceptorIoProcessor-0.0] #CONNECTOR#: XMPPTcpConnector[/0.0.0.0] can not found ClientConnection: /127.0.0.1:49420 srcPort: 5222
2011-06-16 10:54:39.809 DEBUG [SocketAcceptorIoProcessor-0.0] #CONNECTOR#: NIOTCPIncomingConnection[/127.0.0.1:49420-->/127.0.0.1:5222] is closed.
2011-06-16 10:54:39.809 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)</stream:stream> #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:39.813 DEBUG [XMPPService-t-8] #XMPP#: XMPPSessionImpl: _id=xmpps_v48rdx56b1cp, _direction=RECEIVEStream, _sessionType=CLIENT, [email protected]/voxeo, _state=TERMINATED, _remoteAddr=/127.0.0.1, _remotePort=49420, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo-0, _state=STARTED] is invalidating. (s) #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][null]
2011-06-16 10:54:39.814 DEBUG [XMPPService-t-8] #XMPP#: Close underlizing connection for session:XMPPSessionImpl: _id=xmpps_v48rdx56b1cp, _direction=RECEIVEStream, _sessionType=CLIENT, [email protected]/voxeo, _state=TERMINATED, _remoteAddr=/127.0.0.1, _remotePort=49420, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo-0, _state=STARTED]
2011-06-16 10:54:39.815 DEBUG [XMPPService-t-8] #XMPP#: Invoke application:tropo ozone
2011-06-16 10:54:39.815 DEBUG [XMPPService-t-8] #XMPP#: Forwarding Request #[tropo][null][xmpps_v48rdx56b1cp][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49420][127.0.0.1:5222][xmpp][null]
2011-06-16 10:54:45.351 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: Creating xmpp session with app: ApplicationImpl[_symbolicName=tropo-0, _state=STARTED] #[N/A][N/A][N/A][?, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.352 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: Created session: XMPPSessionImpl: _id=xmpps_1br1lh3lyb225, _direction=RECEIVEStream, _sessionType=CLIENT, _remotJID=null, _state=INITIAL, _remoteAddr=/127.0.0.1, _remotePort=49428, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo-0, _state=STARTED] #[N/A][N/A][N/A][?, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.352 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"> #[tropo][null][xmpps_1br1lh3lyb225][?, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.354 DEBUG [XMPPService-t-9] #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_1br1lh3lyb225" xml:lang="en"> #[tropo][null][xmpps_1br1lh3lyb225][?, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.354 DEBUG [XMPPService-t-9] #XMPP#: Send message to: 127.0.0.1:49428 by xmpp #[tropo][null][xmpps_1br1lh3lyb225][?, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.355 DEBUG [XMPPService-t-9] #XMPP#: (o)<stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism></mechanisms></stream:features> #[tropo][null][xmpps_1br1lh3lyb225][?, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.355 DEBUG [XMPPService-t-9] #XMPP#: Send message to: 127.0.0.1:49428 by xmpp #[tropo][null][xmpps_1br1lh3lyb225][?, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.357 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">dXNlcmJAMTI3LjAuMC4xAHVzZXJiADE=</auth> #[tropo][null][xmpps_1br1lh3lyb225][?, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.358 DEBUG [XMPPService-t-10] #XMPP#: (o)<success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/> #[tropo][null][xmpps_1br1lh3lyb225][?, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.359 DEBUG [XMPPService-t-10] #XMPP#: Send message to: 127.0.0.1:49428 by xmpp #[tropo][null][xmpps_1br1lh3lyb225][?, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.362 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"> #[tropo][null][xmpps_1br1lh3lyb225][[email protected], 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.363 DEBUG [XMPPService-t-11] #XMPP#: Invoke application:tropo ozone
2011-06-16 10:54:45.363 DEBUG [XMPPService-t-11] #XMPP#: Forwarding Request #[tropo][null][xmpps_1br1lh3lyb225][[email protected], 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][null]
2011-06-16 10:54:45.363 DEBUG [XMPPService-t-11] #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_1br1lh3lyb225" xml:lang="en"> #[tropo][null][xmpps_1br1lh3lyb225][[email protected], 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.363 DEBUG [XMPPService-t-11] #XMPP#: Send message to: 127.0.0.1:49428 by xmpp #[tropo][null][xmpps_1br1lh3lyb225][[email protected], 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.363 DEBUG [XMPPService-t-11] #XMPP#: (o)<stream:features><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></stream:features> #[tropo][null][xmpps_1br1lh3lyb225][[email protected], 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.363 DEBUG [XMPPService-t-11] #XMPP#: Send message to: 127.0.0.1:49428 by xmpp #[tropo][null][xmpps_1br1lh3lyb225][[email protected], 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.365 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq type="set" id="blather0002"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/></iq> #[tropo][null][xmpps_1br1lh3lyb225][[email protected], 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.366 DEBUG [XMPPService-t-12] #XMPP#: Invoke application:tropo ozone
2011-06-16 10:54:45.366 DEBUG [XMPPService-t-12] #XMPP#: Forwarding Request #[tropo][null][xmpps_1br1lh3lyb225][[email protected], 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][null]
2011-06-16 10:54:45.366 DEBUG [XMPPService-t-12] <iq type="set" id="blather0002" to="127.0.0.1" from="[email protected]"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/></iq> :: xmpps_1br1lh3lyb225
2011-06-16 10:54:45.367 DEBUG [XMPPService-t-12] #XMPP#: Intercept iq bind result, set full jid [email protected]/voxeo to session XMPPSessionImpl: _id=xmpps_1br1lh3lyb225, _direction=RECEIVEStream, _sessionType=CLIENT, [email protected]/voxeo, _state=CONFIRMED, _remoteAddr=/127.0.0.1, _remotePort=49428, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo-0, _state=STARTED] #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.367 DEBUG [XMPPService-t-12] #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> #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.367 DEBUG [XMPPService-t-12] #XMPP#: Send message to: 127.0.0.1:49428 by xmpp #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.368 INFO [XMPPService-t-12] Bound client resource [[email protected]/voxeo]
2011-06-16 10:54:45.370 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq type="set" id="blather0004" to="127.0.0.1"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.371 DEBUG [XMPPService-t-13] #XMPP#: Invoke application:tropo ozone
2011-06-16 10:54:45.371 DEBUG [XMPPService-t-13] #XMPP#: Forwarding Request #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][null]
2011-06-16 10:54:45.371 DEBUG [XMPPService-t-13] <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_1br1lh3lyb225
2011-06-16 10:54:45.371 DEBUG [XMPPService-t-13] #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> #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.371 DEBUG [XMPPService-t-13] #XMPP#: Send message to: 127.0.0.1:49428 by xmpp #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.373 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<iq type="get" id="blather0006"><query xmlns="jabber:iq:roster"/></iq> #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.374 DEBUG [XMPPService-t-14] #XMPP#: Invoke application:tropo ozone
2011-06-16 10:54:45.374 DEBUG [XMPPService-t-14] #XMPP#: Forwarding Request #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][null]
2011-06-16 10:54:45.374 DEBUG [XMPPService-t-14] <iq type="get" id="blather0006" to="127.0.0.1" from="[email protected]/voxeo"><query xmlns="jabber:iq:roster"/></iq> :: xmpps_1br1lh3lyb225
2011-06-16 10:54:45.374 DEBUG [XMPPService-t-14] #XMPP#: (o)<iq type="error" id="blather0006" to="[email protected]/voxeo" from="127.0.0.1"><query xmlns="jabber:iq:roster"/><error type="cancel"><feature-not-implemented xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq> #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.375 DEBUG [XMPPService-t-14] #XMPP#: Send message to: 127.0.0.1:49428 by xmpp #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.377 DEBUG [SocketAcceptorIoProcessor-0.1] #XMPP#: (i)<presence/> #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][N/A]
2011-06-16 10:54:45.377 DEBUG [XMPPService-t-15] #XMPP#: Invoke application:tropo ozone
2011-06-16 10:54:45.377 DEBUG [XMPPService-t-15] #XMPP#: Forwarding Request #[tropo][null][xmpps_1br1lh3lyb225][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49428][127.0.0.1:5222][xmpp][null]
2011-06-16 10:54:49.177 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[ACK sip:192.168.0.44:5060;transport=udp SIP/2.0\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 192.168.0.44:21702;branch=z9hG4bK-d8754z-71a56e4bdb62bf47-1---d8754z-;rport\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nUser-Agent: Bria 3 release 3.2 stamp 61503\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nMax-Forwards: 70\r\nContact: <sip:[email protected]:21702>\r\n\r\n] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:49.178 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Find Path[ id=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.-2d6c7340-2yq63kdg5mrb, path=ApplicationPath[_id=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.-2d6c7340-2yq63kdg5mrb, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_qltdj9ypjpso, appSessionId=sas_2-15-sm1bkkd6xcyonrgPrismDemoApp]]]]]] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:49.178 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv request: ACK #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:49.178 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:49.180 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:54:49.181 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:54:52.763 DEBUG [mrcp/1-t-14] #MRCP#: (i)ANNOUNCE rtsp://192.168.0.44:10074/recognizer/ RTSP/1.0\r\nCseq: 3\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 88\r\n\r\nRECOGNITION-COMPLETE 54004 COMPLETE MRCP/1.0\r\ncompletion-cause: 002 no-input-timeout\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:52.764 DEBUG [mrcp/1-t-14] #MRCP#: (o)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nCseq: 3\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:52.765 DEBUG [mrcp/1-t-15] #MRCP#: Handling RECOGNITION-COMPLETE[54004] #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:52.767 DEBUG [mrcp/1-t-15] #MSCTRL#: MrcpRecognizeListener[SigDet[ACTIVE, MG[ms1-1, mg2]], ACTIVE] handling with MrcpRecognitionCompleteEvent[originalId:54004, requestId:54004] #[2547986646-2001e00-0b06d070-00000001]
2011-06-16 10:54:52.771 DEBUG [mrcp/1-t-15] #MSCTRL#: MrcpAsrResult{type:NO_SPEECH, } #[2547986646-2001e00-0b06d070-00000001]
2011-06-16 10:54:52.771 DEBUG [mrcp/1-t-15] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.44:10074/recognizer/ RTSP/1.0\r\nCseq: 10\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 101\r\n\r\nGET-PARAMS 54007 MRCP/1.0\r\nClear-DTMF-Buffer: true\r\nVendor-Specific-Parameters: Voxeo-DTMF-Buffer\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:52.773 DEBUG [mrcp/1-t-16] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2547986646-2001e00-0b06d070-00000001\r\nCseq: 10\r\nContent-Type: application/mrcp\r\nContent-Length: 80\r\n\r\nMRCP/1.0 54007 200 COMPLETE\r\nvendor-specific-parameters: Voxeo-DTMF-Buffer=;\r\n\r\n #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:54:52.779 DEBUG [mrcp/1-t-15] #MSCTRL#: signal buffer{}
2011-06-16 10:54:52.781 DEBUG [mrcp/1-t-15] #MSCTRL#: SigDet[IDLE, MG[ms1-1, mg2]] moves state from [ACTIVE] to [IDLE]
2011-06-16 10:54:52.782 DEBUG [mrcp/1-t-15] #MSCTRL#: Return SigDetEvt[SigDet[IDLE, MG[ms1-1, mg2]], RECEIVE_SIGNALS_COMPLETED, NO_ERROR, null, INITIAL_TIMEOUT_EXCEEDED, null, -1, null, null, null, null] to the application
2011-06-16 10:54:52.783 DEBUG [mrcp/1-t-15] #MSCTRL#: signal buffer{}
2011-06-16 10:55:41.848 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: (i)[ACK sip:192.168.0.44:5060;transport=udp SIP/2.0\r\nTo: <sip:[email protected]:5060>;tag=2yq63kdg5mrb\r\nVia: SIP/2.0/UDP 192.168.0.44:21702;branch=z9hG4bK-d8754z-71a56e4bdb62bf47-1---d8754z-;rport\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nCall-ID: OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.\r\nUser-Agent: Bria 3 release 3.2 stamp 61503\r\nFrom: <sip:[email protected]>;tag=2d6c7340\r\nMax-Forwards: 70\r\nContact: <sip:[email protected]:21702>\r\n\r\n] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:55:41.849 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Find Path[ id=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.-2d6c7340-2yq63kdg5mrb, path=ApplicationPath[_id=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.-2d6c7340-2yq63kdg5mrb, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_qltdj9ypjpso, appSessionId=sas_2-15-sm1bkkd6xcyonrgPrismDemoApp]]]]]] #[N/A][N/A][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][N/A][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:55:41.849 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SessionManagementLayer recv request: ACK #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](192.168.0.44:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:55:41.849 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:55:41.849 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [ss_qltdj9ypjpso], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:55:41.850 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [sas_2-15-sm1bkkd6xcyonrgPrismDemoApp], invalidateWhenReady: true
2011-06-16 10:56:40.267 ERROR [mrcp/1-t-17] #MRCP#: ERROR_RTSPCONNECTION_READ_FAILED@T: java.io.IOException: Connection reset by peer\n at sun.nio.ch.FileDispatcher.read0(Native Method)\n at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)\n at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:202)\n at sun.nio.ch.IOUtil.read(IOUtil.java:169)\n at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:243)\n at com.mot.mrcp.mrcpv1.rtsp.RtspConnectionThread.run(RtspConnectionThread.java:70)\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 #[2547986646-2001e00-0b06d070-00000001][192.168.0.44:10074][192.168.0.44:49423]
2011-06-16 10:59:04.348 DEBUG [Timer-8] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-15-sm1bkkd6xcyonrgPrismDemoApp] is expiring.
2011-06-16 10:59:04.348 DEBUG [Timer-8] #SIP#: SipApplicationSessionImpl[_state=EXPIRING, _id=sas_2-15-sm1bkkd6xcyonrgPrismDemoApp] is invalidating. (as)
2011-06-16 10:59:04.350 DEBUG [Timer-8] #SIP#: SipSessionImpl[_id=ss_qltdj9ypjpso, _parentId=sas_2-15-sm1bkkd6xcyonrgPrismDemoApp, _handler=PrismSample, _state=CONFIRMED, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=INVITE, _callId=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.] is invalidating. (s) #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
2011-06-16 10:59:04.351 DEBUG [Timer-8] #SIP#: Remove Path[ id=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.-2d6c7340-2yq63kdg5mrb, session=SipSessionImpl[_id=ss_qltdj9ypjpso, _parentId=sas_2-15-sm1bkkd6xcyonrgPrismDemoApp, _handler=PrismSample, _state=CONFIRMED, _fresh=false, _valid=true, _unavailable=true, _role=UAS, _method=INVITE, _callId=OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.]] #[PrismDemoApp][sas_2-15-sm1bkkd6xcyonrgPrismDemoApp][OWIyMjlkZTRhYWY3ZTU1OTY4Y2UyNTY2NGU3YjkyNDI.][ss_qltdj9ypjpso][sip:[email protected](127.0.0.1:21702)][sip:[email protected]:5060(192.168.0.44:5060)]
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment