Skip to content

Instantly share code, notes, and snippets.

@zlu

zlu/sipmethod.log

Created August 6, 2011 00:09
Show Gist options
  • Save zlu/1128812 to your computer and use it in GitHub Desktop.
Save zlu/1128812 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
sipmethod.log
2011-08-05 16:23:37.206 INFO [pool-16-thread-21] Message [[Event class=com.voxeo.moho.sip.SIPAnsweredEventImpl sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:37.210 INFO [pool-16-thread-21] Queued Event [AnsweredEvent[callId=a3f75438-9c74-4b66-9c51-7b9e8033768e]]
2011-08-05 16:23:37.210 INFO [pool-16-thread-21] Event [AnsweredEvent[callId=a3f75438-9c74-4b66-9c51-7b9e8033768e]]
2011-08-05 16:23:37.210 DEBUG [pool-16-thread-21] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><answered xmlns="urn:xmpp:rayo:1"/></presence> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:37.210 DEBUG [pool-16-thread-21] #XMPP#: Send message to: 127.0.0.1:57613 by xmpp #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:37.211 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nCseq: 2\r\nContent-Type: application/sdp\r\nContent-Length: 181\r\n\r\nv=0\r\no=- 10766 10766 IN IP4 71.198.132.91\r\ns=voxeo\r\nc=IN IP4 71.198.132.91\r\nt=0 0\r\nm=audio 20038 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:37.212 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/recognizer/ RTSP/1.0\r\nCseq: 3\r\nTransport: RTP/AVP;unicast;\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nContent-Type: application/sdp\r\nContent-Length: 255\r\n\r\nv=0\r\no=- 3521575406 3521575407 IN IP4 71.198.132.91\r\ns=pjmedia\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\na=X-nat:0\r\nm=audio 47128 RTP/AVP 0 101\r\na=rtcp:4009 IN IP4 192.168.0.196\r\na=rtpmap:0 PCMU/8000\r\na=sendrecv\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:37.222 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nTransport: RTP/AVP;unicast;client_port=47128-47129;server_port=20038-20039\r\nCseq: 3\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:37.222 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-20, nc1] updates the ASR session. #[2621581164-2e2ac00-0ac44840-00000014]
2011-08-05 16:23:37.223 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/synthesizer/ RTSP/1.0\r\nCseq: 4\r\nTransport: RTP/AVP;unicast;\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:37.233 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nTransport: RTP/AVP;unicast;client_port=47128-47129;server_port=20038-20039\r\nCseq: 4\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:37.233 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-20, nc1] updates the TTS session. #[2621581164-2e2ac00-0ac44840-00000014]
2011-08-05 16:23:37.235 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-05 16:23:37.236 DEBUG [msctrl/2-t-25] #MSCTRL#: SdpPort[SDP_NEGOTIATED, NC[ms2-20, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATED]
2011-08-05 16:23:37.236 DEBUG [msctrl/2-t-25] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATED, NC[ms2-20, nc1]], ANSWER_PROCESSED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 13 13 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20038 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-05 16:23:37.236 INFO [pool-16-thread-21] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:38.220 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)<iq type="set" to="[email protected]" id="blather000a" 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="a3f75438-9c74-4b66-9c51-7b9e8033768e"/>\n </dial>\n</iq> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:38.220 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo
2011-08-05 16:23:38.220 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][null]
2011-08-05 16:23:38.220 DEBUG [XMPPService-t-40] <iq type="set" to="[email protected]" id="blather000a" 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="a3f75438-9c74-4b66-9c51-7b9e8033768e"/>
</dial>
</iq> :: xmpps_8dpz25pvdd4y
2011-08-05 16:23:38.221 INFO [pool-16-thread-21] Request [DialCommand[from=sip:[email protected],to=sip:[email protected],headers={},join=JoinCommand[callId=<null>,direction=DUPLEX,media=BRIDGE,to=a3f75438-9c74-4b66-9c51-7b9e8033768e,type=CALL]]]
2011-08-05 16:23:38.225 INFO [pool-16-thread-21] Reply [com.tropo.core.CallRef@9024c3]
2011-08-05 16:23:38.225 DEBUG [pool-16-thread-21] #XMPP#: (o)<iq type="result" id="blather000a" from="[email protected]" to="[email protected]/voxeo"><ref xmlns="urn:xmpp:rayo:1" id="02feb2bb-96f6-4d9b-9e0e-0c6e10136fe2"/></iq> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:38.225 DEBUG [pool-16-thread-21] #XMPP#: Send message to: 127.0.0.1:57613 by xmpp #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:38.229 INFO [pool-16-thread-22] Message [SIPCallImpl[null,INITIALIZED]]
2011-08-05 16:23:38.231 INFO [MOHO-42] #MSCTRL#: MS[ms2-21] creates a MediaObject[BASIC, nc1, null]
2011-08-05 16:23:38.231 INFO [MOHO-42] #MSCTRL#: SdpPort[IDLE, NC[ms2-21, nc1]] generates a SDP offer
2011-08-05 16:23:38.231 DEBUG [MOHO-42] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-21, nc1]] moves state from [IDLE] to [UNDER_PROCESSING]
2011-08-05 16:23:38.232 DEBUG [msctrl/2-t-25] #MRCP#: load configuration from {maxThreadPool=2147483647, minThreadPool=25, MEDIAOBJECT_ID=nc1, com.voxeo.useLocalConfigurationOnGUTFailures=false}
2011-08-05 16:23:38.243 DEBUG [msctrl/2-t-25] #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:57618]
2011-08-05 16:23:38.254 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nTransport: RTP/AVP;unicast;client_port=65535-65536;server_port=20040-20041\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 20040 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:57618]
2011-08-05 16:23:38.255 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-21, nc1] initializes the ASR session. #[2621592952-2239e00-0ac44840-00000015]
2011-08-05 16:23:38.255 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-05 16:23:38.255 DEBUG [msctrl/2-t-25] #MSCTRL#: SdpPort[SDP_NEGOTIATING, NC[ms2-21, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATING]
2011-08-05 16:23:38.255 DEBUG [msctrl/2-t-25] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATING, NC[ms2-21, 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 20040 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-05 16:23:38.256 DEBUG [msctrl/2-t-25] #SIP#: Session creating: ss_1azav1yg51u62 #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:38.256 DEBUG [msctrl/2-t-25] #SIP#: SetRoutingDirective: NEW #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:38.256 DEBUG [msctrl/2-t-25] #SIP#: SessionManagementLayer send request: INVITE sip:[email protected] #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:38.317 DEBUG [msctrl/2-t-25] #SIP#: The transaction was created: z9hG4bK1lorvn15ms5vs #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:38.318 DEBUG [msctrl/2-t-25] #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=z9hG4bK1lorvn15ms5vs\r\nCSeq: 1 INVITE\r\nContent-Length: 421\r\nCall-ID: 1tdftnbhe6y2f\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=140n6qwfq93n9\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 20040 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-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:38.345 DEBUG [msctrl/2-t-25] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:38.346 DEBUG [msctrl/2-t-25] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:38.582 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 100 trying -- your call is important to us\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bK1lorvn15ms5vs;rport=57243;received=71.198.132.91\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 1tdftnbhe6y2f\r\nServer: ser (3.2.0-dev2 (i386/linux))\r\nFrom: <sip:[email protected]>;tag=140n6qwfq93n9\r\nWarning: 392 213.192.59.75:5060 "Noisy feedback tells: pid=19077 req_src_ip=71.198.132.91 req_src_port=57243 in_uri=sip:[email protected] out_uri=sip:[email protected]:55497;transport=tcp via_cnt==1"\r\n\r\n] #[N/A][N/A][1tdftnbhe6y2f][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:38.583 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 100/INVITE, branch=z9hG4bK1lorvn15ms5vs #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:38.586 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/100 #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:38.586 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:38.586 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1azav1yg51u62], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:38.589 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:39.024 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 180 Ringing\r\nTo: <sip:[email protected]>;tag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bK1lorvn15ms5vs\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=140n6qwfq93n9;avp=FbADBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2Q>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 1tdftnbhe6y2f\r\nServer: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=140n6qwfq93n9\r\nContact: <sip:[email protected]:55062;transport=tcp>\r\n\r\n] #[N/A][N/A][1tdftnbhe6y2f][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:39.024 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 180/INVITE, branch=z9hG4bK1lorvn15ms5vs #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:39.025 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/180 #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:39.026 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Add Path[ id=1tdftnbhe6y2f-ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC-140n6qwfq93n9, session=SipSessionImpl[_id=ss_1azav1yg51u62, _parentId=sas_2-15-sm10va9ksndqzfitropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=1tdftnbhe6y2f], party= CALLEE] #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:39.026 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:39.026 DEBUG [tcp/0.0.0.0/5060-t-12] [SIP/2.0 180 Ringing
To: <sip:[email protected]>;tag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC
Via: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bK1lorvn15ms5vs
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Record-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=140n6qwfq93n9;avp=FbADBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2Q>
CSeq: 1 INVITE
Content-Length: 0
Call-ID: 1tdftnbhe6y2f
Server: Blink Pro 1.1.1 (MacOSX)
From: <sip:[email protected]>;tag=140n6qwfq93n9
Contact: <sip:[email protected]:55062;transport=tcp>
]
2011-08-05 16:23:39.026 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:39.026 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1azav1yg51u62], current State = EARLY, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:39.026 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:39.028 INFO [pool-16-thread-22] Message [[Event class=com.voxeo.moho.sip.SIPRingEventImpl sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:39.029 INFO [pool-16-thread-22] Queued Event [RingingEvent[callId=02feb2bb-96f6-4d9b-9e0e-0c6e10136fe2]]
2011-08-05 16:23:39.029 INFO [pool-16-thread-22] Event [RingingEvent[callId=02feb2bb-96f6-4d9b-9e0e-0c6e10136fe2]]
2011-08-05 16:23:39.029 DEBUG [pool-16-thread-22] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><ringing xmlns="urn:xmpp:rayo:1"/></presence> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:39.029 DEBUG [pool-16-thread-22] #XMPP#: Send message to: 127.0.0.1:57613 by xmpp #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:42.049 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bK1lorvn15ms5vs\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=140n6qwfq93n9;avp=FbADBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2Q>\r\nCSeq: 1 INVITE\r\nContent-Length: 241\r\nSupported: 100rel, norefersub\r\nCall-ID: 1tdftnbhe6y2f\r\nServer: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=140n6qwfq93n9\r\nContact: <sip:[email protected]:55062;transport=tcp>\r\n\r\nv=0\r\no=- 3521575421 3521575422 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47136 RTP/AVP 0 101\r\na=rtcp:50013\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n] #[N/A][N/A][1tdftnbhe6y2f][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:42.049 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 200/INVITE, branch=z9hG4bK1lorvn15ms5vs #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:42.050 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/200 #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:42.050 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:42.050 DEBUG [tcp/0.0.0.0/5060-t-12] [SIP/2.0 200 OK
Content-Type: application/sdp
To: <sip:[email protected]>;tag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC
Via: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bK1lorvn15ms5vs
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Record-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=140n6qwfq93n9;avp=FbADBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2Q>
CSeq: 1 INVITE
Content-Length: 241
Supported: 100rel, norefersub
Call-ID: 1tdftnbhe6y2f
Server: Blink Pro 1.1.1 (MacOSX)
From: <sip:[email protected]>;tag=140n6qwfq93n9
Contact: <sip:[email protected]:55062;transport=tcp>
v=0
o=- 3521575421 3521575422 IN IP4 192.168.0.196
s=Blink Pro 1.1.1 (MacOSX)
c=IN IP4 213.192.59.91
t=0 0
m=audio 47136 RTP/AVP 0 101
a=rtcp:50013
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
]
2011-08-05 16:23:42.051 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer send request: ACK sip:[email protected]:55062;transport=tcp #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:42.052 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (o)[ACK sip:[email protected]:55062;transport=tcp SIP/2.0\r\nTo: <sip:[email protected]>;tag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bKfaomd4vyql0g;x-sm-sid=7d66feb5-ce8b-4dcd-98b8-3614b7151a47;x-sm-nid=ss_1azav1yg51u62\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nRoute: <sip:213.192.59.75;transport=tcp;lr;ftag=140n6qwfq93n9;avp=FbADBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2Q>\r\nCall-ID: 1tdftnbhe6y2f\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=140n6qwfq93n9\r\n\r\n] #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:42.052 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Send message to: /213.192.59.75:5060 by tcp #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:42.053 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:42.053 INFO [tcp/0.0.0.0/5060-t-12] #MSCTRL#: SdpPort[SDP_NEGOTIATING, NC[ms2-21, nc1]] processes a SDP answer \nv=0\r\no=- 3521575421 3521575422 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47136 RTP/AVP 0 101\r\na=rtcp:50013\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n
2011-08-05 16:23:42.054 DEBUG [tcp/0.0.0.0/5060-t-12] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-21, nc1]] moves state from [SDP_NEGOTIATING] to [UNDER_PROCESSING]
2011-08-05 16:23:42.054 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-05 16:23:42.054 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:42.054 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1azav1yg51u62], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:42.055 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:42.055 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 2\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nContent-Type: application/sdp\r\nContent-Length: 241\r\n\r\nv=0\r\no=- 3521575421 3521575422 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47136 RTP/AVP 0 101\r\na=rtcp:50013\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:42.056 INFO [pool-16-thread-22] Message [[Event class=com.voxeo.moho.sip.SIPAnsweredEventImpl sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:42.056 INFO [pool-16-thread-22] Queued Event [AnsweredEvent[callId=02feb2bb-96f6-4d9b-9e0e-0c6e10136fe2]]
2011-08-05 16:23:42.056 INFO [pool-16-thread-22] Event [AnsweredEvent[callId=02feb2bb-96f6-4d9b-9e0e-0c6e10136fe2]]
2011-08-05 16:23:42.057 DEBUG [pool-16-thread-22] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><answered xmlns="urn:xmpp:rayo:1"/></presence> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:42.058 DEBUG [pool-16-thread-22] #XMPP#: Send message to: 127.0.0.1:57613 by xmpp #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:42.062 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nCseq: 2\r\nContent-Type: application/sdp\r\nContent-Length: 179\r\n\r\nv=0\r\no=- 3827 3827 IN IP4 71.198.132.91\r\ns=voxeo\r\nc=IN IP4 71.198.132.91\r\nt=0 0\r\nm=audio 20040 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:42.063 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/recognizer/ RTSP/1.0\r\nCseq: 3\r\nTransport: RTP/AVP;unicast;\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nContent-Type: application/sdp\r\nContent-Length: 241\r\n\r\nv=0\r\no=- 3521575421 3521575422 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47136 RTP/AVP 0 101\r\na=rtcp:50013\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:42.074 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nTransport: RTP/AVP;unicast;client_port=47136-47137;server_port=20040-20041\r\nCseq: 3\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:42.074 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-21, nc1] updates the ASR session. #[2621592952-2239e00-0ac44840-00000015]
2011-08-05 16:23:42.074 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/synthesizer/ RTSP/1.0\r\nCseq: 4\r\nTransport: RTP/AVP;unicast;\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:42.084 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nTransport: RTP/AVP;unicast;client_port=47136-47137;server_port=20040-20041\r\nCseq: 4\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:42.084 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-21, nc1] updates the TTS session. #[2621592952-2239e00-0ac44840-00000015]
2011-08-05 16:23:42.085 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-05 16:23:42.085 DEBUG [msctrl/2-t-25] #MSCTRL#: SdpPort[SDP_NEGOTIATED, NC[ms2-21, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATED]
2011-08-05 16:23:42.085 DEBUG [msctrl/2-t-25] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATED, NC[ms2-21, nc1]], ANSWER_PROCESSED, 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 20040 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-05 16:23:42.086 INFO [MOHO-42] #MSCTRL#: NC[ms2-21, nc1] joins to NC[ms2-20, nc1] in DUPLEX
2011-08-05 16:23:42.091 DEBUG [MOHO-42] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 5\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nContent-Type: application/mrcp\r\nContent-Length: 202\r\n\r\nVOXEO-JOIN 53000 MRCP/1.0\r\nVendor-Specific-Parameters: Voxeo-Join-DTMF-Passthrough=true;Voxeo-Join-Listen-Only=false;Voxeo-Join-Talk-Only=false\r\nX-Voxeo-Join-ID: 2621581164-2e2ac00-0ac44840-00000014\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:42.110 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nCseq: 5\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 53000 200 IN-PROGRESS\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:42.111 DEBUG [MOHO-42] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 5\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nContent-Type: application/mrcp\r\nContent-Length: 202\r\n\r\nVOXEO-JOIN 63000 MRCP/1.0\r\nVendor-Specific-Parameters: Voxeo-Join-DTMF-Passthrough=true;Voxeo-Join-Listen-Only=false;Voxeo-Join-Talk-Only=false\r\nX-Voxeo-Join-ID: 2621592952-2239e00-0ac44840-00000015\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:42.122 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nCseq: 5\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 63000 200 IN-PROGRESS\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:42.123 DEBUG [MOHO-42] #MSCTRL#: NC[ms2-21, nc1] adds(NC[ms2-20, nc1], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-08-05 16:23:42.124 DEBUG [MOHO-42] #MSCTRL#: NC[ms2-20, nc1] adds(NC[ms2-21, nc1], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-08-05 16:23:42.124 INFO [pool-16-thread-22] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:42.124 INFO [pool-16-thread-22] Queued Event [JoinedEvent[callId=a3f75438-9c74-4b66-9c51-7b9e8033768e,to=02feb2bb-96f6-4d9b-9e0e-0c6e10136fe2,type=CALL]]
2011-08-05 16:23:42.125 INFO [pool-16-thread-22] Event [JoinedEvent[callId=a3f75438-9c74-4b66-9c51-7b9e8033768e,to=02feb2bb-96f6-4d9b-9e0e-0c6e10136fe2,type=CALL]]
2011-08-05 16:23:42.124 INFO [pool-16-thread-20] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:42.125 DEBUG [pool-16-thread-22] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><joined xmlns="urn:xmpp:rayo:1" call-id="02feb2bb-96f6-4d9b-9e0e-0c6e10136fe2"/></presence> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:42.125 DEBUG [pool-16-thread-22] #XMPP#: Send message to: 127.0.0.1:57613 by xmpp #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:43.070 DEBUG [SocketAcceptorIoProcessor-0.0] #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="a3f75438-9c74-4b66-9c51-7b9e8033768e"/>\n </dial>\n</iq> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:43.071 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo
2011-08-05 16:23:43.071 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][null]
2011-08-05 16:23:43.071 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="a3f75438-9c74-4b66-9c51-7b9e8033768e"/>
</dial>
</iq> :: xmpps_8dpz25pvdd4y
2011-08-05 16:23:43.072 INFO [pool-16-thread-22] Request [DialCommand[from=sip:[email protected],to=sip:[email protected],headers={},join=JoinCommand[callId=<null>,direction=DUPLEX,media=BRIDGE,to=a3f75438-9c74-4b66-9c51-7b9e8033768e,type=CALL]]]
2011-08-05 16:23:43.075 INFO [pool-16-thread-22] Reply [com.tropo.core.CallRef@11a22b6]
2011-08-05 16:23:43.075 INFO [pool-16-thread-21] Message [SIPCallImpl[null,INITIALIZED]]
2011-08-05 16:23:43.075 DEBUG [pool-16-thread-22] #XMPP#: (o)<iq type="result" id="blather000c" from="[email protected]" to="[email protected]/voxeo"><ref xmlns="urn:xmpp:rayo:1" id="12161cc9-7069-4cbb-acad-0a489e1c94f2"/></iq> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:43.075 DEBUG [pool-16-thread-22] #XMPP#: Send message to: 127.0.0.1:57613 by xmpp #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:43.079 INFO [MOHO-48] #MSCTRL#: MS[ms2-22] creates a MediaObject[BASIC, nc1, null]
2011-08-05 16:23:43.079 INFO [MOHO-48] #MSCTRL#: SdpPort[IDLE, NC[ms2-22, nc1]] generates a SDP offer
2011-08-05 16:23:43.079 DEBUG [MOHO-48] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-22, nc1]] moves state from [IDLE] to [UNDER_PROCESSING]
2011-08-05 16:23:43.079 DEBUG [msctrl/2-t-25] #MRCP#: load configuration from {maxThreadPool=2147483647, minThreadPool=25, MEDIAOBJECT_ID=nc1, com.voxeo.useLocalConfigurationOnGUTFailures=false}
2011-08-05 16:23:43.081 DEBUG [msctrl/2-t-25] #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:57620]
2011-08-05 16:23:43.092 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621597800-832d000-0ac44840-00000016\r\nTransport: RTP/AVP;unicast;client_port=65535-65536;server_port=20042-20043\r\nCseq: 1\r\nContent-Type: application/sdp\r\nContent-Length: 419\r\n\r\nv=0\r\no=- 2 2 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20042 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:57620]
2011-08-05 16:23:43.092 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-22, nc1] initializes the ASR session. #[2621597800-832d000-0ac44840-00000016]
2011-08-05 16:23:43.092 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-05 16:23:43.092 DEBUG [msctrl/2-t-25] #MSCTRL#: SdpPort[SDP_NEGOTIATING, NC[ms2-22, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATING]
2011-08-05 16:23:43.092 DEBUG [msctrl/2-t-25] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATING, NC[ms2-22, nc1]], OFFER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 2 2 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20042 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-05 16:23:43.093 DEBUG [msctrl/2-t-25] #SIP#: Session creating: ss_1add0j0wtfe2b #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:43.093 DEBUG [msctrl/2-t-25] #SIP#: SetRoutingDirective: NEW #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:43.094 DEBUG [msctrl/2-t-25] #SIP#: SessionManagementLayer send request: INVITE sip:[email protected] #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:43.165 DEBUG [msctrl/2-t-25] #SIP#: The transaction was created: z9hG4bKkp71olh3ygff #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:43.165 DEBUG [msctrl/2-t-25] #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=z9hG4bKkp71olh3ygff\r\nCSeq: 1 INVITE\r\nContent-Length: 419\r\nCall-ID: 5iu54ayeo9r0\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=1hrbbrcosh4lq\r\nContact: <sip:192.168.0.196:5060;transport=tcp>\r\n\r\nv=0\r\no=- 2 2 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20042 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-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:43.203 DEBUG [msctrl/2-t-25] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:43.204 DEBUG [msctrl/2-t-25] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:43.431 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 100 trying -- your call is important to us\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bKkp71olh3ygff;rport=57243;received=71.198.132.91\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 5iu54ayeo9r0\r\nServer: ser (3.2.0-dev2 (i386/linux))\r\nFrom: <sip:[email protected]>;tag=1hrbbrcosh4lq\r\nWarning: 392 213.192.59.75:5060 "Noisy feedback tells: pid=19077 req_src_ip=71.198.132.91 req_src_port=57243 in_uri=sip:[email protected] out_uri=sip:[email protected]:55497;transport=tcp via_cnt==1"\r\n\r\n] #[N/A][N/A][5iu54ayeo9r0][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:43.432 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 100/INVITE, branch=z9hG4bKkp71olh3ygff #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:43.432 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/100 #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:43.432 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-sm7ci2crpb3df5tropo2], invalidateWhenReady: true
2011-08-05 16:23:43.433 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1add0j0wtfe2b], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:43.433 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-14-sm7ci2crpb3df5tropo2], invalidateWhenReady: true
2011-08-05 16:23:43.891 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 180 Ringing\r\nTo: <sip:[email protected]>;tag=x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bKkp71olh3ygff\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=1hrbbrcosh4lq;avp=nKEDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2U>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 5iu54ayeo9r0\r\nServer: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=1hrbbrcosh4lq\r\nContact: <sip:[email protected]:55062;transport=tcp>\r\n\r\n] #[N/A][N/A][5iu54ayeo9r0][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:43.892 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 180/INVITE, branch=z9hG4bKkp71olh3ygff #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:43.892 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/180 #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:43.893 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Add Path[ id=5iu54ayeo9r0-x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N-1hrbbrcosh4lq, session=SipSessionImpl[_id=ss_1add0j0wtfe2b, _parentId=sas_2-14-sm7ci2crpb3df5tropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=5iu54ayeo9r0], party= CALLEE] #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:43.893 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:43.893 DEBUG [tcp/0.0.0.0/5060-t-12] [SIP/2.0 180 Ringing
To: <sip:[email protected]>;tag=x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N
Via: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bKkp71olh3ygff
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Record-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=1hrbbrcosh4lq;avp=nKEDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2U>
CSeq: 1 INVITE
Content-Length: 0
Call-ID: 5iu54ayeo9r0
Server: Blink Pro 1.1.1 (MacOSX)
From: <sip:[email protected]>;tag=1hrbbrcosh4lq
Contact: <sip:[email protected]:55062;transport=tcp>
]
2011-08-05 16:23:43.893 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-sm7ci2crpb3df5tropo2], invalidateWhenReady: true
2011-08-05 16:23:43.893 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1add0j0wtfe2b], current State = EARLY, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:43.894 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-14-sm7ci2crpb3df5tropo2], invalidateWhenReady: true
2011-08-05 16:23:43.895 INFO [pool-16-thread-21] Message [[Event class=com.voxeo.moho.sip.SIPRingEventImpl sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:43.895 INFO [pool-16-thread-21] Queued Event [RingingEvent[callId=12161cc9-7069-4cbb-acad-0a489e1c94f2]]
2011-08-05 16:23:43.895 INFO [pool-16-thread-21] Event [RingingEvent[callId=12161cc9-7069-4cbb-acad-0a489e1c94f2]]
2011-08-05 16:23:43.896 DEBUG [pool-16-thread-21] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><ringing xmlns="urn:xmpp:rayo:1"/></presence> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:43.896 DEBUG [pool-16-thread-21] #XMPP#: Send message to: 127.0.0.1:57613 by xmpp #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:45.512 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[INVITE sip:71.198.132.91:57243;transport=tcp SIP/2.0\r\nTo: <sip:[email protected]>;tag=140n6qwfq93n9\r\nContent-Type: application/sdp\r\nX-RTP-Proxy: YES\r\nVia: SIP/2.0/TCP 213.192.59.75;branch=z9hG4bK3175.0fd090e3.0;i=31a\r\nVia: SIP/2.0/tcp 192.168.0.196:55062;received=71.198.132.91;rport=55062;branch=z9hG4bKPjMen1rBSfFZP1UomrdOq3raeGQduToh.S\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;ftag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC;avp=2e8DCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2QTCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2QTBgBzdGltZXIEADE4MDATBwBhY2NvdW50AwB5ZXM;lr=on>\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nCall-ID: 1tdftnbhe6y2f\r\nUser-Agent: Blink Pro 1.1.1 (MacOSX)\r\nMax-Forwards: 16\r\nFrom: <sip:[email protected]>;tag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC\r\nContact: <sip:[email protected]:55062;transport=tcp>\r\nCSeq: 19520 INVITE\r\nContent-Length: 241\r\nSupported: 100rel, norefersub\r\nP-hint: rr-enforced\r\n\r\nv=0\r\no=- 3521575421 3521575423 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47136 RTP/AVP 0 101\r\na=rtcp:50013\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendonly\r\n] #[N/A][N/A][1tdftnbhe6y2f][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.513 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: The transaction was created: z9hG4bK3175.0fd090e3.0 #[N/A][N/A][1tdftnbhe6y2f][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.514 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (o)[SIP/2.0 100 Trying\r\nTo: <sip:[email protected]>;tag=140n6qwfq93n9\r\nVia: SIP/2.0/TCP 213.192.59.75;branch=z9hG4bK3175.0fd090e3.0;i=31a\r\nVia: SIP/2.0/tcp 192.168.0.196:55062;received=71.198.132.91;rport=55062;branch=z9hG4bKPjMen1rBSfFZP1UomrdOq3raeGQduToh.S\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;ftag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC;avp=2e8DCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2QTCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2QTBgBzdGltZXIEADE4MDATBwBhY2NvdW50AwB5ZXM;lr=on>\r\nCSeq: 19520 INVITE\r\nContent-Length: 0\r\nCall-ID: 1tdftnbhe6y2f\r\nFrom: <sip:[email protected]>;tag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC\r\n\r\n] #[N/A][N/A][1tdftnbhe6y2f][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.514 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Find Connector: tcp:sip.iptel.org/213.192.59.75, 5060 #[N/A][N/A][1tdftnbhe6y2f][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.514 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[N/A][N/A][1tdftnbhe6y2f][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.519 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Find Path[ id=1tdftnbhe6y2f-ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC-140n6qwfq93n9, path=ApplicationPath[_id=1tdftnbhe6y2f-ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC-140n6qwfq93n9, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_1azav1yg51u62, appSessionId=sas_2-15-sm10va9ksndqzfitropo2]]]]]] #[N/A][N/A][1tdftnbhe6y2f][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.519 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv request: INVITE #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.520 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ApplicationDispatchLayer invoke application: Controller with INVITE #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.521 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.529 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:45.529 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1azav1yg51u62], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:45.530 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:45.530 INFO [pool-16-thread-21] Message [[Event class=com.voxeo.moho.sip.SIPReInviteEventImpl sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:45.531 INFO [MOHO-47] #MSCTRL#: SdpPort[SDP_NEGOTIATED, NC[ms2-21, nc1]] processes a SDP offer \nv=0\r\no=- 3521575421 3521575423 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47136 RTP/AVP 0 101\r\na=rtcp:50013\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendonly\r\n
2011-08-05 16:23:45.532 DEBUG [MOHO-47] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-21, nc1]] moves state from [SDP_NEGOTIATED] to [UNDER_PROCESSING]
2011-08-05 16:23:45.532 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-05 16:23:45.533 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 6\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nContent-Type: application/sdp\r\nContent-Length: 241\r\n\r\nv=0\r\no=- 3521575421 3521575423 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47136 RTP/AVP 0 101\r\na=rtcp:50013\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendonly\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:45.541 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nCseq: 6\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:45.541 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/recognizer/ RTSP/1.0\r\nCseq: 7\r\nTransport: RTP/AVP;unicast;\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nContent-Type: application/sdp\r\nContent-Length: 241\r\n\r\nv=0\r\no=- 3521575421 3521575423 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47136 RTP/AVP 0 101\r\na=rtcp:50013\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendonly\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:45.551 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nCseq: 7\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:45.552 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/synthesizer/ RTSP/1.0\r\nCseq: 8\r\nTransport: RTP/AVP;unicast;\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:45.562 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nCseq: 8\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:45.562 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-21, nc1] updates the ASR session. #[2621592952-2239e00-0ac44840-00000015]
2011-08-05 16:23:45.562 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-21, nc1] updates the TTS session. #[2621592952-2239e00-0ac44840-00000015]
2011-08-05 16:23:45.563 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-05 16:23:45.563 DEBUG [msctrl/2-t-25] #MSCTRL#: SdpPort[SDP_NEGOTIATED, NC[ms2-21, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATED]
2011-08-05 16:23:45.563 DEBUG [msctrl/2-t-25] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATED, NC[ms2-21, nc1]], ANSWER_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 20040 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-05 16:23:45.572 DEBUG [msctrl/2-t-25] #SIP#: SessionManagementLayer send response: INVITE/200 #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.574 DEBUG [msctrl/2-t-25] #SIP#: Add Path[ id=1tdftnbhe6y2f-ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC-140n6qwfq93n9, session=SipSessionImpl[_id=ss_1azav1yg51u62, _parentId=sas_2-15-sm10va9ksndqzfitropo2, _handler=Controller, _state=CONFIRMED, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=1tdftnbhe6y2f], party= CALLER] #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:45.575 DEBUG [msctrl/2-t-25] #SIP#: (o)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=140n6qwfq93n9\r\nVia: SIP/2.0/TCP 213.192.59.75;branch=z9hG4bK3175.0fd090e3.0;i=31a\r\nVia: SIP/2.0/tcp 192.168.0.196:55062;received=71.198.132.91;rport=55062;branch=z9hG4bKPjMen1rBSfFZP1UomrdOq3raeGQduToh.S\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;ftag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC;avp=2e8DCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2QTCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2QTBgBzdGltZXIEADE4MDATBwBhY2NvdW50AwB5ZXM;lr=on>\r\nCSeq: 19520 INVITE\r\nContent-Length: 433\r\nCall-ID: 1tdftnbhe6y2f\r\nFrom: <sip:[email protected]>;tag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC\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 20040 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\na=recvonly\r\n] #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.575 DEBUG [msctrl/2-t-25] #SIP#: Find Connector: tcp:sip.iptel.org/213.192.59.75, 5060 #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.575 DEBUG [msctrl/2-t-25] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.576 DEBUG [msctrl/2-t-25] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:45.576 DEBUG [msctrl/2-t-25] #SIP#: processInvalidationWhenReady [ss_1azav1yg51u62], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:45.576 DEBUG [msctrl/2-t-25] #SIP#: processInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:45.740 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bKkp71olh3ygff\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=1hrbbrcosh4lq;avp=nKEDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2U>\r\nCSeq: 1 INVITE\r\nContent-Length: 241\r\nSupported: 100rel, norefersub\r\nCall-ID: 5iu54ayeo9r0\r\nServer: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=1hrbbrcosh4lq\r\nContact: <sip:[email protected]:55062;transport=tcp>\r\n\r\nv=0\r\no=- 3521575425 3521575426 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47144 RTP/AVP 0 101\r\na=rtcp:50015\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n] #[N/A][N/A][5iu54ayeo9r0][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.741 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 200/INVITE, branch=z9hG4bKkp71olh3ygff #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:45.741 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/200 #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:45.742 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:45.742 DEBUG [tcp/0.0.0.0/5060-t-12] [SIP/2.0 200 OK
Content-Type: application/sdp
To: <sip:[email protected]>;tag=x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N
Via: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bKkp71olh3ygff
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Record-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=1hrbbrcosh4lq;avp=nKEDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2U>
CSeq: 1 INVITE
Content-Length: 241
Supported: 100rel, norefersub
Call-ID: 5iu54ayeo9r0
Server: Blink Pro 1.1.1 (MacOSX)
From: <sip:[email protected]>;tag=1hrbbrcosh4lq
Contact: <sip:[email protected]:55062;transport=tcp>
v=0
o=- 3521575425 3521575426 IN IP4 192.168.0.196
s=Blink Pro 1.1.1 (MacOSX)
c=IN IP4 213.192.59.91
t=0 0
m=audio 47144 RTP/AVP 0 101
a=rtcp:50015
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
]
2011-08-05 16:23:45.743 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer send request: ACK sip:[email protected]:55062;transport=tcp #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:45.743 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (o)[ACK sip:[email protected]:55062;transport=tcp SIP/2.0\r\nTo: <sip:[email protected]>;tag=x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bKx1e2zaj56g7;x-sm-sid=7d66feb5-ce8b-4dcd-98b8-3614b7151a47;x-sm-nid=ss_1add0j0wtfe2b\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nRoute: <sip:213.192.59.75;transport=tcp;lr;ftag=1hrbbrcosh4lq;avp=nKEDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2U>\r\nCall-ID: 5iu54ayeo9r0\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=1hrbbrcosh4lq\r\n\r\n] #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:45.744 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Send message to: /213.192.59.75:5060 by tcp #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:45.744 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:45.744 INFO [tcp/0.0.0.0/5060-t-12] #MSCTRL#: SdpPort[SDP_NEGOTIATING, NC[ms2-22, nc1]] processes a SDP answer \nv=0\r\no=- 3521575425 3521575426 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47144 RTP/AVP 0 101\r\na=rtcp:50015\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n
2011-08-05 16:23:45.745 DEBUG [tcp/0.0.0.0/5060-t-12] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-22, nc1]] moves state from [SDP_NEGOTIATING] to [UNDER_PROCESSING]
2011-08-05 16:23:45.745 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-05 16:23:45.746 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 2\r\nSession: 2621597800-832d000-0ac44840-00000016\r\nContent-Type: application/sdp\r\nContent-Length: 241\r\n\r\nv=0\r\no=- 3521575425 3521575426 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47144 RTP/AVP 0 101\r\na=rtcp:50015\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n #[2621597800-832d000-0ac44840-00000016][192.168.0.196:10074][192.168.0.196:57620]
2011-08-05 16:23:45.746 INFO [pool-16-thread-21] Message [[Event class=com.voxeo.moho.sip.SIPAnsweredEventImpl sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:45.746 INFO [pool-16-thread-21] Queued Event [AnsweredEvent[callId=12161cc9-7069-4cbb-acad-0a489e1c94f2]]
2011-08-05 16:23:45.746 INFO [pool-16-thread-21] Event [AnsweredEvent[callId=12161cc9-7069-4cbb-acad-0a489e1c94f2]]
2011-08-05 16:23:45.746 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-sm7ci2crpb3df5tropo2], invalidateWhenReady: true
2011-08-05 16:23:45.746 DEBUG [pool-16-thread-21] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><answered xmlns="urn:xmpp:rayo:1"/></presence> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:45.747 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1add0j0wtfe2b], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:45.747 DEBUG [pool-16-thread-21] #XMPP#: Send message to: 127.0.0.1:57613 by xmpp #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:45.747 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-14-sm7ci2crpb3df5tropo2], invalidateWhenReady: true
2011-08-05 16:23:45.749 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621597800-832d000-0ac44840-00000016\r\nCseq: 2\r\nContent-Type: application/sdp\r\nContent-Length: 179\r\n\r\nv=0\r\no=- 2668 2668 IN IP4 71.198.132.91\r\ns=voxeo\r\nc=IN IP4 71.198.132.91\r\nt=0 0\r\nm=audio 20042 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n #[2621597800-832d000-0ac44840-00000016][192.168.0.196:10074][192.168.0.196:57620]
2011-08-05 16:23:45.750 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/recognizer/ RTSP/1.0\r\nCseq: 3\r\nTransport: RTP/AVP;unicast;\r\nSession: 2621597800-832d000-0ac44840-00000016\r\nContent-Type: application/sdp\r\nContent-Length: 241\r\n\r\nv=0\r\no=- 3521575425 3521575426 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47144 RTP/AVP 0 101\r\na=rtcp:50015\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n #[2621597800-832d000-0ac44840-00000016][192.168.0.196:10074][192.168.0.196:57620]
2011-08-05 16:23:45.762 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621597800-832d000-0ac44840-00000016\r\nTransport: RTP/AVP;unicast;client_port=47144-47145;server_port=20042-20043\r\nCseq: 3\r\n\r\n #[2621597800-832d000-0ac44840-00000016][192.168.0.196:10074][192.168.0.196:57620]
2011-08-05 16:23:45.762 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-22, nc1] updates the ASR session. #[2621597800-832d000-0ac44840-00000016]
2011-08-05 16:23:45.763 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/synthesizer/ RTSP/1.0\r\nCseq: 4\r\nTransport: RTP/AVP;unicast;\r\nSession: 2621597800-832d000-0ac44840-00000016\r\n\r\n #[2621597800-832d000-0ac44840-00000016][192.168.0.196:10074][192.168.0.196:57620]
2011-08-05 16:23:45.772 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621597800-832d000-0ac44840-00000016\r\nTransport: RTP/AVP;unicast;client_port=47144-47145;server_port=20042-20043\r\nCseq: 4\r\n\r\n #[2621597800-832d000-0ac44840-00000016][192.168.0.196:10074][192.168.0.196:57620]
2011-08-05 16:23:45.773 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-22, nc1] updates the TTS session. #[2621597800-832d000-0ac44840-00000016]
2011-08-05 16:23:45.774 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-05 16:23:45.774 DEBUG [msctrl/2-t-25] #MSCTRL#: SdpPort[SDP_NEGOTIATED, NC[ms2-22, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATED]
2011-08-05 16:23:45.774 DEBUG [msctrl/2-t-25] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATED, NC[ms2-22, nc1]], ANSWER_PROCESSED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 2 2 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20042 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-05 16:23:45.774 INFO [MOHO-48] #MSCTRL#: NC[ms2-22, nc1] joins to NC[ms2-20, nc1] in DUPLEX
2011-08-05 16:23:45.775 DEBUG [MOHO-48] #MSCTRL#: NC[ms2-20, nc1] rejoins to NC[ms2-21, nc1] in SEND
2011-08-05 16:23:45.775 INFO [MOHO-48] #MSCTRL#: NC[ms2-20, nc1] unjoins from NC[ms2-21, nc1]
2011-08-05 16:23:45.777 DEBUG [MOHO-48] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 9\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:45.785 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nCseq: 9\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:45.786 DEBUG [MOHO-48] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 6\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:45.809 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nCseq: 6\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:45.810 DEBUG [MOHO-48] #MSCTRL#: NC[ms2-20, nc1] removes(NC[ms2-21, nc1], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-08-05 16:23:45.810 DEBUG [MOHO-48] #MSCTRL#: NC[ms2-21, nc1] removes(NC[ms2-20, nc1], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-08-05 16:23:45.810 INFO [MOHO-48] #MSCTRL#: NC[ms2-20, nc1] joins to NC[ms2-21, nc1] in SEND
2011-08-05 16:23:45.810 DEBUG [MOHO-48] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 7\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:45.822 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nTransport: RTP/AVP;unicast;client_port=47128-47129;server_port=20038-20039\r\nCseq: 7\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:45.822 DEBUG [MOHO-48] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 8\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nContent-Type: application/mrcp\r\nContent-Length: 201\r\n\r\nVOXEO-JOIN 63001 MRCP/1.0\r\nVendor-Specific-Parameters: Voxeo-Join-DTMF-Passthrough=true;Voxeo-Join-Listen-Only=false;Voxeo-Join-Talk-Only=true\r\nX-Voxeo-Join-ID: 2621592952-2239e00-0ac44840-00000015\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:45.842 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nCseq: 8\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 63001 200 IN-PROGRESS\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:45.843 DEBUG [MOHO-48] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 10\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:45.852 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nTransport: RTP/AVP;unicast;client_port=47136-47137;server_port=20040-20041\r\nCseq: 10\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:45.853 DEBUG [MOHO-48] #MRCP#: (o)ANNOUNCE rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 11\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nContent-Type: application/mrcp\r\nContent-Length: 202\r\n\r\nVOXEO-JOIN 53001 MRCP/1.0\r\nVendor-Specific-Parameters: Voxeo-Join-DTMF-Passthrough=true;Voxeo-Join-Listen-Only=false;Voxeo-Join-Talk-Only=false\r\nX-Voxeo-Join-ID: 2621581164-2e2ac00-0ac44840-00000014\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:45.863 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nCseq: 11\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 53001 200 IN-PROGRESS\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:45.864 DEBUG [MOHO-48] #MSCTRL#: NC[ms2-20, nc1] adds(NC[ms2-21, nc1], JoineeContext[RESOURCE_CONTAINER, SEND, null])
2011-08-05 16:23:45.864 DEBUG [MOHO-48] #MSCTRL#: NC[ms2-21, nc1] adds(NC[ms2-20, nc1], JoineeContext[RESOURCE_CONTAINER, RECV, null])
2011-08-05 16:23:45.864 DEBUG [MOHO-48] #MSCTRL#: NC[ms2-22, nc1] adds(NC[ms2-20, nc1], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-08-05 16:23:45.864 DEBUG [MOHO-48] #MSCTRL#: NC[ms2-20, nc1] adds(NC[ms2-22, nc1], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-08-05 16:23:45.865 INFO [pool-16-thread-21] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:45.865 INFO [pool-16-thread-22] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:45.865 INFO [pool-16-thread-22] Queued Event [JoinedEvent[callId=a3f75438-9c74-4b66-9c51-7b9e8033768e,to=12161cc9-7069-4cbb-acad-0a489e1c94f2,type=CALL]]
2011-08-05 16:23:45.865 INFO [pool-16-thread-22] Event [JoinedEvent[callId=a3f75438-9c74-4b66-9c51-7b9e8033768e,to=12161cc9-7069-4cbb-acad-0a489e1c94f2,type=CALL]]
2011-08-05 16:23:45.866 DEBUG [pool-16-thread-22] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><joined xmlns="urn:xmpp:rayo:1" call-id="12161cc9-7069-4cbb-acad-0a489e1c94f2"/></presence> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:45.866 DEBUG [pool-16-thread-22] #XMPP#: Send message to: 127.0.0.1:57613 by xmpp #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:46.032 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[ACK sip:71.198.132.91:57243;transport=tcp SIP/2.0\r\nTo: <sip:[email protected]>;tag=140n6qwfq93n9\r\nVia: SIP/2.0/TCP 213.192.59.75;branch=0;i=31a\r\nVia: SIP/2.0/tcp 192.168.0.196:55062;received=71.198.132.91;rport=55062;branch=z9hG4bKPjqbeo87pz0yoM4j2jy-UJkmBcTSIGAMnB\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;ftag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC;avp=2e8DCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2QTCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2QTBgBzdGltZXIEADE4MDATBwBhY2NvdW50AwB5ZXM;lr=on>\r\nCSeq: 19520 ACK\r\nContent-Length: 0\r\nCall-ID: 1tdftnbhe6y2f\r\nP-hint: rr-enforced\r\nUser-Agent: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC\r\nMax-Forwards: 16\r\n\r\n] #[N/A][N/A][1tdftnbhe6y2f][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:46.042 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Find Path[ id=1tdftnbhe6y2f-ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC-140n6qwfq93n9, path=ApplicationPath[_id=1tdftnbhe6y2f-ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC-140n6qwfq93n9, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_1azav1yg51u62, appSessionId=sas_2-15-sm10va9ksndqzfitropo2]]]]]] #[N/A][N/A][1tdftnbhe6y2f][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:46.042 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv request: ACK #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:46.043 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ApplicationDispatchLayer invoke application: Controller with ACK #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:46.043 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:46.043 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:46.043 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1azav1yg51u62], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.045 INFO [MOHO-47] #MSCTRL#: NC[ms2-20, nc1] unjoins from NC[ms2-21, nc1]
2011-08-05 16:23:46.045 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:46.046 DEBUG [MOHO-47] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 12\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:46.054 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nCseq: 12\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:46.055 DEBUG [MOHO-47] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 9\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:46.076 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nCseq: 9\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:46.076 DEBUG [MOHO-47] #MSCTRL#: NC[ms2-20, nc1] removes(NC[ms2-21, nc1], JoineeContext[RESOURCE_CONTAINER, SEND, null])
2011-08-05 16:23:46.077 DEBUG [MOHO-47] #MSCTRL#: NC[ms2-21, nc1] removes(NC[ms2-20, nc1], JoineeContext[RESOURCE_CONTAINER, RECV, null])
2011-08-05 16:23:46.078 INFO [MOHO-47] #MSCTRL#: SdpPort[SDP_NEGOTIATED, NC[ms2-20, nc1]] processes a SDP offer \nv=0\r\no=- 3521575406 3521575407 IN IP4 71.198.132.91\r\ns=pjmedia\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\na=X-nat:0\r\nm=audio 47128 RTP/AVP 0 101\r\na=rtcp:4009 IN IP4 192.168.0.196\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=recvonly\r\n
2011-08-05 16:23:46.078 DEBUG [MOHO-47] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-20, nc1]] moves state from [SDP_NEGOTIATED] to [UNDER_PROCESSING]
2011-08-05 16:23:46.078 DEBUG [MOHO-47] Set mg id with call id :1a6v6j5xq79fx
2011-08-05 16:23:46.079 INFO [MOHO-47] #MSCTRL#: MS[MG-1a6v6j5xq79fx] updates MEDIAOBJECT_ID, old:"ms2-20", new:"MG-1a6v6j5xq79fx"
2011-08-05 16:23:46.080 INFO [MOHO-47] #MSCTRL#: MS[MG-1a6v6j5xq79fx] creates a MediaObject[PLAYER_RECORDER_SIGNALDETECTOR, MG-1a6v6j5xq79fx, {MEDIAOBJECT_ID=MG-1a6v6j5xq79fx}]
2011-08-05 16:23:46.081 INFO [MOHO-47] #MSCTRL#: MG[MG-1a6v6j5xq79fx, MG-1a6v6j5xq79fx] joins to NC[MG-1a6v6j5xq79fx, nc1] in RECV
2011-08-05 16:23:46.081 DEBUG [MOHO-47] #MSCTRL#: MG[MG-1a6v6j5xq79fx, MG-1a6v6j5xq79fx] adds JoineeMrcpContext[mscontrol://192.168.0.196:10074/MG-1a6v6j5xq79fx/nc1, 2621581164-2e2ac00-0ac44840-00000014, 2621581164-2e2ac00-0ac44840-00000014] #[2621581164-2e2ac00-0ac44840-00000014]
2011-08-05 16:23:46.082 DEBUG [MOHO-47] #MSCTRL#: NC[MG-1a6v6j5xq79fx, nc1] adds(MG[MG-1a6v6j5xq79fx, MG-1a6v6j5xq79fx], JoineeContext[RESOURCE_CONTAINER, SEND, null])
2011-08-05 16:23:46.082 DEBUG [MOHO-47] #MSCTRL#: MG[MG-1a6v6j5xq79fx, MG-1a6v6j5xq79fx] adds(NC[MG-1a6v6j5xq79fx, nc1], JoineeContext[RESOURCE_CONTAINER, RECV, null])
2011-08-05 16:23:46.083 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-05 16:23:46.083 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/recognizer/ RTSP/1.0\r\nCseq: 10\r\nTransport: RTP/AVP;unicast;\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nContent-Type: application/sdp\r\nContent-Length: 255\r\n\r\nv=0\r\no=- 3521575406 3521575407 IN IP4 71.198.132.91\r\ns=pjmedia\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\na=X-nat:0\r\nm=audio 47128 RTP/AVP 0 101\r\na=rtcp:4009 IN IP4 192.168.0.196\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=recvonly\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:46.094 DEBUG [MOHO-47] #SIP#: SessionManagementLayer send request: INVITE sip:[email protected]:65454;ob #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:46.096 DEBUG [MOHO-47] #SIP#: The transaction was created: z9hG4bKxumb5fs5jrf #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.097 DEBUG [MOHO-47] #SIP#: (o)[INVITE sip:[email protected]:65454;ob SIP/2.0\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=CWqPjRKlk3hXdx.NkP4qK327UF-UL.dm\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bKxumb5fs5jrf;x-sm-sid=7d66feb5-ce8b-4dcd-98b8-3614b7151a47;x-sm-nid=ss_1jio6cycv775\r\nCSeq: 2 INVITE\r\nContent-Length: 433\r\nRoute: <sip:213.192.59.75;transport=tcp;lr;r2=on;ftag=1mvlufxv458ml;avp=9xcDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODItNGUzYjA5NGQtZGQxYjkyMDU>\r\nRoute: <sip:213.192.59.75;lr;r2=on;ftag=1mvlufxv458ml;avp=9xcDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODItNGUzYjA5NGQtZGQxYjkyMDU>\r\nCall-ID: 1a6v6j5xq79fx\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=1mvlufxv458ml\r\nContact: <sip:192.168.0.196:5060;transport=tcp>\r\n\r\nv=0\r\no=- 13 13 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20038 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\na=sendonly\r\n] #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.097 DEBUG [MOHO-47] #SIP#: Send message to: /213.192.59.75:5060 by tcp #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.097 DEBUG [MOHO-47] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.099 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nCseq: 10\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:46.099 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://192.168.0.196:10074/synthesizer/ RTSP/1.0\r\nCseq: 11\r\nTransport: RTP/AVP;unicast;\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:46.109 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nCseq: 11\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:46.110 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[MG-1a6v6j5xq79fx, nc1] updates the ASR session. #[2621581164-2e2ac00-0ac44840-00000014]
2011-08-05 16:23:46.110 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[MG-1a6v6j5xq79fx, nc1] updates the TTS session. #[2621581164-2e2ac00-0ac44840-00000014]
2011-08-05 16:23:46.111 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-05 16:23:46.111 DEBUG [msctrl/2-t-25] #MSCTRL#: SdpPort[SDP_NEGOTIATED, NC[MG-1a6v6j5xq79fx, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATED]
2011-08-05 16:23:46.111 DEBUG [msctrl/2-t-25] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATED, NC[MG-1a6v6j5xq79fx, nc1]], ANSWER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 13 13 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20038 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-05 16:23:46.195 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bKkp71olh3ygff\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=1hrbbrcosh4lq;avp=nKEDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2U>\r\nCSeq: 1 INVITE\r\nContent-Length: 241\r\nSupported: 100rel, norefersub\r\nCall-ID: 5iu54ayeo9r0\r\nServer: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=1hrbbrcosh4lq\r\nContact: <sip:[email protected]:55062;transport=tcp>\r\n\r\nv=0\r\no=- 3521575425 3521575426 IN IP4 192.168.0.196\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 47144 RTP/AVP 0 101\r\na=rtcp:50015\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n] #[N/A][N/A][5iu54ayeo9r0][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:46.196 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 200/INVITE, branch=z9hG4bKkp71olh3ygff #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.196 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (o)[ACK sip:[email protected]:55062;transport=tcp SIP/2.0\r\nTo: <sip:[email protected]>;tag=x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bKx1e2zaj56g7;x-sm-sid=7d66feb5-ce8b-4dcd-98b8-3614b7151a47;x-sm-nid=ss_1add0j0wtfe2b\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nRoute: <sip:213.192.59.75;transport=tcp;lr;ftag=1hrbbrcosh4lq;avp=nKEDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2U>\r\nCall-ID: 5iu54ayeo9r0\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=1hrbbrcosh4lq\r\n\r\n] #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.196 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Send message to: /213.192.59.75:5060 by tcp #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.197 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.198 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKkp71olh3ygff] discards the response.
2011-08-05 16:23:46.322 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 100 trying -- your call is important to us\r\nTo: <sip:[email protected]>;tag=CWqPjRKlk3hXdx.NkP4qK327UF-UL.dm\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bKxumb5fs5jrf;x-sm-sid=7d66feb5-ce8b-4dcd-98b8-3614b7151a47;x-sm-nid=ss_1jio6cycv775;rport=57243;received=71.198.132.91\r\nCSeq: 2 INVITE\r\nContent-Length: 0\r\nCall-ID: 1a6v6j5xq79fx\r\nServer: ser (3.2.0-dev2 (i386/linux))\r\nFrom: <sip:[email protected]>;tag=1mvlufxv458ml\r\nWarning: 392 213.192.59.75:5060 "Noisy feedback tells: pid=19077 req_src_ip=71.198.132.91 req_src_port=57243 in_uri=sip:[email protected]:65454;ob out_uri=sip:[email protected]:65454;ob via_cnt==1"\r\n\r\n] #[N/A][N/A][1a6v6j5xq79fx][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:46.323 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 100/INVITE, branch=z9hG4bKxumb5fs5jrf #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.323 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/100 #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.323 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-smoelenhx060gutropo2], invalidateWhenReady: true
2011-08-05 16:23:46.324 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1jio6cycv775], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 2, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.324 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-14-smoelenhx060gutropo2], invalidateWhenReady: true
2011-08-05 16:23:46.547 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=CWqPjRKlk3hXdx.NkP4qK327UF-UL.dm\r\nVia: SIP/2.0/TCP 71.198.132.91:5060;rport=57243;received=71.198.132.91;branch=z9hG4bKxumb5fs5jrf;x-sm-sid=7d66feb5-ce8b-4dcd-98b8-3614b7151a47;x-sm-nid=ss_1jio6cycv775\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;r2=on;ftag=1mvlufxv458ml;avp=9xcDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODItNGUzYjA5NGQtZGQxYjkyMDU>\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;r2=on;ftag=1mvlufxv458ml;avp=9xcDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODItNGUzYjA5NGQtZGQxYjkyMDU>\r\nCSeq: 2 INVITE\r\nContent-Length: 255\r\nSupported: replaces, 100rel, timer, norefersub\r\nCall-ID: 1a6v6j5xq79fx\r\nFrom: <sip:[email protected]>;tag=1mvlufxv458ml\r\nContact: "zhao lu" <sip:[email protected]:65454;ob>\r\nSession-Expires: 1800;refresher=uac\r\n\r\nv=0\r\no=- 3521575406 3521575408 IN IP4 71.198.132.91\r\ns=pjmedia\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\na=X-nat:0\r\nm=audio 47128 RTP/AVP 0 101\r\na=rtcp:4009 IN IP4 192.168.0.196\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=recvonly\r\n] #[N/A][N/A][1a6v6j5xq79fx][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:46.547 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 200/INVITE, branch=z9hG4bKxumb5fs5jrf #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.547 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/200 #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.548 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:46.548 DEBUG [tcp/0.0.0.0/5060-t-12] [SIP/2.0 200 OK
Content-Type: application/sdp
To: <sip:[email protected]>;tag=CWqPjRKlk3hXdx.NkP4qK327UF-UL.dm
Via: SIP/2.0/TCP 71.198.132.91:5060;rport=57243;received=71.198.132.91;branch=z9hG4bKxumb5fs5jrf;x-sm-sid=7d66feb5-ce8b-4dcd-98b8-3614b7151a47;x-sm-nid=ss_1jio6cycv775
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE
Allow: OPTIONS
Record-Route: <sip:213.192.59.75;lr;r2=on;ftag=1mvlufxv458ml;avp=9xcDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODItNGUzYjA5NGQtZGQxYjkyMDU>
Record-Route: <sip:213.192.59.75;transport=tcp;lr;r2=on;ftag=1mvlufxv458ml;avp=9xcDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODItNGUzYjA5NGQtZGQxYjkyMDU>
CSeq: 2 INVITE
Content-Length: 255
Supported: replaces, 100rel, timer, norefersub
Call-ID: 1a6v6j5xq79fx
From: <sip:[email protected]>;tag=1mvlufxv458ml
Contact: "zhao lu" <sip:[email protected]:65454;ob>
Session-Expires: 1800;refresher=uac
v=0
o=- 3521575406 3521575408 IN IP4 71.198.132.91
s=pjmedia
c=IN IP4 213.192.59.91
t=0 0
a=X-nat:0
m=audio 47128 RTP/AVP 0 101
a=rtcp:4009 IN IP4 192.168.0.196
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=recvonly
]
2011-08-05 16:23:46.549 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer send request: ACK sip:[email protected]:65454;ob #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:46.550 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (o)[ACK sip:[email protected]:65454;ob SIP/2.0\r\nTo: <sip:[email protected]>;tag=CWqPjRKlk3hXdx.NkP4qK327UF-UL.dm\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bKwobgdpwwl5bo;x-sm-sid=7d66feb5-ce8b-4dcd-98b8-3614b7151a47;x-sm-nid=ss_1jio6cycv775\r\nCSeq: 2 ACK\r\nContent-Length: 0\r\nRoute: <sip:213.192.59.75;transport=tcp;lr;r2=on;ftag=1mvlufxv458ml;avp=9xcDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODItNGUzYjA5NGQtZGQxYjkyMDU>\r\nRoute: <sip:213.192.59.75;lr;r2=on;ftag=1mvlufxv458ml;avp=9xcDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODItNGUzYjA5NGQtZGQxYjkyMDU>\r\nCall-ID: 1a6v6j5xq79fx\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=1mvlufxv458ml\r\n\r\n] #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.550 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Send message to: /213.192.59.75:5060 by tcp #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.550 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.551 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-smoelenhx060gutropo2], invalidateWhenReady: true
2011-08-05 16:23:46.551 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1jio6cycv775], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 2, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.551 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-14-smoelenhx060gutropo2], invalidateWhenReady: true
2011-08-05 16:23:46.754 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)<iq type="set" to="[email protected]" id="blather000e" 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="a3f75438-9c74-4b66-9c51-7b9e8033768e"/>\n </dial>\n</iq> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:46.754 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo
2011-08-05 16:23:46.754 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][null]
2011-08-05 16:23:46.754 DEBUG [XMPPService-t-40] <iq type="set" to="[email protected]" id="blather000e" 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="a3f75438-9c74-4b66-9c51-7b9e8033768e"/>
</dial>
</iq> :: xmpps_8dpz25pvdd4y
2011-08-05 16:23:46.755 INFO [pool-16-thread-22] Request [DialCommand[from=sip:[email protected],to=sip:[email protected],headers={},join=JoinCommand[callId=<null>,direction=DUPLEX,media=BRIDGE,to=a3f75438-9c74-4b66-9c51-7b9e8033768e,type=CALL]]]
2011-08-05 16:23:46.760 INFO [pool-16-thread-22] Reply [com.tropo.core.CallRef@1ecb022]
2011-08-05 16:23:46.760 DEBUG [pool-16-thread-22] #XMPP#: (o)<iq type="result" id="blather000e" from="[email protected]" to="[email protected]/voxeo"><ref xmlns="urn:xmpp:rayo:1" id="e798f899-318d-4b81-9687-7f259595e316"/></iq> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:46.761 DEBUG [pool-16-thread-22] #XMPP#: Send message to: 127.0.0.1:57613 by xmpp #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:46.763 INFO [pool-16-thread-21] Message [SIPCallImpl[null,INITIALIZED]]
2011-08-05 16:23:46.765 INFO [MOHO-47] #MSCTRL#: MS[ms2-23] creates a MediaObject[BASIC, nc1, null]
2011-08-05 16:23:46.765 INFO [MOHO-47] #MSCTRL#: SdpPort[IDLE, NC[ms2-23, nc1]] generates a SDP offer
2011-08-05 16:23:46.765 DEBUG [MOHO-47] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-23, nc1]] moves state from [IDLE] to [UNDER_PROCESSING]
2011-08-05 16:23:46.765 DEBUG [msctrl/2-t-25] #MRCP#: load configuration from {maxThreadPool=2147483647, minThreadPool=25, MEDIAOBJECT_ID=nc1, com.voxeo.useLocalConfigurationOnGUTFailures=false}
2011-08-05 16:23:46.777 DEBUG [msctrl/2-t-25] #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:57623]
2011-08-05 16:23:46.788 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621601486-836e800-0ac44840-00000017\r\nTransport: RTP/AVP;unicast;client_port=65535-65536;server_port=20044-20045\r\nCseq: 1\r\nContent-Type: application/sdp\r\nContent-Length: 421\r\n\r\nv=0\r\no=- 12 12 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20044 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:57623]
2011-08-05 16:23:46.789 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-23, nc1] initializes the ASR session. #[2621601486-836e800-0ac44840-00000017]
2011-08-05 16:23:46.789 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-05 16:23:46.790 DEBUG [msctrl/2-t-25] #MSCTRL#: SdpPort[SDP_NEGOTIATING, NC[ms2-23, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATING]
2011-08-05 16:23:46.790 DEBUG [msctrl/2-t-25] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATING, NC[ms2-23, nc1]], OFFER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 12 12 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20044 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-05 16:23:46.793 DEBUG [msctrl/2-t-25] #SIP#: Session creating: ss_1a5c4jqhqt0kg #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:46.793 DEBUG [msctrl/2-t-25] #SIP#: SetRoutingDirective: NEW #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:46.794 DEBUG [msctrl/2-t-25] #SIP#: SessionManagementLayer send request: INVITE sip:[email protected] #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:46.867 DEBUG [msctrl/2-t-25] #SIP#: The transaction was created: z9hG4bK1v34j5fnoqgs3 #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.868 DEBUG [msctrl/2-t-25] #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=z9hG4bK1v34j5fnoqgs3\r\nCSeq: 1 INVITE\r\nContent-Length: 421\r\nCall-ID: vbns0q35sbp6\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=cu3qeynty1hp\r\nContact: <sip:192.168.0.196:5060;transport=tcp>\r\n\r\nv=0\r\no=- 12 12 IN IP4 192.168.0.196\r\ns=voxeo\r\nc=IN IP4 192.168.0.196\r\nt=0 0\r\nm=audio 20044 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-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.905 DEBUG [msctrl/2-t-25] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:46.906 DEBUG [msctrl/2-t-25] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:47.137 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 100 trying -- your call is important to us\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bK1v34j5fnoqgs3;rport=57243;received=71.198.132.91\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: vbns0q35sbp6\r\nServer: ser (3.2.0-dev2 (i386/linux))\r\nFrom: <sip:[email protected]>;tag=cu3qeynty1hp\r\nWarning: 392 213.192.59.75:5060 "Noisy feedback tells: pid=19077 req_src_ip=71.198.132.91 req_src_port=57243 in_uri=sip:[email protected] out_uri=sip:[email protected]:55497;transport=tcp via_cnt==1"\r\n\r\n] #[N/A][N/A][vbns0q35sbp6][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:47.138 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 100/INVITE, branch=z9hG4bK1v34j5fnoqgs3 #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:47.138 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/100 #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:47.139 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1cz9vl1vfg4qstropo2], invalidateWhenReady: true
2011-08-05 16:23:47.139 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1a5c4jqhqt0kg], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:47.139 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm1cz9vl1vfg4qstropo2], invalidateWhenReady: true
2011-08-05 16:23:47.574 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 180 Ringing\r\nTo: <sip:[email protected]>;tag=XK2o2yb.LHRjX7OXf45SpPqEFadNiyjA\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bK1v34j5fnoqgs3\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=cu3qeynty1hp;avp=B5MDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2Y>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: vbns0q35sbp6\r\nServer: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=cu3qeynty1hp\r\nContact: <sip:[email protected]:55062;transport=tcp>\r\n\r\n] #[N/A][N/A][vbns0q35sbp6][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:47.575 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 180/INVITE, branch=z9hG4bK1v34j5fnoqgs3 #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:47.575 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/180 #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:47.576 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Add Path[ id=vbns0q35sbp6-XK2o2yb.LHRjX7OXf45SpPqEFadNiyjA-cu3qeynty1hp, session=SipSessionImpl[_id=ss_1a5c4jqhqt0kg, _parentId=sas_2-15-sm1cz9vl1vfg4qstropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=vbns0q35sbp6], party= CALLEE] #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:47.576 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:47.576 DEBUG [tcp/0.0.0.0/5060-t-12] [SIP/2.0 180 Ringing
To: <sip:[email protected]>;tag=XK2o2yb.LHRjX7OXf45SpPqEFadNiyjA
Via: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bK1v34j5fnoqgs3
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Record-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=cu3qeynty1hp;avp=B5MDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2Y>
CSeq: 1 INVITE
Content-Length: 0
Call-ID: vbns0q35sbp6
Server: Blink Pro 1.1.1 (MacOSX)
From: <sip:[email protected]>;tag=cu3qeynty1hp
Contact: <sip:[email protected]:55062;transport=tcp>
]
2011-08-05 16:23:47.576 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1cz9vl1vfg4qstropo2], invalidateWhenReady: true
2011-08-05 16:23:47.578 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1a5c4jqhqt0kg], current State = EARLY, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:47.579 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm1cz9vl1vfg4qstropo2], invalidateWhenReady: true
2011-08-05 16:23:47.580 INFO [pool-16-thread-21] Message [[Event class=com.voxeo.moho.sip.SIPRingEventImpl sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:47.580 INFO [pool-16-thread-21] Queued Event [RingingEvent[callId=e798f899-318d-4b81-9687-7f259595e316]]
2011-08-05 16:23:47.580 INFO [pool-16-thread-21] Event [RingingEvent[callId=e798f899-318d-4b81-9687-7f259595e316]]
2011-08-05 16:23:47.581 DEBUG [pool-16-thread-21] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><ringing xmlns="urn:xmpp:rayo:1"/></presence> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:47.581 DEBUG [pool-16-thread-21] #XMPP#: Send message to: 127.0.0.1:57613 by xmpp #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:51.530 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 603 Busy Everywhere\r\nTo: <sip:[email protected]>;tag=XK2o2yb.LHRjX7OXf45SpPqEFadNiyjA\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bK1v34j5fnoqgs3\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=cu3qeynty1hp;avp=B5MDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2Y>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: vbns0q35sbp6\r\nServer: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=cu3qeynty1hp\r\n\r\n] #[N/A][N/A][vbns0q35sbp6][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:51.531 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 603/INVITE, branch=z9hG4bK1v34j5fnoqgs3 #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:51.533 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (o)[ACK sip:[email protected] SIP/2.0\r\nTo: <sip:[email protected]>;tag=XK2o2yb.LHRjX7OXf45SpPqEFadNiyjA\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bK1v34j5fnoqgs3\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nCall-ID: vbns0q35sbp6\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=cu3qeynty1hp\r\n\r\n] #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:51.571 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:51.572 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected]]
2011-08-05 16:23:51.572 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: InviteClientTransaction[_state=TERMINATED, _id=z9hG4bK1v34j5fnoqgs3] is released. #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:51.572 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1cz9vl1vfg4qstropo2], invalidateWhenReady: true
2011-08-05 16:23:51.573 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1a5c4jqhqt0kg], current State = EARLY, Vaild:true, Role:UAC, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:51.573 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm1cz9vl1vfg4qstropo2], invalidateWhenReady: true
2011-08-05 16:23:51.573 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/603 #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:51.573 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:51.573 DEBUG [tcp/0.0.0.0/5060-t-12] [SIP/2.0 603 Busy Everywhere
To: <sip:[email protected]>;tag=XK2o2yb.LHRjX7OXf45SpPqEFadNiyjA
Via: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bK1v34j5fnoqgs3
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Record-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=cu3qeynty1hp;avp=B5MDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2Y>
CSeq: 1 INVITE
Content-Length: 0
Call-ID: vbns0q35sbp6
Server: Blink Pro 1.1.1 (MacOSX)
From: <sip:[email protected]>;tag=cu3qeynty1hp
]
2011-08-05 16:23:51.573 DEBUG [tcp/0.0.0.0/5060-t-12] destroyNetworkConnection
2011-08-05 16:23:51.574 DEBUG [tcp/0.0.0.0/5060-t-12] #MSCTRL#: NC[ms2-23, nc1] moves state from [INITIALIZED] to [RELEASED]
2011-08-05 16:23:51.574 INFO [tcp/0.0.0.0/5060-t-12] #MSCTRL#: MS[ms2-23] removes a MediaObject[mscontrol://192.168.0.196:10074/ms2-23/nc1]
2011-08-05 16:23:51.575 DEBUG [tcp/0.0.0.0/5060-t-12] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 2\r\nSession: 2621601486-836e800-0ac44840-00000017\r\n\r\n #[2621601486-836e800-0ac44840-00000017][192.168.0.196:10074][192.168.0.196:57623]
2011-08-05 16:23:51.576 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621601486-836e800-0ac44840-00000017\r\nCseq: 2\r\n\r\n #[2621601486-836e800-0ac44840-00000017][192.168.0.196:10074][192.168.0.196:57623]
2011-08-05 16:23:51.576 DEBUG [tcp/0.0.0.0/5060-t-12] #MSCTRL#: MS[ms2-23] moves state from [INITIALIZED] to [RELEASED]
2011-08-05 16:23:51.576 DEBUG [tcp/0.0.0.0/5060-t-12] terminating call. Notifying joinDelegate conditaion. callID:vbns0q35sbp6
2011-08-05 16:23:51.577 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1cz9vl1vfg4qstropo2], invalidateWhenReady: true
2011-08-05 16:23:51.577 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1a5c4jqhqt0kg], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:51.577 INFO [pool-16-thread-22] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:51.577 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: server will automatically invalidate sipsession [ss_1a5c4jqhqt0kg] #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:51.577 INFO [pool-16-thread-21] Message [[Event class=com.voxeo.moho.sip.SIPDeniedEventImpl sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:51.578 INFO [pool-16-thread-21] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:51.578 INFO [pool-16-thread-21] Message [[Event class=com.voxeo.moho.event.MohoCallCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:51.578 INFO [pool-16-thread-21] Queued Event [EndEvent[callId=e798f899-318d-4b81-9687-7f259595e316,reason=ERROR,errorText=<null>,headers=<null>]]
2011-08-05 16:23:51.581 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipSessionImpl[_id=ss_1a5c4jqhqt0kg, _parentId=sas_2-15-sm1cz9vl1vfg4qstropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=vbns0q35sbp6] is invalidating. (s) #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:51.582 INFO [pool-16-thread-21] Call cleanup [call=SIPCallImpl[SipSessionAdaptor[sessionid=ss_1a5c4jqhqt0kg, appSessionId=sas_2-15-sm1cz9vl1vfg4qstropo2],FAILED]]
2011-08-05 16:23:51.584 INFO [pool-16-thread-21] Event [EndEvent[callId=e798f899-318d-4b81-9687-7f259595e316,reason=ERROR,errorText=<null>,headers=<null>]]
2011-08-05 16:23:51.584 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Remove Path[ id=vbns0q35sbp6-XK2o2yb.LHRjX7OXf45SpPqEFadNiyjA-cu3qeynty1hp, session=SipSessionImpl[_id=ss_1a5c4jqhqt0kg, _parentId=sas_2-15-sm1cz9vl1vfg4qstropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=true, _role=UAC, _method=INVITE, _callId=vbns0q35sbp6]] #[tropo2][sas_2-15-sm1cz9vl1vfg4qstropo2][vbns0q35sbp6][ss_1a5c4jqhqt0kg][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:51.585 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm1cz9vl1vfg4qstropo2], invalidateWhenReady: true
2011-08-05 16:23:51.585 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-15-sm1cz9vl1vfg4qstropo2]
2011-08-05 16:23:51.585 DEBUG [pool-16-thread-21] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><end xmlns="urn:xmpp:rayo:1"><error/></end></presence> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:51.585 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-15-sm1cz9vl1vfg4qstropo2] is invalidating. (as)
2011-08-05 16:23:51.585 DEBUG [pool-16-thread-21] #XMPP#: Send message to: 127.0.0.1:57613 by xmpp #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:51.588 DEBUG [SocketAcceptorIoProcessor-0.0] #CONNECTOR#: NIOTCPOutgoingConnection[/127.0.0.1:5222-->/127.0.0.1:57613] is closed.
2011-08-05 16:23:51.588 ERROR [SocketAcceptorIoProcessor-0.0] #CONNECTOR#: XMPPTcpConnector[/0.0.0.0] can not found ClientConnection: /127.0.0.1:57613 srcPort: 5222
2011-08-05 16:23:51.589 DEBUG [SocketAcceptorIoProcessor-0.0] #CONNECTOR#: NIOTCPIncomingConnection[/127.0.0.1:57613-->/127.0.0.1:5222] is closed.
2011-08-05 16:23:51.589 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)</stream:stream> #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][N/A]
2011-08-05 16:23:51.590 DEBUG [XMPPService-t-40] #XMPP#: XMPPSessionImpl: _id=xmpps_8dpz25pvdd4y, _direction=RECEIVEStream, _sessionType=CLIENT, [email protected]/voxeo, _state=TERMINATED, _remoteAddr=/127.0.0.1, _remotePort=57613, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo2-0, _state=STARTED] is invalidating. (s) #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][null]
2011-08-05 16:23:51.591 DEBUG [XMPPService-t-40] #XMPP#: Close underlizing connection for session:XMPPSessionImpl: _id=xmpps_8dpz25pvdd4y, _direction=RECEIVEStream, _sessionType=CLIENT, [email protected]/voxeo, _state=TERMINATED, _remoteAddr=/127.0.0.1, _remotePort=57613, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo2-0, _state=STARTED]
2011-08-05 16:23:51.591 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo
2011-08-05 16:23:51.591 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_8dpz25pvdd4y][[email protected]/voxeo, 127.0.0.1][127.0.0.1:57613][127.0.0.1:5222][xmpp][null]
2011-08-05 16:23:55.917 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[BYE sip:71.198.132.91:57243;transport=tcp SIP/2.0\r\nTo: <sip:[email protected]>;tag=1hrbbrcosh4lq\r\nVia: SIP/2.0/TCP 213.192.59.75;branch=z9hG4bKafbe.508493f6.0;i=31a\r\nVia: SIP/2.0/tcp 192.168.0.196:55062;received=71.198.132.91;rport=55062;branch=z9hG4bKPj9OUWFeom3FPr-nNN939avu.fPyOiUGSX\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;ftag=x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N;avp=RPwDCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2UTCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2UTBgBzdGltZXIEADE4MDATBwBhY2NvdW50AwB5ZXM;lr=on>\r\nCSeq: 4269 BYE\r\nContent-Length: 0\r\nCall-ID: 5iu54ayeo9r0\r\nP-hint: rr-enforced\r\nUser-Agent: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N\r\nMax-Forwards: 16\r\n\r\n] #[N/A][N/A][5iu54ayeo9r0][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:55.917 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: The transaction was created: z9hG4bKafbe.508493f6.0 #[N/A][N/A][5iu54ayeo9r0][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:55.918 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Find Path[ id=5iu54ayeo9r0-x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N-1hrbbrcosh4lq, path=ApplicationPath[_id=5iu54ayeo9r0-x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N-1hrbbrcosh4lq, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_1add0j0wtfe2b, appSessionId=sas_2-14-sm7ci2crpb3df5tropo2]]]]]] #[N/A][N/A][5iu54ayeo9r0][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:55.918 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv request: BYE #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:55.918 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ApplicationDispatchLayer invoke application: Controller with BYE #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:55.919 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:55.919 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-sm7ci2crpb3df5tropo2], invalidateWhenReady: true
2011-08-05 16:23:55.919 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1add0j0wtfe2b], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:55.919 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-14-sm7ci2crpb3df5tropo2], invalidateWhenReady: true
2011-08-05 16:23:55.920 DEBUG [MOHO-42] destroyNetworkConnection
2011-08-05 16:23:55.920 DEBUG [MOHO-42] #MSCTRL#: NC[ms2-22, nc1] moves state from [INITIALIZED] to [RELEASED]
2011-08-05 16:23:55.922 INFO [pool-16-thread-21] Message [[Event class=com.voxeo.moho.sip.SIPHangupEventImpl sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:55.922 INFO [MOHO-42] #MSCTRL#: MS[ms2-22] removes a MediaObject[mscontrol://192.168.0.196:10074/ms2-22/nc1]
2011-08-05 16:23:55.924 INFO [pool-16-thread-21] Call is disconnecting. Unjoining peer [SIPCallImpl[SipSessionAdaptor[sessionid=ss_1jio6cycv775, appSessionId=sas_2-14-smoelenhx060gutropo2],ANSWERED]]
2011-08-05 16:23:55.924 DEBUG [MOHO-42] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/mixer RTSP/1.0\r\nCseq: 5\r\nSession: 2621597800-832d000-0ac44840-00000016\r\n\r\n #[2621597800-832d000-0ac44840-00000016][192.168.0.196:10074][192.168.0.196:57620]
2011-08-05 16:23:55.926 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621597800-832d000-0ac44840-00000016\r\nCseq: 5\r\n\r\n #[2621597800-832d000-0ac44840-00000016][192.168.0.196:10074][192.168.0.196:57620]
2011-08-05 16:23:55.926 DEBUG [MOHO-42] #MSCTRL#: NC[MG-1a6v6j5xq79fx, nc1] removes(NC[ms2-22, nc1], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-08-05 16:23:55.926 DEBUG [MOHO-42] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/recognizer/ RTSP/1.0\r\nCseq: 6\r\nSession: 2621597800-832d000-0ac44840-00000016\r\n\r\n #[2621597800-832d000-0ac44840-00000016][192.168.0.196:10074][192.168.0.196:57620]
2011-08-05 16:23:55.936 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621597800-832d000-0ac44840-00000016\r\nCseq: 6\r\n\r\n #[2621597800-832d000-0ac44840-00000016][192.168.0.196:10074][192.168.0.196:57620]
2011-08-05 16:23:55.937 DEBUG [MOHO-42] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/synthesizer/ RTSP/1.0\r\nCseq: 7\r\nSession: 2621597800-832d000-0ac44840-00000016\r\n\r\n #[2621597800-832d000-0ac44840-00000016][192.168.0.196:10074][192.168.0.196:57620]
2011-08-05 16:23:55.947 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621597800-832d000-0ac44840-00000016\r\nCseq: 7\r\n\r\n #[2621597800-832d000-0ac44840-00000016][192.168.0.196:10074][192.168.0.196:57620]
2011-08-05 16:23:55.948 DEBUG [MOHO-42] #MSCTRL#: MS[ms2-22] moves state from [INITIALIZED] to [RELEASED]
2011-08-05 16:23:55.948 DEBUG [MOHO-42] destroyNetworkConnection
2011-08-05 16:23:55.948 DEBUG [MOHO-42] #MSCTRL#: NC[MG-1a6v6j5xq79fx, nc1] moves state from [INITIALIZED] to [RELEASED]
2011-08-05 16:23:55.949 INFO [MOHO-42] #MSCTRL#: MS[MG-1a6v6j5xq79fx] removes a MediaObject[mscontrol://192.168.0.196:10074/MG-1a6v6j5xq79fx/nc1]
2011-08-05 16:23:55.949 DEBUG [MOHO-42] #MSCTRL#: MG[MG-1a6v6j5xq79fx, MG-1a6v6j5xq79fx] removes JoineeMrcpContext[mscontrol://192.168.0.196:10074/MG-1a6v6j5xq79fx/nc1, 2621581164-2e2ac00-0ac44840-00000014, 2621581164-2e2ac00-0ac44840-00000014] #[2621581164-2e2ac00-0ac44840-00000014]
2011-08-05 16:23:55.949 DEBUG [MOHO-42] #MSCTRL#: MG[MG-1a6v6j5xq79fx, MG-1a6v6j5xq79fx] removes(NC[MG-1a6v6j5xq79fx, nc1], JoineeContext[RESOURCE_CONTAINER, RECV, null])
2011-08-05 16:23:55.949 DEBUG [MOHO-42] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/recognizer/ RTSP/1.0\r\nCseq: 12\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:55.958 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nCseq: 12\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:55.959 DEBUG [MOHO-42] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/synthesizer/ RTSP/1.0\r\nCseq: 13\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:55.969 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621581164-2e2ac00-0ac44840-00000014\r\nCseq: 13\r\n\r\n #[2621581164-2e2ac00-0ac44840-00000014][192.168.0.196:10074][192.168.0.196:57615]
2011-08-05 16:23:55.970 DEBUG [MOHO-42] #MSCTRL#: MS[MG-1a6v6j5xq79fx] moves state from [INITIALIZED] to [RELEASED]
2011-08-05 16:23:55.970 DEBUG [MOHO-42] #MSCTRL#: MG[MG-1a6v6j5xq79fx, MG-1a6v6j5xq79fx] moves state from [INITIALIZED] to [RELEASED]
2011-08-05 16:23:55.970 DEBUG [MOHO-42] #MSCTRL#: Stopping Player[IDLE, MG[MG-1a6v6j5xq79fx, MG-1a6v6j5xq79fx]], isStopAll:true
2011-08-05 16:23:55.970 DEBUG [MOHO-42] destroyNetworkConnection
2011-08-05 16:23:55.970 DEBUG [MOHO-42] #MSCTRL#: NC[ms2-21, nc1] moves state from [INITIALIZED] to [RELEASED]
2011-08-05 16:23:55.971 INFO [MOHO-42] #MSCTRL#: MS[ms2-21] removes a MediaObject[mscontrol://192.168.0.196:10074/ms2-21/nc1]
2011-08-05 16:23:55.971 DEBUG [MOHO-42] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/recognizer/ RTSP/1.0\r\nCseq: 13\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:55.980 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nCseq: 13\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:55.981 DEBUG [MOHO-42] #MRCP#: (o)TEARDOWN rtsp://192.168.0.196:10074/synthesizer/ RTSP/1.0\r\nCseq: 14\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:55.990 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 2621592952-2239e00-0ac44840-00000015\r\nCseq: 14\r\n\r\n #[2621592952-2239e00-0ac44840-00000015][192.168.0.196:10074][192.168.0.196:57618]
2011-08-05 16:23:55.991 DEBUG [MOHO-42] #MSCTRL#: MS[ms2-21] moves state from [INITIALIZED] to [RELEASED]
2011-08-05 16:23:55.991 DEBUG [MOHO-42] terminating call. Notifying this. callID:1tdftnbhe6y2f
2011-08-05 16:23:55.993 INFO [pool-16-thread-22] Message [[Event class=com.voxeo.moho.event.MohoCallCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:55.993 DEBUG [MOHO-42] #SIP#: SessionManagementLayer send request: BYE sip:[email protected]:55062;transport=tcp #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:55.994 INFO [pool-16-thread-22] Queued Event [EndEvent[callId=02feb2bb-96f6-4d9b-9e0e-0c6e10136fe2,reason=HANGUP,errorText=<null>,headers=<null>]]
2011-08-05 16:23:55.994 INFO [pool-16-thread-22] Call cleanup [call=SIPCallImpl[SipSessionAdaptor[sessionid=ss_1azav1yg51u62, appSessionId=sas_2-15-sm10va9ksndqzfitropo2],DISCONNECTED]]
2011-08-05 16:23:55.994 DEBUG [MOHO-42] #SIP#: The transaction was created: z9hG4bK1uebjdtarvlbd #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:55.995 DEBUG [MOHO-42] #SIP#: (o)[BYE sip:[email protected]:55062;transport=tcp SIP/2.0\r\nTo: <sip:[email protected]>;tag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bK1uebjdtarvlbd;x-sm-sid=7d66feb5-ce8b-4dcd-98b8-3614b7151a47;x-sm-nid=ss_1azav1yg51u62\r\nCSeq: 2 BYE\r\nContent-Length: 0\r\nRoute: <sip:213.192.59.75;transport=tcp;ftag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC;avp=2e8DCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2QTCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2QTBgBzdGltZXIEADE4MDATBwBhY2NvdW50AwB5ZXM;lr=on>\r\nCall-ID: 1tdftnbhe6y2f\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=140n6qwfq93n9\r\n\r\n] #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:55.995 DEBUG [MOHO-42] #SIP#: Send message to: /213.192.59.75:5060 by tcp #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:55.995 DEBUG [MOHO-42] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:55.995 DEBUG [MOHO-42] terminating call. Notifying this. callID:1a6v6j5xq79fx
2011-08-05 16:23:55.995 INFO [pool-16-thread-22] Event [EndEvent[callId=02feb2bb-96f6-4d9b-9e0e-0c6e10136fe2,reason=HANGUP,errorText=<null>,headers=<null>]]
2011-08-05 16:23:55.997 DEBUG [MOHO-42] #SIP#: SessionManagementLayer send request: BYE sip:[email protected]:65454;ob #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected]][sip:[email protected]]
2011-08-05 16:23:55.998 INFO [pool-16-thread-22] Message [[Event class=com.voxeo.moho.event.MohoCallCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:55.998 DEBUG [MOHO-42] #SIP#: The transaction was created: z9hG4bKjabv6gldk218 #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:55.998 INFO [pool-16-thread-22] Queued Event [EndEvent[callId=a3f75438-9c74-4b66-9c51-7b9e8033768e,reason=HANGUP,errorText=<null>,headers=<null>]]
2011-08-05 16:23:56.001 DEBUG [MOHO-42] #SIP#: (o)[BYE sip:[email protected]:65454;ob SIP/2.0\r\nTo: <sip:[email protected]>;tag=CWqPjRKlk3hXdx.NkP4qK327UF-UL.dm\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;branch=z9hG4bKjabv6gldk218;x-sm-sid=7d66feb5-ce8b-4dcd-98b8-3614b7151a47;x-sm-nid=ss_1jio6cycv775\r\nCSeq: 3 BYE\r\nContent-Length: 0\r\nRoute: <sip:213.192.59.75;transport=tcp;lr;r2=on;ftag=1mvlufxv458ml;avp=9xcDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODItNGUzYjA5NGQtZGQxYjkyMDU>\r\nRoute: <sip:213.192.59.75;lr;r2=on;ftag=1mvlufxv458ml;avp=9xcDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODItNGUzYjA5NGQtZGQxYjkyMDU>\r\nCall-ID: 1a6v6j5xq79fx\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=1mvlufxv458ml\r\n\r\n] #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.001 DEBUG [MOHO-42] #SIP#: Send message to: /213.192.59.75:5060 by tcp #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected]][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.001 DEBUG [MOHO-42] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.001 DEBUG [MOHO-42] terminating call. Notifying this. callID:5iu54ayeo9r0
2011-08-05 16:23:56.002 INFO [pool-16-thread-22] Call cleanup [call=SIPCallImpl[SipSessionAdaptor[sessionid=ss_1jio6cycv775, appSessionId=sas_2-14-smoelenhx060gutropo2],DISCONNECTED]]
2011-08-05 16:23:56.003 INFO [pool-16-thread-22] Event [EndEvent[callId=a3f75438-9c74-4b66-9c51-7b9e8033768e,reason=HANGUP,errorText=<null>,headers=<null>]]
2011-08-05 16:23:56.006 DEBUG [MOHO-42] #SIP#: SessionManagementLayer send response: BYE/200 #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:56.007 DEBUG [MOHO-42] #SIP#: Add Path[ id=5iu54ayeo9r0-x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N-1hrbbrcosh4lq, session=SipSessionImpl[_id=ss_1add0j0wtfe2b, _parentId=sas_2-14-sm7ci2crpb3df5tropo2, _handler=Controller, _state=CONFIRMED, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=5iu54ayeo9r0], party= CALLER] #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.007 DEBUG [MOHO-42] #SIP#: (o)[SIP/2.0 200 OK\r\nTo: <sip:[email protected]>;tag=1hrbbrcosh4lq\r\nVia: SIP/2.0/TCP 213.192.59.75;branch=z9hG4bKafbe.508493f6.0;i=31a\r\nVia: SIP/2.0/tcp 192.168.0.196:55062;received=71.198.132.91;rport=55062;branch=z9hG4bKPj9OUWFeom3FPr-nNN939avu.fPyOiUGSX\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;ftag=x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N;avp=RPwDCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2UTCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2UTBgBzdGltZXIEADE4MDATBwBhY2NvdW50AwB5ZXM;lr=on>\r\nCSeq: 4269 BYE\r\nContent-Length: 0\r\nCall-ID: 5iu54ayeo9r0\r\nFrom: <sip:[email protected]>;tag=x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N\r\n\r\n] #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:56.007 DEBUG [MOHO-42] #SIP#: Find Connector: tcp:sip.iptel.org/213.192.59.75, 5060 #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:56.008 DEBUG [MOHO-42] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:56.008 DEBUG [MOHO-42] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-sm7ci2crpb3df5tropo2], invalidateWhenReady: true
2011-08-05 16:23:56.008 DEBUG [MOHO-42] #SIP#: processInvalidationWhenReady [ss_1add0j0wtfe2b], current State = TERMINATED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.009 DEBUG [MOHO-42] #SIP#: server will automatically invalidate sipsession [ss_1add0j0wtfe2b] #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.010 DEBUG [MOHO-42] #SIP#: SipSessionImpl[_id=ss_1add0j0wtfe2b, _parentId=sas_2-14-sm7ci2crpb3df5tropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=5iu54ayeo9r0] is invalidating. (s) #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.011 DEBUG [MOHO-42] #SIP#: Remove Path[ id=5iu54ayeo9r0-x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N-1hrbbrcosh4lq, session=SipSessionImpl[_id=ss_1add0j0wtfe2b, _parentId=sas_2-14-sm7ci2crpb3df5tropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=true, _role=UAC, _method=INVITE, _callId=5iu54ayeo9r0]] #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.011 DEBUG [MOHO-42] #SIP#: Remove Path[ id=5iu54ayeo9r0-x-xVaY5zbeIHPba4dSrN6rmf0ARzRh-N-1hrbbrcosh4lq, session=SipSessionImpl[_id=ss_1add0j0wtfe2b, _parentId=sas_2-14-sm7ci2crpb3df5tropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=true, _role=UAC, _method=INVITE, _callId=5iu54ayeo9r0]] #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.011 DEBUG [MOHO-42] #SIP#: processInvalidationWhenReady [sas_2-14-sm7ci2crpb3df5tropo2], invalidateWhenReady: true
2011-08-05 16:23:56.012 DEBUG [MOHO-42] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-14-sm7ci2crpb3df5tropo2]
2011-08-05 16:23:56.012 DEBUG [MOHO-42] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-14-sm7ci2crpb3df5tropo2] is invalidating. (as)
2011-08-05 16:23:56.013 INFO [pool-16-thread-21] Peer unjoined [SIPCallImpl[SipSessionAdaptor[sessionid=ss_1jio6cycv775, appSessionId=sas_2-14-smoelenhx060gutropo2],DISCONNECTED]]
2011-08-05 16:23:56.013 INFO [pool-16-thread-22] Message [[Event class=com.voxeo.moho.event.MohoCallCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:56.013 INFO [pool-16-thread-22] Queued Event [EndEvent[callId=12161cc9-7069-4cbb-acad-0a489e1c94f2,reason=HANGUP,errorText=<null>,headers=<null>]]
2011-08-05 16:23:56.014 INFO [pool-16-thread-22] Call cleanup [call=SIPCallImpl[SipSessionAdaptor[sessionid=ss_1add0j0wtfe2b, appSessionId=sas_2-14-sm7ci2crpb3df5tropo2],DISCONNECTED]]
2011-08-05 16:23:56.014 INFO [pool-16-thread-22] Event [EndEvent[callId=12161cc9-7069-4cbb-acad-0a489e1c94f2,reason=HANGUP,errorText=<null>,headers=<null>]]
2011-08-05 16:23:56.016 INFO [pool-16-thread-22] Actor is disposed. Ignoring message. [[Event class=com.voxeo.moho.event.MohoUnjoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-05 16:23:56.108 DEBUG [Timer-11] #SIP#: NonInviteServerTransaction[_state=PROCEEDING, _id=z9hG4bKafbe.508493f6.0] timerRemoveTransaction is fired. #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:56.108 DEBUG [Timer-11] #SIP#: NonInviteServerTransaction[_state=TERMINATED, _id=z9hG4bKafbe.508493f6.0] is released. #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:56.528 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 200 OK\r\nTo: <sip:[email protected]>;tag=ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bK1uebjdtarvlbd;x-sm-sid=7d66feb5-ce8b-4dcd-98b8-3614b7151a47;x-sm-nid=ss_1azav1yg51u62\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=140n6qwfq93n9;avp=hDADBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2QTCQBkaWFsb2dfaWQWADRhODUtNGUzYWQzNDMtOTU3NDBhN2Q>\r\nCSeq: 2 BYE\r\nContent-Length: 0\r\nCall-ID: 1tdftnbhe6y2f\r\nServer: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=140n6qwfq93n9\r\n\r\n] #[N/A][N/A][1tdftnbhe6y2f][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:56.528 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: (i)[SIP/2.0 200 OK\r\nTo: <sip:[email protected]>;tag=CWqPjRKlk3hXdx.NkP4qK327UF-UL.dm\r\nVia: SIP/2.0/TCP 192.168.0.196:5060;rport=57243;received=71.198.132.91;branch=z9hG4bKjabv6gldk218;x-sm-sid=7d66feb5-ce8b-4dcd-98b8-3614b7151a47;x-sm-nid=ss_1jio6cycv775\r\nRecord-Route: <sip:213.192.59.75;lr;r2=on;ftag=1mvlufxv458ml;avp=IEQDBwBhY2NvdW50AwB5ZXMDCQBkaWFsb2dfaWQWADRhODItNGUzYjA5NGQtZGQxYjkyMDUDBgBzdGltZXIEADE4MDA>\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;r2=on;ftag=1mvlufxv458ml;avp=IEQDBwBhY2NvdW50AwB5ZXMDCQBkaWFsb2dfaWQWADRhODItNGUzYjA5NGQtZGQxYjkyMDUDBgBzdGltZXIEADE4MDA>\r\nCSeq: 3 BYE\r\nContent-Length: 0\r\nCall-ID: 1a6v6j5xq79fx\r\nFrom: <sip:[email protected]>;tag=1mvlufxv458ml\r\n\r\n] #[N/A][N/A][1a6v6j5xq79fx][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:56.529 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 200/BYE, branch=z9hG4bK1uebjdtarvlbd #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.529 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: Receive 200/BYE, branch=z9hG4bKjabv6gldk218 #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.529 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: NonInviteClientTransaction[_state=TERMINATED, _id=z9hG4bK1uebjdtarvlbd] is released. #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.529 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:56.530 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1azav1yg51u62], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.530 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:56.530 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: NonInviteClientTransaction[_state=TERMINATED, _id=z9hG4bKjabv6gldk218] is released. #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.530 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-smoelenhx060gutropo2], invalidateWhenReady: true
2011-08-05 16:23:56.530 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: processInvalidationWhenReady [ss_1jio6cycv775], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 2, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.530 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: processInvalidationWhenReady [sas_2-14-smoelenhx060gutropo2], invalidateWhenReady: true
2011-08-05 16:23:56.531 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: SessionManagementLayer recv response: BYE/200 #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.531 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:56.530 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: BYE/200 #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.531 DEBUG [tcp/0.0.0.0/5060-t-11] SIPCallImpl[SipSessionAdaptor[sessionid=ss_1jio6cycv775, appSessionId=sas_2-14-smoelenhx060gutropo2],DISCONNECTED] is already terminated.
2011-08-05 16:23:56.531 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-smoelenhx060gutropo2], invalidateWhenReady: true
2011-08-05 16:23:56.531 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:23:56.531 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: processInvalidationWhenReady [ss_1jio6cycv775], current State = TERMINATED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 2, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.532 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: server will automatically invalidate sipsession [ss_1jio6cycv775] #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.532 DEBUG [tcp/0.0.0.0/5060-t-12] SIPCallImpl[SipSessionAdaptor[sessionid=ss_1azav1yg51u62, appSessionId=sas_2-15-sm10va9ksndqzfitropo2],DISCONNECTED] is already terminated.
2011-08-05 16:23:56.532 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:56.532 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_1azav1yg51u62], current State = TERMINATED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.533 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: SipSessionImpl[_id=ss_1jio6cycv775, _parentId=sas_2-14-smoelenhx060gutropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=1a6v6j5xq79fx] is invalidating. (s) #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.533 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: server will automatically invalidate sipsession [ss_1azav1yg51u62] #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.534 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: Remove Path[ id=1a6v6j5xq79fx-CWqPjRKlk3hXdx.NkP4qK327UF-UL.dm-1mvlufxv458ml, session=SipSessionImpl[_id=ss_1jio6cycv775, _parentId=sas_2-14-smoelenhx060gutropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=true, _role=UAC, _method=INVITE, _callId=1a6v6j5xq79fx]] #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.535 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: processInvalidationWhenReady [sas_2-14-smoelenhx060gutropo2], invalidateWhenReady: true
2011-08-05 16:23:56.535 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipSessionImpl[_id=ss_1azav1yg51u62, _parentId=sas_2-15-sm10va9ksndqzfitropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=1tdftnbhe6y2f] is invalidating. (s) #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.535 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-14-smoelenhx060gutropo2]
2011-08-05 16:23:56.535 DEBUG [tcp/0.0.0.0/5060-t-11] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-14-smoelenhx060gutropo2] is invalidating. (as)
2011-08-05 16:23:56.536 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Remove Path[ id=1tdftnbhe6y2f-ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC-140n6qwfq93n9, session=SipSessionImpl[_id=ss_1azav1yg51u62, _parentId=sas_2-15-sm10va9ksndqzfitropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=true, _role=UAC, _method=INVITE, _callId=1tdftnbhe6y2f]] #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.537 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Remove Path[ id=1tdftnbhe6y2f-ZD4PauUaW55nBYWCLbbcr7LsGYFAHvQC-140n6qwfq93n9, session=SipSessionImpl[_id=ss_1azav1yg51u62, _parentId=sas_2-15-sm10va9ksndqzfitropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=true, _role=UAC, _method=INVITE, _callId=1tdftnbhe6y2f]] #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:23:56.537 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm10va9ksndqzfitropo2], invalidateWhenReady: true
2011-08-05 16:23:56.537 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-15-sm10va9ksndqzfitropo2]
2011-08-05 16:23:56.537 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-15-sm10va9ksndqzfitropo2] is invalidating. (as)
2011-08-05 16:24:09.201 DEBUG [Timer-9] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKjlu6lmd2o5xa] timerRemoveTransaction is fired. #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:24:09.202 DEBUG [Timer-9] #SIP#: InviteClientTransaction[_state=TERMINATED, _id=z9hG4bKjlu6lmd2o5xa] is released. #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:24:14.051 DEBUG [Timer-12] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bK1lorvn15ms5vs] timerRemoveTransaction is fired. #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:24:14.052 DEBUG [Timer-12] #SIP#: InviteClientTransaction[_state=TERMINATED, _id=z9hG4bK1lorvn15ms5vs] is released. #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:24:17.576 DEBUG [Timer-9] #SIP#: InviteServerTransaction[_state=ACCEPTED, _id=z9hG4bK3175.0fd090e3.0] timerRemoveTransaction is fired. #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:24:17.577 DEBUG [Timer-9] #SIP#: InviteServerTransaction[_state=TERMINATED, _id=z9hG4bK3175.0fd090e3.0] is released. #[tropo2][sas_2-15-sm10va9ksndqzfitropo2][1tdftnbhe6y2f][ss_1azav1yg51u62][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:57243)]
2011-08-05 16:24:17.741 DEBUG [Timer-10] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKkp71olh3ygff] timerRemoveTransaction is fired. #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:24:17.741 DEBUG [Timer-10] #SIP#: InviteClientTransaction[_state=TERMINATED, _id=z9hG4bKkp71olh3ygff] is released. #[tropo2][sas_2-14-sm7ci2crpb3df5tropo2][5iu54ayeo9r0][ss_1add0j0wtfe2b][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:24:18.549 DEBUG [Timer-12] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKxumb5fs5jrf] timerRemoveTransaction is fired. #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:24:18.549 DEBUG [Timer-12] #SIP#: InviteClientTransaction[_state=TERMINATED, _id=z9hG4bKxumb5fs5jrf] is released. #[tropo2][sas_2-14-smoelenhx060gutropo2][1a6v6j5xq79fx][ss_1jio6cycv775][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.722 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[OPTIONS sip:[email protected] SIP/2.0\r\nTo: "sipssc"<sip:[email protected]>\r\nVia: SIP/2.0/UDP 192.168.1.9:5060;branch=z9hG4bK-03352893;rport\r\nCSeq: 1 OPTIONS\r\nAccept: application/sdp\r\nContent-Length: 0\r\nCall-ID: 153542816799058794820720120\r\nUser-Agent: sundayddr\r\nMax-Forwards: 70\r\nFrom: "sipsscuser"<sip:[email protected]>; tag=75083291922649292537220880350062898835651646548\r\nContact: sip:[email protected]:5060\r\n\r\n] #[N/A][N/A][153542816799058794820720120][N/A][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.724 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: The transaction was created: z9hG4bK-03352893 #[N/A][N/A][153542816799058794820720120][N/A][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.725 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Found [tropo2] to handle the request by alphabet.
2011-08-05 16:53:45.725 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][153542816799058794820720120][N/A][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.725 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Session creating: ss_l0bfa4fyer9b #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.726 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Session created:SipSessionImpl[_id=ss_l0bfa4fyer9b, _parentId=sas_2-15-sm1sca9caxvj0nutropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UNKNOW, _method=OPTIONS, _callId=153542816799058794820720120] #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.726 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv request: OPTIONS #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.726 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ApplicationDispatchLayer invoke application: Controller with OPTIONS #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.726 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.731 ERROR [udp/0.0.0.0/5060-t-3] #SIP#: Servlet Error@T: java.lang.NullPointerException\n at com.voxeo.moho.sip.SIPUnknownRequestEventImpl.<init>(SIPUnknownRequestEventImpl.java:48)\n at com.voxeo.moho.sip.SIPDriverImpl.doOthers(SIPDriverImpl.java:334)\n at com.voxeo.moho.sip.SIPDriverImpl.doOptions(SIPDriverImpl.java:281)\n at com.voxeo.moho.sip.SIPDriverImpl.doRequest(SIPDriverImpl.java:93)\n at com.voxeo.moho.sip.SIPController.doRequest(SIPController.java:113)\n at javax.servlet.sip.SipServlet.service(SipServlet.java:36)\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:357)\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:69)\n at com.micromethod.sipmethod.server.sip.session.SessionManagementLayer._in(SessionManagementLayer.java:105)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorChainImpl.invokeNextPreApplication(SipInterceptorChainImpl.java:68)\n at com.micromethod.sipmethod.server.sip.interceptor.GenericAuthenticator.preApplication(GenericAuthenticator.java:156)\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:62)\n at com.micromethod.sipmethod.server.sip.session.ApplicationSelectionLayer.in(ApplicationSelectionLayer.java:215)\n at com.micromethod.sipmethod.server.sip.impl.ResolverLayer.in(ResolverLayer.java:35)\n at com.micromethod.sipmethod.server.sip.transaction.TransactionManagementLayer.handleByST(TransactionManagementLayer.java:396)\n at com.micromethod.sipmethod.server.sip.transaction.TransactionManagementLayer.in(TransactionManagementLayer.java:112)\n at com.micromethod.sipmethod.server.sip.impl.NetworkManagementLayer.in(NetworkManagementLayer.java:80)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl._handle(SIPServiceImpl.java:656)\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.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\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-05 16:53:45.732 ERROR [udp/0.0.0.0/5060-t-3] #SIP#: The Servlet[Controller] 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:357)\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:69)\n at com.micromethod.sipmethod.server.sip.session.SessionManagementLayer._in(SessionManagementLayer.java:105)\n at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorChainImpl.invokeNextPreApplication(SipInterceptorChainImpl.java:68)\n at com.micromethod.sipmethod.server.sip.interceptor.GenericAuthenticator.preApplication(GenericAuthenticator.java:156)\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:62)\n at com.micromethod.sipmethod.server.sip.session.ApplicationSelectionLayer.in(ApplicationSelectionLayer.java:215)\n at com.micromethod.sipmethod.server.sip.impl.ResolverLayer.in(ResolverLayer.java:35)\n at com.micromethod.sipmethod.server.sip.transaction.TransactionManagementLayer.handleByST(TransactionManagementLayer.java:396)\n at com.micromethod.sipmethod.server.sip.transaction.TransactionManagementLayer.in(TransactionManagementLayer.java:112)\n at com.micromethod.sipmethod.server.sip.impl.NetworkManagementLayer.in(NetworkManagementLayer.java:80)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl._handle(SIPServiceImpl.java:656)\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.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\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-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.732 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer send response: OPTIONS/500 #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.734 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Add Path[ id=153542816799058794820720120-75083291922649292537220880350062898835651646548-1orucip1lfpvm, session=SipSessionImpl[_id=ss_l0bfa4fyer9b, _parentId=sas_2-15-sm1sca9caxvj0nutropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=OPTIONS, _callId=153542816799058794820720120], party= CALLER] #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.734 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (o)[SIP/2.0 500 Servlet error\r\nContent-Type: text/plain\r\nTo: sipssc <sip:[email protected]>;tag=1orucip1lfpvm\r\nVia: SIP/2.0/UDP 192.168.1.9:5060;branch=z9hG4bK-03352893;rport=5060;received=61.191.41.7\r\nCSeq: 1 OPTIONS\r\nContent-Length: 101\r\nCall-ID: 153542816799058794820720120\r\nFrom: sipsscuser <sip:[email protected]>;tag=75083291922649292537220880350062898835651646548\r\n\r\nApplication threw an exception: javax.servlet.ServletException: Servlet execution threw an exception.] #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.735 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Send message to: /61.191.41.7:5060 by udp #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.735 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Connected to 61.191.41.7:5060/udp #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.738 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1sca9caxvj0nutropo2], invalidateWhenReady: true
2011-08-05 16:53:45.738 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_l0bfa4fyer9b], current State = INITIAL, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: true, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.738 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1sca9caxvj0nutropo2], invalidateWhenReady: true
2011-08-05 16:53:45.739 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1sca9caxvj0nutropo2], invalidateWhenReady: true
2011-08-05 16:53:45.739 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_l0bfa4fyer9b], current State = INITIAL, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:53:45.739 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1sca9caxvj0nutropo2], invalidateWhenReady: true
2011-08-05 16:54:17.735 DEBUG [Timer-12] #SIP#: NonInviteServerTransaction[_state=COMPLETED, _id=z9hG4bK-03352893] timerRemoveTransaction is fired. #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:54:17.735 DEBUG [Timer-12] #SIP#: NonInviteServerTransaction[_state=TERMINATED, _id=z9hG4bK-03352893] is released. #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:54:17.739 DEBUG [Timer-13] #SIP#: SipSessionImpl[_id=ss_l0bfa4fyer9b, _parentId=sas_2-15-sm1sca9caxvj0nutropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=OPTIONS, _callId=153542816799058794820720120] is invalidating. (s) #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:54:17.740 DEBUG [Timer-13] #SIP#: Remove Path[ id=153542816799058794820720120-75083291922649292537220880350062898835651646548-1orucip1lfpvm, session=SipSessionImpl[_id=ss_l0bfa4fyer9b, _parentId=sas_2-15-sm1sca9caxvj0nutropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=true, _role=UAS, _method=OPTIONS, _callId=153542816799058794820720120]] #[tropo2][sas_2-15-sm1sca9caxvj0nutropo2][153542816799058794820720120][ss_l0bfa4fyer9b][sip:[email protected](61.191.41.7:5060)][sip:[email protected](192.168.0.196:5060)]
2011-08-05 16:54:17.741 DEBUG [Timer-13] #SIP#: processInvalidationWhenReady [sas_2-15-sm1sca9caxvj0nutropo2], invalidateWhenReady: true
2011-08-05 16:54:17.741 DEBUG [Timer-13] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-15-sm1sca9caxvj0nutropo2]
2011-08-05 16:54:17.746 DEBUG [Timer-13] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-15-sm1sca9caxvj0nutropo2] is invalidating. (as)
2011-08-05 17:07:50.219 DEBUG [http-0.0.0.0-8080-exec-2] #HTTP#: (i)GET / HTTP/1.1\r\nHost: 127.0.0.1:8080\r\nUser-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7) AppleWebKit/534.48.3 (KHTML, like Gecko) Version/5.1 Safari/534.48.3\r\nAccept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8\r\nAccept-language: en-us\r\nAccept-encoding: gzip, deflate\r\nConnection: keep-alive\r\n
2011-08-05 17:07:50.224 DEBUG [http-0.0.0.0-8080-exec-2] #HTTP#: Mapping HTTP Request(/) to ApplicationImpl[_symbolicName=ROOT-0, _state=STARTED] and HttpServletWrapper[jsp, org.apache.jasper.servlet.JspServlet]
2011-08-05 17:07:50.225 DEBUG [http-0.0.0.0-8080-exec-2] #HTTP#: GenericAuthenticator[m_name=DefaultHttpAuthenticator, m_state=STARTED] no applicable login config defined
2011-08-05 17:07:50.225 DEBUG [http-0.0.0.0-8080-exec-2] #HTTP#: Invoke HttpServletWrapper[jsp, org.apache.jasper.servlet.JspServlet] for HTTP Request(/)
2011-08-05 17:07:50.225 DEBUG [http-0.0.0.0-8080-exec-2] #HTTP#: Invoke org.apache.jasper.servlet.JspServlet@d79951 for HTTP Request(/:com.voxeo.prism.msctrl)
2011-08-05 17:07:51.148 DEBUG [http-0.0.0.0-8080-exec-2] #HTTP#: (o)HTTP/1.1 302\r\nLocation: http://127.0.0.1:8080/console/Prism.jsp\r\nContent-Type: text/html\r\nContent-Length: 0\r\nDate: Sat, 06 Aug 2011 00:07:51 GMT\r\n\r\n
2011-08-05 17:07:58.338 DEBUG [http-0.0.0.0-8080-exec-5] CentralControllerAction: Initializing Applications Node
2011-08-05 17:07:58.374 DEBUG [http-0.0.0.0-8080-exec-5] Initialized Application Form(App size): 8
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment