Skip to content

Instantly share code, notes, and snippets.

@zlu

zlu/sipmethod.log

Created June 29, 2011 16:41
Show Gist options
  • Save zlu/1054274 to your computer and use it in GitHub Desktop.
Save zlu/1054274 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
sipmethod.log
2011-06-29 17:38:56.459 INFO [pool-16-thread-3] Queued Event [OfferEvent[from=sip:[email protected],to=sip:[email protected]:5060,headers={Max-Forwards=70, Content-Length=422, Contact=<sip:[email protected]:18568>, Supported=replaces, Allow=INVITE, To=<sip:[email protected]:5060>, CSeq=1 INVITE, User-Agent=Bria 3 release 3.2 stamp 61503, Via=SIP/2.0/UDP 127.0.0.1:18568;branch=z9hG4bK-d8754z-b2021f5adfeb3948-1---d8754z-;rport=18568, Call-ID=M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., Content-Type=application/sdp, From=<sip:[email protected]>;tag=0881eb4e}]]
2011-06-29 17:38:56.467 INFO [pool-16-thread-3] Event [OfferEvent[from=sip:[email protected],to=sip:[email protected]:5060,headers={Max-Forwards=70, Content-Length=422, Contact=<sip:[email protected]:18568>, Supported=replaces, Allow=INVITE, To=<sip:[email protected]:5060>, CSeq=1 INVITE, User-Agent=Bria 3 release 3.2 stamp 61503, Via=SIP/2.0/UDP 127.0.0.1:18568;branch=z9hG4bK-d8754z-b2021f5adfeb3948-1---d8754z-;rport=18568, Call-ID=M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., Content-Type=application/sdp, From=<sip:[email protected]>;tag=0881eb4e}]]
2011-06-29 17:38:56.498 DEBUG [pool-16-thread-3] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><offer xmlns="urn:xmpp:ozone:1" to="sip:[email protected]:5060" from="sip:[email protected]"><header name="Max-Forwards" value="70"/><header name="Content-Length" value="422"/><header name="Contact" value="&lt;sip:[email protected]:18568&gt;"/><header name="Supported" value="replaces"/><header name="Allow" value="INVITE"/><header name="To" value="&lt;sip:[email protected]:5060&gt;"/><header name="CSeq" value="1 INVITE"/><header name="User-Agent" value="Bria 3 release 3.2 stamp 61503"/><header name="Via" value="SIP/2.0/UDP 127.0.0.1:18568;branch=z9hG4bK-d8754z-b2021f5adfeb3948-1---d8754z-;rport=18568"/><header name="Call-ID" value="M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM."/><header name="Content-Type" value="application/sdp"/><header name="From" value="&lt;sip:[email protected]&gt;;tag=0881eb4e"/></offer></presence> #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:38:56.498 DEBUG [pool-16-thread-3] #XMPP#: Send message to: 127.0.0.1:51741 by xmpp #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:38:56.505 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)<iq type="set" to="[email protected]" id="blather0008" from="[email protected]/voxeo"><answer xmlns="urn:xmpp:ozone:1"/></iq> #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:38:56.507 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)<iq type="set" to="[email protected]" id="blather0009" from="[email protected]/voxeo"><say xmlns="urn:xmpp:ozone:say:1">please wait while we transfer your call</say></iq> #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:38:56.507 DEBUG [XMPPService-t-8] #XMPP#: Invoke application:tropo2 ozone
2011-06-29 17:38:56.507 DEBUG [XMPPService-t-8] #XMPP#: Forwarding Request #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][null]
2011-06-29 17:38:56.508 DEBUG [XMPPService-t-8] <iq type="set" to="[email protected]" id="blather0008" from="[email protected]/voxeo"><answer xmlns="urn:xmpp:ozone:1"/></iq> :: xmpps_11v5jqjnrq0ee
2011-06-29 17:38:56.535 DEBUG [XMPPService-t-8] #XMPP#: Invoke application:tropo2 ozone
2011-06-29 17:38:56.535 DEBUG [XMPPService-t-8] #XMPP#: Forwarding Request #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][null]
2011-06-29 17:38:56.536 DEBUG [XMPPService-t-8] <iq type="set" to="[email protected]" id="blather0009" from="[email protected]/voxeo"><say xmlns="urn:xmpp:ozone:say:1">please wait while we transfer your call</say></iq> :: xmpps_11v5jqjnrq0ee
2011-06-29 17:38:56.539 INFO [pool-16-thread-3] Request [AnswerCommand[callId=b6222f50-99db-4d5c-a925-681f6329517c,headers={}]]
2011-06-29 17:38:56.547 DEBUG [pool-16-thread-3] #SIP#: SessionManagementLayer send response: INVITE/180 #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:56.550 DEBUG [pool-16-thread-3] #SIP#: Add Path[ id=M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.-0881eb4e-j0ewmf0uqjz5, session=SipSessionImpl[_id=ss_o5try4fdj5ae, _parentId=sas_2-15-sm1pq3llcc2i3uxtropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=INVITE, _callId=M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.], party= CALLER] #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:56.556 DEBUG [pool-16-thread-3] #SIP#: (o)[SIP/2.0 180 Ringing\r\nTo: <sip:[email protected]:5060>;tag=j0ewmf0uqjz5\r\nVia: SIP/2.0/UDP 127.0.0.1:18568;branch=z9hG4bK-d8754z-b2021f5adfeb3948-1---d8754z-;rport=18568\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.\r\nFrom: <sip:[email protected]>;tag=0881eb4e\r\n\r\n] #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:56.558 DEBUG [pool-16-thread-3] #SIP#: Send message to: /127.0.0.1:18568 by udp #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:56.559 DEBUG [pool-16-thread-3] #SIP#: Connected to 127.0.0.1:18568/udp #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:56.559 DEBUG [pool-16-thread-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1pq3llcc2i3uxtropo2], invalidateWhenReady: true
2011-06-29 17:38:56.564 DEBUG [pool-16-thread-3] #SIP#: processInvalidationWhenReady [ss_o5try4fdj5ae], current State = EARLY, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:56.565 DEBUG [pool-16-thread-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1pq3llcc2i3uxtropo2], invalidateWhenReady: true
2011-06-29 17:38:56.616 DEBUG [MOHO-1] Set ms id with call id :M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.
2011-06-29 17:38:56.622 INFO [MOHO-1] #MSCTRL#: MS[MS-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] updates MEDIAOBJECT_ID, old:"ms2-1", new:"MS-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM."
2011-06-29 17:38:56.622 DEBUG [MOHO-1] Set nc id with call id :M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.
2011-06-29 17:38:56.623 INFO [MOHO-1] #MSCTRL#: MS[NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] updates MEDIAOBJECT_ID, old:"MS-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.", new:"NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM."
2011-06-29 17:38:56.686 INFO [MOHO-1] #MSCTRL#: MS[NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] creates a MediaObject[BASIC, NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., {MEDIAOBJECT_ID=NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.}]
2011-06-29 17:38:56.687 INFO [MOHO-1] #MSCTRL#: SdpPort[IDLE, NC[NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]] processes a SDP offer \nv=0\r\no=- 1309365536216098 1 IN IP4 192.168.1.39\r\ns=CounterPath Bria 3.2\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\na=ice-ufrag:fb039a\r\na=ice-pwd:d5998f55534a9e37b9091be7c7629332\r\nm=audio 63378 RTP/AVP 0 8 18 101\r\na=rtpmap:18 G729/8000\r\na=fmtp:18 annexb=yes\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\na=candidate:1 1 UDP 659136 192.168.1.39 63378 typ host\r\na=candidate:1 2 UDP 659134 192.168.1.39 63379 typ host\r\n
2011-06-29 17:38:56.886 DEBUG [MOHO-1] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]] moves state from [IDLE] to [UNDER_PROCESSING]
2011-06-29 17:38:56.887 DEBUG [MOHO-1] Start wait joinDelegate. CallID:M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.
2011-06-29 17:38:56.887 INFO [msctrl/2-t-1] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-06-29 17:38:56.918 DEBUG [msctrl/2-t-1] #MRCP#: load configuration from {maxThreadPool=2147483647, minThreadPool=25, MEDIAOBJECT_ID=NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., com.voxeo.useLocalConfigurationOnGUTFailures=false}
2011-06-29 17:38:57.097 DEBUG [msctrl/2-t-1] #MRCP#: (o)SETUP rtsp://192.168.1.39:10074/recognizer/ RTSP/1.0\r\nCseq: 1\r\nTransport: RTP/AVP;unicast;\r\nContent-Type: application/sdp\r\nContent-Length: 422\r\n\r\nv=0\r\no=- 1309365536216098 1 IN IP4 192.168.1.39\r\ns=CounterPath Bria 3.2\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\na=ice-ufrag:fb039a\r\na=ice-pwd:d5998f55534a9e37b9091be7c7629332\r\nm=audio 63378 RTP/AVP 0 8 18 101\r\na=rtpmap:18 G729/8000\r\na=fmtp:18 annexb=yes\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\na=candidate:1 1 UDP 659136 192.168.1.39 63378 typ host\r\na=candidate:1 2 UDP 659134 192.168.1.39 63379 typ host\r\n #[N/A][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:38:57.111 DEBUG [mrcp/2-t-1] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nTransport: RTP/AVP;unicast;client_port=63378-63379;server_port=20000-20001\r\nCseq: 1\r\nContent-Type: application/sdp\r\nContent-Length: 173\r\n\r\nv=0\r\no=- 49 49 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20000 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n #[N/A][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:38:57.125 DEBUG [msctrl/2-t-1] #MSCTRL#: NC[NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] initializes the ASR session. #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:38:57.143 DEBUG [msctrl/2-t-1] #MRCP#: (o)SETUP rtsp://192.168.1.39:10074/synthesizer/ RTSP/1.0\r\nCseq: 2\r\nTransport: RTP/AVP;unicast;\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:38:57.150 DEBUG [mrcp/2-t-2] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nTransport: RTP/AVP;unicast;client_port=63378-63379;server_port=20000-20001\r\nCseq: 2\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:38:57.156 DEBUG [msctrl/2-t-1] #MSCTRL#: NC[NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] initializes the TTS session. #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:38:57.157 DEBUG [msctrl/2-t-1] #MSCTRL#: SdpPort[SDP_NEGOTIATED, NC[NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATED]
2011-06-29 17:38:57.163 DEBUG [msctrl/2-t-1] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATED, NC[NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], ANSWER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 49 49 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20000 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n] to the application
2011-06-29 17:38:57.164 DEBUG [msctrl/2-t-1] #SIP#: SessionManagementLayer send response: INVITE/200 #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:57.168 DEBUG [msctrl/2-t-1] #SIP#: (o)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]:5060>;tag=j0ewmf0uqjz5\r\nVia: SIP/2.0/UDP 127.0.0.1:18568;branch=z9hG4bK-d8754z-b2021f5adfeb3948-1---d8754z-;rport=18568\r\nCSeq: 1 INVITE\r\nContent-Length: 173\r\nCall-ID: M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.\r\nFrom: <sip:[email protected]>;tag=0881eb4e\r\nContact: <sip:192.168.1.39:5060;transport=udp>\r\n\r\nv=0\r\no=- 49 49 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20000 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n] #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:57.168 DEBUG [msctrl/2-t-1] #SIP#: Send message to: /127.0.0.1:18568 by udp #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:57.168 DEBUG [msctrl/2-t-1] #SIP#: Connected to 127.0.0.1:18568/udp #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:57.170 DEBUG [msctrl/2-t-1] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1pq3llcc2i3uxtropo2], invalidateWhenReady: true
2011-06-29 17:38:57.170 DEBUG [msctrl/2-t-1] #SIP#: processInvalidationWhenReady [ss_o5try4fdj5ae], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:57.172 DEBUG [msctrl/2-t-1] #SIP#: processInvalidationWhenReady [sas_2-15-sm1pq3llcc2i3uxtropo2], invalidateWhenReady: true
2011-06-29 17:38:57.194 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: (i)[ACK sip:192.168.1.39:5060;transport=udp SIP/2.0\r\nTo: <sip:[email protected]:5060>;tag=j0ewmf0uqjz5\r\nVia: SIP/2.0/UDP 192.168.1.39:18568;branch=z9hG4bK-d8754z-0966b67bf4e6170c-1---d8754z-;rport\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nCall-ID: M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.\r\nUser-Agent: Bria 3 release 3.2 stamp 61503\r\nFrom: <sip:[email protected]>;tag=0881eb4e\r\nMax-Forwards: 70\r\nContact: <sip:[email protected]:18568>\r\n\r\n] #[N/A][N/A][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][N/A][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:57.198 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Find Path[ id=M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.-0881eb4e-j0ewmf0uqjz5, path=ApplicationPath[_id=M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.-0881eb4e-j0ewmf0uqjz5, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_o5try4fdj5ae, appSessionId=sas_2-15-sm1pq3llcc2i3uxtropo2]]]]]] #[N/A][N/A][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][N/A][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:57.199 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SessionManagementLayer recv request: ACK #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:57.199 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: ApplicationDispatchLayer invoke application: Controller with ACK #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:57.200 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:57.200 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1pq3llcc2i3uxtropo2], invalidateWhenReady: true
2011-06-29 17:38:57.200 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [ss_o5try4fdj5ae], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:38:57.201 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [sas_2-15-sm1pq3llcc2i3uxtropo2], invalidateWhenReady: true
2011-06-29 17:38:57.205 INFO [pool-16-thread-3] Reply [null]
2011-06-29 17:38:57.207 DEBUG [pool-16-thread-3] #XMPP#: (o)<iq type="result" id="blather0008" from="[email protected]" to="[email protected]/voxeo"/> #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:38:57.208 DEBUG [pool-16-thread-3] #XMPP#: Send message to: 127.0.0.1:51741 by xmpp #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:38:57.214 INFO [pool-16-thread-2] Request [Say[callId=b6222f50-99db-4d5c-a925-681f6329517c,verbId=87a61a84-bb74-4e14-ada4-02c63ac8b2cb,prompt=Ssml[ssml=please wait while we transfer your call,voice=<null>,uri=data:application%2Fssml%2Bxml%2C%3Cspeak%3Eplease+wait+while+we+transfer+your+call%3C%2Fspeak%3E]]]
2011-06-29 17:38:57.215 DEBUG [pool-16-thread-2] Creating instance of bean 'sayHandler'
2011-06-29 17:38:57.240 DEBUG [pool-16-thread-2] Finished creating instance of bean 'sayHandler'
2011-06-29 17:38:57.240 DEBUG [pool-16-thread-2] Set mg id with call id :M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.
2011-06-29 17:38:57.241 INFO [pool-16-thread-2] #MSCTRL#: MS[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] updates MEDIAOBJECT_ID, old:"NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.", new:"MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM."
2011-06-29 17:38:57.356 INFO [pool-16-thread-2] #MSCTRL#: MS[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] creates a MediaObject[PLAYER_RECORDER_SIGNALDETECTOR, MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., {MEDIAOBJECT_ID=MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.}]
2011-06-29 17:38:57.364 INFO [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] joins to NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] in DUPLEX
2011-06-29 17:38:57.373 DEBUG [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] adds JoineeMrcpContext[mscontrol://192.168.1.39:10074/MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM./NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., 3695479077-25fbe00-0ab370b0-00000001, 3695479077-25fbe00-0ab370b0-00000001] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:38:57.374 DEBUG [pool-16-thread-2] #MSCTRL#: NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] adds(MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-06-29 17:38:57.375 DEBUG [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] adds(NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-06-29 17:38:57.400 DEBUG [pool-16-thread-2] #MSCTRL#: Add PlayListItem[0, 0, false, rtcs=null, optargs={JUMP_PLAYLIST_INCREMENT=1, VOLUME_CHANGE=3, BARGE_IN_ENABLED=false, PLAYER_FILE_FORMAT=FORMAT_INFERRED, PLAYER_START_PAUSED=false, PLAYER_JUMP_TIME=5000, PLAYER_AUDIO_CODEC=CODEC_INFERRED, BEHAVIOUR_IF_BUSY=QUEUE_IF_BUSY, VOICE_NAME=null, PLAYER_MAX_DURATION=-1, PLAYER_START_OFFSET=0},"<speak>please wait while we transfer your call</speak>"]
2011-06-29 17:38:57.401 DEBUG [pool-16-thread-2] #MSCTRL#: Find PlayListItem[IDLE, 0, 0, false]
2011-06-29 17:38:57.401 DEBUG [pool-16-thread-2] #MSCTRL#: Player[IDLE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]] starts playing PlayListItem[IDLE, 0, 0, false]
2011-06-29 17:38:57.402 DEBUG [pool-16-thread-2] #MSCTRL#: Player[ACTIVE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]] moves state from [IDLE] to [ACTIVE]
2011-06-29 17:38:57.402 DEBUG [pool-16-thread-2] #MSCTRL#: PlayListItem[0, 0] moves state from [IDLE] to [PLAYING]
2011-06-29 17:38:57.407 DEBUG [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] added MrcpSpeakListener[Player[ACTIVE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], ACTIVE] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:38:57.497 DEBUG [pool-16-thread-2] #MRCP#: (o)ANNOUNCE rtsp://192.168.1.39:10074/synthesizer/ RTSP/1.0\r\nCseq: 3\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 245\r\n\r\nSPEAK 71000 MRCP/1.0\r\nKill-On-Barge-In: false\r\nSpeech-Language: en-US\r\nVendor-Specific-Parameters: Voxeo-Playback-Mode=JSR309\r\nContent-Type: application/synthesis+ssml\r\nContent-Length: 54\r\n\r\n<speak>please wait while we transfer your call</speak> #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:38:57.502 DEBUG [mrcp/2-t-3] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nCseq: 3\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 71000 200 IN-PROGRESS\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:38:57.511 DEBUG [pool-16-thread-2] #MSCTRL#: PlayListItem[0, 0] added (71000, 3695479077-25fbe00-0ab370b0-00000001)
2011-06-29 17:38:57.516 INFO [pool-16-thread-2] Reply [com.tropo.core.verb.VerbRef@988edd]
2011-06-29 17:38:57.517 DEBUG [pool-16-thread-2] #XMPP#: (o)<iq type="result" id="blather0009" from="[email protected]" to="[email protected]/voxeo"><ref xmlns="urn:xmpp:ozone:1" id="d6fd31f3-9ac1-4ad5-a379-104706dd2096"/></iq> #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:38:57.517 DEBUG [pool-16-thread-2] #XMPP#: Send message to: 127.0.0.1:51741 by xmpp #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:38:57.520 INFO [pool-16-thread-2] Message [[Event class=com.voxeo.moho.event.JoinCompleteEvent sourceClass=SIPIncomingCall]]
2011-06-29 17:38:59.895 DEBUG [mrcp/2-t-4] #MRCP#: (i)ANNOUNCE rtsp://192.168.1.39:10074/synthesizer/ RTSP/1.0\r\nCseq: 1\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 72\r\n\r\nSPEAK-COMPLETE 71000 COMPLETE MRCP/1.0\r\ncompletion-cause: 000 normal\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:38:59.896 DEBUG [mrcp/2-t-4] #MRCP#: (o)RTSP/1.0 200 OK\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nCseq: 1\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:38:59.899 DEBUG [mrcp/2-t-5] #MRCP#: Handling SPEAK-COMPLETE[71000] #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:38:59.902 DEBUG [mrcp/2-t-5] #MSCTRL#: Find PlayListItem[PLAYING, 0, 0, false, speakIds=[71000]]
2011-06-29 17:38:59.904 DEBUG [mrcp/2-t-5] #MSCTRL#: MrcpSpeakListener[Player[ACTIVE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], ACTIVE] handling with MrcpSpeakCompleteEvent[originalId:71000, requestId:71000, rc:0, duration:2496] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:38:59.904 DEBUG [mrcp/2-t-5] #MSCTRL#: PlayListItem[0, 0] removed (71000, 3695479077-25fbe00-0ab370b0-00000001)
2011-06-29 17:38:59.905 DEBUG [mrcp/2-t-5] #MSCTRL#: PlayListItem[0, 0] moves state from [PLAYING] to [IDLE]
2011-06-29 17:38:59.906 DEBUG [mrcp/2-t-5] #MSCTRL#: Player[IDLE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]] moves state from [ACTIVE] to [IDLE]
2011-06-29 17:38:59.907 DEBUG [mrcp/2-t-5] #MSCTRL#: clear up playList=[PlayListItem[IDLE, 0, 0, false]]
2011-06-29 17:38:59.907 DEBUG [mrcp/2-t-5] #MSCTRL#: Return PlayerEvent[Player[IDLE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], PLAY_COMPLETED, NO_ERROR, null, END_OF_PLAY_LIST, null, null, 0, 2496] to the application
2011-06-29 17:38:59.910 INFO [pool-16-thread-2] Message [[Event class=com.voxeo.moho.event.OutputCompleteEvent sourceClass=SIPIncomingCall]]
2011-06-29 17:38:59.920 INFO [pool-16-thread-2] Queued Event [SayCompleteEvent[callId=b6222f50-99db-4d5c-a925-681f6329517c,verbId=d6fd31f3-9ac1-4ad5-a379-104706dd2096,reason=SUCCESS,errorText=<null>]]
2011-06-29 17:38:59.921 INFO [pool-16-thread-2] Event [SayCompleteEvent[callId=b6222f50-99db-4d5c-a925-681f6329517c,verbId=d6fd31f3-9ac1-4ad5-a379-104706dd2096,reason=SUCCESS,errorText=<null>]]
2011-06-29 17:38:59.942 DEBUG [pool-16-thread-2] #XMPP#: (o)<presence from="[email protected]/d6fd31f3-9ac1-4ad5-a379-104706dd2096" to="[email protected]/voxeo"><complete xmlns="urn:xmpp:ozone:ext:1"><success xmlns="urn:xmpp:ozone:say:complete:1"/></complete></presence> #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:38:59.942 DEBUG [pool-16-thread-2] #XMPP#: Send message to: 127.0.0.1:51741 by xmpp #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:38:59.960 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)<iq type="set" to="[email protected]" id="blather000c" from="[email protected]/voxeo"><transfer xmlns="urn:xmpp:ozone:transfer:1"><to>sip:[email protected]</to><to>sip:[email protected]</to><to>sip:[email protected]</to></transfer></iq> #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:38:59.986 DEBUG [XMPPService-t-9] #XMPP#: Invoke application:tropo2 ozone
2011-06-29 17:38:59.986 DEBUG [XMPPService-t-9] #XMPP#: Forwarding Request #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][null]
2011-06-29 17:38:59.987 DEBUG [XMPPService-t-9] <iq type="set" to="[email protected]" id="blather000c" from="[email protected]/voxeo"><transfer xmlns="urn:xmpp:ozone:transfer:1"><to>sip:[email protected]</to><to>sip:[email protected]</to><to>sip:[email protected]</to></transfer></iq> :: xmpps_11v5jqjnrq0ee
2011-06-29 17:39:00.013 INFO [pool-16-thread-2] Request [Transfer[callId=b6222f50-99db-4d5c-a925-681f6329517c,verbId=93ae68bf-d6b1-4ad3-814b-bd62008f634d,to=[sip:[email protected], sip:[email protected], sip:[email protected]],from=<null>,timeout=PT30S,answerOnMedia=false,terminator=#,ringbackTone=<null>]]
2011-06-29 17:39:00.014 DEBUG [pool-16-thread-2] Creating instance of bean 'transferHandler'
2011-06-29 17:39:00.031 DEBUG [pool-16-thread-2] Finished creating instance of bean 'transferHandler'
2011-06-29 17:39:00.052 INFO [MOHO-5] #MSCTRL#: MS[ms2-3] creates a MediaObject[BASIC, nc1, null]
2011-06-29 17:39:00.053 INFO [MOHO-5] #MSCTRL#: SdpPort[IDLE, NC[ms2-3, nc1]] generates a SDP offer
2011-06-29 17:39:00.053 DEBUG [MOHO-5] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-3, nc1]] moves state from [IDLE] to [UNDER_PROCESSING]
2011-06-29 17:39:00.053 INFO [MOHO-6] #MSCTRL#: MS[ms2-4] creates a MediaObject[BASIC, nc1, null]
2011-06-29 17:39:00.052 INFO [MOHO-4] #MSCTRL#: MS[ms2-2] creates a MediaObject[BASIC, nc1, null]
2011-06-29 17:39:00.055 DEBUG [msctrl/2-t-2] #MRCP#: load configuration from {maxThreadPool=2147483647, minThreadPool=25, MEDIAOBJECT_ID=nc1, com.voxeo.useLocalConfigurationOnGUTFailures=false}
2011-06-29 17:39:00.053 INFO [MOHO-6] #MSCTRL#: SdpPort[IDLE, NC[ms2-4, nc1]] generates a SDP offer
2011-06-29 17:39:00.056 DEBUG [MOHO-6] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-4, nc1]] moves state from [IDLE] to [UNDER_PROCESSING]
2011-06-29 17:39:00.054 INFO [MOHO-4] #MSCTRL#: SdpPort[IDLE, NC[ms2-2, nc1]] generates a SDP offer
2011-06-29 17:39:00.056 DEBUG [MOHO-4] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-2, nc1]] moves state from [IDLE] to [UNDER_PROCESSING]
2011-06-29 17:39:00.055 DEBUG [MOHO-5] Start wait joinDelegate. CallID:
2011-06-29 17:39:00.059 DEBUG [msctrl/2-t-2] #MRCP#: (o)SETUP rtsp://192.168.1.39:10074/mixer RTSP/1.0\r\nCseq: 1\r\n\r\n #[N/A][192.168.1.39:10074][192.168.1.39:51752]
2011-06-29 17:39:00.059 DEBUG [msctrl/2-t-3] #MRCP#: load configuration from {maxThreadPool=2147483647, minThreadPool=25, MEDIAOBJECT_ID=nc1, com.voxeo.useLocalConfigurationOnGUTFailures=false}
2011-06-29 17:39:00.060 INFO [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] joins to NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] in RECV
2011-06-29 17:39:00.059 DEBUG [msctrl/2-t-4] #MRCP#: load configuration from {maxThreadPool=2147483647, minThreadPool=25, MEDIAOBJECT_ID=nc1, com.voxeo.useLocalConfigurationOnGUTFailures=false}
2011-06-29 17:39:00.059 DEBUG [MOHO-4] Start wait joinDelegate. CallID:
2011-06-29 17:39:00.056 DEBUG [MOHO-6] Start wait joinDelegate. CallID:
2011-06-29 17:39:00.062 DEBUG [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] rejoins to NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] in RECV
2011-06-29 17:39:00.062 INFO [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] unjoins from NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]
2011-06-29 17:39:00.063 DEBUG [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] removes JoineeMrcpContext[mscontrol://192.168.1.39:10074/MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM./NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., 3695479077-25fbe00-0ab370b0-00000001, 3695479077-25fbe00-0ab370b0-00000001] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:39:00.063 DEBUG [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] removed MrcpSpeakListener[Player[IDLE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], ACTIVE] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:39:00.063 DEBUG [pool-16-thread-2] #MSCTRL#: Remove MrcpSpeakListener[Player[IDLE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], ACTIVE] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:39:00.063 DEBUG [pool-16-thread-2] #MSCTRL#: NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] removes(MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-06-29 17:39:00.063 DEBUG [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] removes(NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-06-29 17:39:00.063 INFO [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] joins to NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] in RECV
2011-06-29 17:39:00.064 DEBUG [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] adds JoineeMrcpContext[mscontrol://192.168.1.39:10074/MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM./NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., 3695479077-25fbe00-0ab370b0-00000001, 3695479077-25fbe00-0ab370b0-00000001] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:39:00.064 DEBUG [pool-16-thread-2] #MSCTRL#: NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] adds(MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.], JoineeContext[RESOURCE_CONTAINER, SEND, null])
2011-06-29 17:39:00.064 DEBUG [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] adds(NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.], JoineeContext[RESOURCE_CONTAINER, RECV, null])
2011-06-29 17:39:00.069 DEBUG [pool-16-thread-2] #MSCTRL#: DetectionItem[DetectionItemIdx_0, -1, patternLabels={SD_PATTERN_0}, rtcs=null, optargs={VOXEO_CONFIDENCE_THRESHOLD=30, DTMF_HOTWORD_DETECTION_ENABLED=false, SPEECH_LANGUAGE=null, SD_INITIAL_TIMEOUT=-1, BUFFERING=true, DTMF_TERM_CHAR=null, VOXEO_INPUT_MODE=null, DTMF_TYPE_AHEAD_ENABLED=false, SD_DURATION=-1, SENSITIVITY=0.5, SD_INTER_SIG_TIMEOUT=-1}, null]
2011-06-29 17:39:00.070 DEBUG [pool-16-thread-2] #MSCTRL#: signal buffer{}
2011-06-29 17:39:00.071 DEBUG [mrcp/2-t-6] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695482074-25fcc00-0ab370b0-00000002\r\nTransport: RTP/AVP;unicast;client_port=65535-65536;server_port=20002-20003\r\nCseq: 1\r\nContent-Type: application/sdp\r\nContent-Length: 417\r\n\r\nv=0\r\no=- 1 1 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20002 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.1.39:10074][192.168.1.39:51752]
2011-06-29 17:39:00.071 DEBUG [msctrl/2-t-2] #MSCTRL#: NC[ms2-3, nc1] initializes the ASR session. #[3695482074-25fcc00-0ab370b0-00000002]
2011-06-29 17:39:00.071 INFO [msctrl/2-t-2] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-06-29 17:39:00.071 DEBUG [msctrl/2-t-2] #MSCTRL#: SdpPort[SDP_NEGOTIATING, NC[ms2-3, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATING]
2011-06-29 17:39:00.072 DEBUG [msctrl/2-t-3] #MRCP#: (o)SETUP rtsp://192.168.1.39:10074/mixer RTSP/1.0\r\nCseq: 1\r\n\r\n #[N/A][192.168.1.39:10074][192.168.1.39:51753]
2011-06-29 17:39:00.073 DEBUG [msctrl/2-t-4] #MRCP#: (o)SETUP rtsp://192.168.1.39:10074/mixer RTSP/1.0\r\nCseq: 1\r\n\r\n #[N/A][192.168.1.39:10074][192.168.1.39:51754]
2011-06-29 17:39:00.072 DEBUG [msctrl/2-t-2] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATING, NC[ms2-3, nc1]], OFFER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 1 1 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20002 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-06-29 17:39:00.075 DEBUG [msctrl/2-t-2] #SIP#: Session creating: ss_sb1xgdv9nuuo #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:39:00.076 DEBUG [msctrl/2-t-2] #SIP#: SetRoutingDirective: NEW #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:39:00.076 DEBUG [msctrl/2-t-2] #SIP#: SessionManagementLayer send request: INVITE sip:[email protected] #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:39:00.079 DEBUG [pool-16-thread-2] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] added MrcpRecognizeListener[SigDet[IDLE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], ACTIVE] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:39:00.082 DEBUG [mrcp/2-t-7] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695482078-2811000-0ab370b0-00000004\r\nTransport: RTP/AVP;unicast;client_port=65535-65536;server_port=20006-20007\r\nCseq: 1\r\nContent-Type: application/sdp\r\nContent-Length: 419\r\n\r\nv=0\r\no=- 11 11 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20006 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.1.39:10074][192.168.1.39:51754]
2011-06-29 17:39:00.082 DEBUG [mrcp/2-t-8] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695482076-2ff7e00-0ab370b0-00000003\r\nTransport: RTP/AVP;unicast;client_port=65535-65536;server_port=20004-20005\r\nCseq: 1\r\nContent-Type: application/sdp\r\nContent-Length: 419\r\n\r\nv=0\r\no=- 12 12 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20004 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.1.39:10074][192.168.1.39:51753]
2011-06-29 17:39:00.083 DEBUG [msctrl/2-t-4] #MSCTRL#: NC[ms2-2, nc1] initializes the ASR session. #[3695482078-2811000-0ab370b0-00000004]
2011-06-29 17:39:00.087 INFO [msctrl/2-t-4] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-06-29 17:39:00.087 DEBUG [msctrl/2-t-4] #MSCTRL#: SdpPort[SDP_NEGOTIATING, NC[ms2-2, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATING]
2011-06-29 17:39:00.087 DEBUG [msctrl/2-t-4] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATING, NC[ms2-2, nc1]], OFFER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 11 11 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20006 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-06-29 17:39:00.083 DEBUG [msctrl/2-t-3] #MSCTRL#: NC[ms2-4, nc1] initializes the ASR session. #[3695482076-2ff7e00-0ab370b0-00000003]
2011-06-29 17:39:00.090 INFO [msctrl/2-t-3] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-06-29 17:39:00.090 DEBUG [msctrl/2-t-3] #MSCTRL#: SdpPort[SDP_NEGOTIATING, NC[ms2-4, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATING]
2011-06-29 17:39:00.090 DEBUG [msctrl/2-t-3] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATING, NC[ms2-4, nc1]], OFFER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 12 12 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20004 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-06-29 17:39:00.088 DEBUG [msctrl/2-t-4] #SIP#: Session creating: ss_125lmu9son68j #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:39:00.093 DEBUG [msctrl/2-t-3] #SIP#: Session creating: ss_1v9lkqvbmjr0x #[tropo2][sas_2-15-sm1p5vlbm4ew4iitropo2][1sd7z5ipe0xxi][ss_1v9lkqvbmjr0x][sip:[email protected]][sip:[email protected]]
2011-06-29 17:39:00.094 DEBUG [msctrl/2-t-3] #SIP#: SetRoutingDirective: NEW #[tropo2][sas_2-15-sm1p5vlbm4ew4iitropo2][1sd7z5ipe0xxi][ss_1v9lkqvbmjr0x][sip:[email protected]][sip:[email protected]]
2011-06-29 17:39:00.094 DEBUG [msctrl/2-t-3] #SIP#: SessionManagementLayer send request: INVITE sip:[email protected] #[tropo2][sas_2-15-sm1p5vlbm4ew4iitropo2][1sd7z5ipe0xxi][ss_1v9lkqvbmjr0x][sip:[email protected]][sip:[email protected]]
2011-06-29 17:39:00.093 DEBUG [msctrl/2-t-4] #SIP#: SetRoutingDirective: NEW #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:39:00.094 DEBUG [msctrl/2-t-4] #SIP#: SessionManagementLayer send request: INVITE sip:[email protected] #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:39:00.210 DEBUG [pool-16-thread-2] #MRCP#: (o)ANNOUNCE rtsp://192.168.1.39:10074/recognizer/ RTSP/1.0\r\nCseq: 4\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 351\r\n\r\nDEFINE-GRAMMAR 71001 MRCP/1.0\r\nSpeech-Language: en-US\r\nVendor-Specific-Parameters: Voxeo-Input-Mode=dtmf voice\r\nContent-Type: application/x-jsgf\r\nContent-Length: 146\r\nContent-Id: [email protected]\r\n\r\n#JSGF 1.0;\ngrammar SIMPLE_GRAMMAR_01ABFC750A0C942167651C40D088531D;\npublic <SIMPLE_GRAMMAR_01ABFC750A0C942167651C40D088531D> = (/1.0/dtmf-pound);\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:00.216 DEBUG [mrcp/2-t-9] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nCseq: 4\r\nContent-Type: application/mrcp\r\nContent-Length: 31\r\n\r\nMRCP/1.0 71001 200 COMPLETE\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:00.220 DEBUG [pool-16-thread-2] #MSCTRL#: define a Grammar[SD_PATTERN_0]-[[email protected]] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:39:00.233 DEBUG [pool-16-thread-2] #MRCP#: (o)ANNOUNCE rtsp://192.168.1.39:10074/recognizer/ RTSP/1.0\r\nCseq: 5\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 315\r\n\r\nRECOGNIZE 71002 MRCP/1.0\r\nDtmf-Interdigit-Timeout: 0\r\nConfidence-Threshold: 30\r\nClear-DTMF-Buffer: false\r\nSpeech-Language: en-US\r\nSensitivity-Level: 50\r\nDtmf-Term-Timeout: 0\r\nVendor-Specific-Parameters: Voxeo-Input-Mode=dtmf voice\r\nContent-Type: text/uri-list\r\nContent-Length: 32\r\n\r\nsession:[email protected]\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:00.265 DEBUG [mrcp/2-t-10] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nCseq: 5\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 71002 200 IN-PROGRESS\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:00.269 DEBUG [pool-16-thread-2] #MSCTRL#: DetectionItem[DetectionItemIdx_0, -1, {SD_PATTERN_0}, dtmf voice, null, recoId=71002, asrType=prophecy] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:39:00.270 DEBUG [pool-16-thread-2] #MSCTRL#: SigDet[ACTIVE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]] moves state from [IDLE] to [ACTIVE]
2011-06-29 17:39:00.270 INFO [pool-16-thread-2] Reply [com.tropo.core.verb.VerbRef@9332f4]
2011-06-29 17:39:00.270 DEBUG [pool-16-thread-2] #XMPP#: (o)<iq type="result" id="blather000c" from="[email protected]" to="[email protected]/voxeo"><ref xmlns="urn:xmpp:ozone:1" id="7be702b6-7e2f-447d-b10e-09cf804253b4"/></iq> #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:39:00.270 DEBUG [pool-16-thread-2] #XMPP#: Send message to: 127.0.0.1:51741 by xmpp #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:39:28.525 DEBUG [mrcp/2-t-11] #MRCP#: (i)ANNOUNCE rtsp://192.168.1.39:10074/recognizer/ RTSP/1.0\r\nCseq: 2\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 46\r\n\r\nSTART-OF-SPEECH 71002 IN-PROGRESS MRCP/1.0\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:28.525 DEBUG [mrcp/2-t-11] #MRCP#: (o)RTSP/1.0 200 OK\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nCseq: 2\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:28.528 DEBUG [mrcp/2-t-12] #MRCP#: (o)ANNOUNCE rtsp://192.168.1.39:10074/synthesizer/ RTSP/1.0\r\nCseq: 6\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 36\r\n\r\nBARGE-IN-OCCURRED 71003 MRCP/1.0\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:28.529 DEBUG [mrcp/2-t-12] #MSCTRL#: MrcpRecognizeListener[SigDet[ACTIVE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], ACTIVE] handling with START-OF-SPEECH #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:39:28.536 DEBUG [mrcp/2-t-13] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nCseq: 6\r\nContent-Type: application/mrcp\r\nContent-Length: 31\r\n\r\nMRCP/1.0 71003 200 COMPLETE\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:29.169 DEBUG [Timer-10] #SIP#: InviteServerTransaction[_state=ACCEPTED, _id=z9hG4bK-d8754z-b2021f5adfeb3948-1---d8754z-] timerRemoveTransaction is fired. #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:39:29.170 DEBUG [Timer-10] #SIP#: InviteServerTransaction[_state=TERMINATED, _id=z9hG4bK-d8754z-b2021f5adfeb3948-1---d8754z-] is released. #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:39:29.343 DEBUG [mrcp/2-t-14] #MRCP#: (i)ANNOUNCE rtsp://192.168.1.39:10074/recognizer/ RTSP/1.0\r\nCseq: 3\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 80\r\n\r\nRECOGNITION-COMPLETE 71002 COMPLETE MRCP/1.0\r\ncompletion-cause: 001 no-match\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:29.344 DEBUG [mrcp/2-t-14] #MRCP#: (o)RTSP/1.0 200 OK\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nCseq: 3\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:29.345 DEBUG [mrcp/2-t-15] #MRCP#: Handling RECOGNITION-COMPLETE[71002] #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:29.348 DEBUG [mrcp/2-t-15] #MSCTRL#: MrcpRecognizeListener[SigDet[ACTIVE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], ACTIVE] handling with MrcpRecognitionCompleteEvent[originalId:71002, requestId:71002] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:39:29.351 DEBUG [mrcp/2-t-15] #MSCTRL#: MrcpAsrResult{type:NO_MATCH, } #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:39:29.352 DEBUG [mrcp/2-t-15] #MRCP#: (o)ANNOUNCE rtsp://192.168.1.39:10074/recognizer/ RTSP/1.0\r\nCseq: 7\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nContent-Type: application/mrcp\r\nContent-Length: 101\r\n\r\nGET-PARAMS 71004 MRCP/1.0\r\nClear-DTMF-Buffer: true\r\nVendor-Specific-Parameters: Voxeo-DTMF-Buffer\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:29.370 DEBUG [mrcp/2-t-16] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nCseq: 7\r\nContent-Type: application/mrcp\r\nContent-Length: 80\r\n\r\nMRCP/1.0 71004 200 COMPLETE\r\nvendor-specific-parameters: Voxeo-DTMF-Buffer=;\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:39:29.373 DEBUG [mrcp/2-t-15] #MSCTRL#: signal buffer{}
2011-06-29 17:39:29.375 DEBUG [mrcp/2-t-15] #MSCTRL#: SigDet[IDLE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]] moves state from [ACTIVE] to [IDLE]
2011-06-29 17:39:29.375 DEBUG [mrcp/2-t-15] #MSCTRL#: Return SigDetEvt[SigDet[IDLE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], RECEIVE_SIGNALS_COMPLETED, NO_ERROR, null, NO_GRAMMAR_MATCH, null, -1, null, null, null, null] to the application
2011-06-29 17:39:29.380 DEBUG [mrcp/2-t-15] #MSCTRL#: signal buffer{}
2011-06-29 17:39:29.381 INFO [pool-16-thread-2] Message [[Event class=com.voxeo.moho.event.InputCompleteEvent sourceClass=SIPIncomingCall]]
2011-06-29 17:39:30.368 DEBUG [msctrl/2-t-3] destroyNetworkConnection
2011-06-29 17:39:30.369 DEBUG [msctrl/2-t-3] #MSCTRL#: NC[ms2-4, nc1] moves state from [INITIALIZED] to [RELEASED]
2011-06-29 17:39:30.370 INFO [msctrl/2-t-3] #MSCTRL#: MS[ms2-4] removes a MediaObject[mscontrol://192.168.1.39:10074/ms2-4/nc1]
2011-06-29 17:39:30.370 DEBUG [msctrl/2-t-3] #MRCP#: (o)TEARDOWN rtsp://192.168.1.39:10074/mixer RTSP/1.0\r\nCseq: 2\r\nSession: 3695482076-2ff7e00-0ab370b0-00000003\r\n\r\n #[3695482076-2ff7e00-0ab370b0-00000003][192.168.1.39:10074][192.168.1.39:51753]
2011-06-29 17:39:30.372 DEBUG [mrcp/2-t-17] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695482076-2ff7e00-0ab370b0-00000003\r\nCseq: 2\r\n\r\n #[3695482076-2ff7e00-0ab370b0-00000003][192.168.1.39:10074][192.168.1.39:51753]
2011-06-29 17:39:30.373 DEBUG [msctrl/2-t-3] #MSCTRL#: MS[ms2-4] moves state from [INITIALIZED] to [RELEASED]
2011-06-29 17:39:30.374 DEBUG [msctrl/2-t-3] terminating call. Notifying joinDelegate conditaion. callID:1sd7z5ipe0xxi
2011-06-29 17:39:30.374 WARN [msctrl/2-t-3]
java.lang.RuntimeException: java.lang.NullPointerException
at com.voxeo.moho.sip.Media2NOJoinDelegate.doSdpEvent(Media2NOJoinDelegate.java:60)
at com.voxeo.moho.sip.SIPCallImpl.onEvent(SIPCallImpl.java:676)
at com.voxeo.moho.sip.SIPCallImpl.onEvent(SIPCallImpl.java:91)
at com.voxeo.mscontrol.MediaEventNotifierSupport.notify(MediaEventNotifierSupport.java:61)
at com.voxeo.mscontrol.networkconnection.MrcpSdpPortManager$CreateThread.run(MrcpSdpPortManager.java:318)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:680)
Caused by: java.lang.NullPointerException
at com.micromethod.sipmethod.server.common.dns.impl.SimpleDNSResolver.doA6Query(SimpleDNSResolver.java:154)
at com.micromethod.sipmethod.server.common.dns.impl.FailoverableResolver.doA6Query(FailoverableResolver.java:107)
at com.micromethod.sipmethod.server.common.dns.impl.CachableResolver.doA6Query(CachableResolver.java:121)
at com.micromethod.sipmethod.server.common.dns.impl.DNSResolverImpl.doA6Query(DNSResolverImpl.java:56)
at com.micromethod.sipmethod.server.sip.impl.SIPDNSResolverImpl.doAClassQuery(SIPDNSResolverImpl.java:278)
at com.micromethod.sipmethod.server.sip.impl.SIPDNSResolverImpl.lookup(SIPDNSResolverImpl.java:206)
at com.micromethod.sipmethod.server.sip.impl.SIPDNSResolverImpl.lookup(SIPDNSResolverImpl.java:57)
at com.micromethod.sipmethod.server.sip.message.SipServletRequestImpl.getDestinations(SipServletRequestImpl.java:718)
at com.micromethod.sipmethod.server.sip.stack.SipUtils.getTargetFor(SipUtils.java:246)
at com.micromethod.sipmethod.server.sip.stack.SipUtils.getSuitablyLocalAddressFor(SipUtils.java:326)
at com.micromethod.sipmethod.server.sip.session.SessionManagementLayer._out(SessionManagementLayer.java:154)
at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorChainImpl.invokeNextPostApplication(SipInterceptorChainImpl.java:98)
at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorSupport.postApplication(SipInterceptorSupport.java:31)
at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorChainImpl.invokeNextPostApplication(SipInterceptorChainImpl.java:91)
at com.micromethod.sipmethod.server.sip.interceptor.SipInterceptorPipelineImpl.postInvokeApplication(SipInterceptorPipelineImpl.java:40)
at com.micromethod.sipmethod.server.sip.session.SessionManagementLayer.out(SessionManagementLayer.java:81)
at com.micromethod.sipmethod.server.sip.impl.ApplicationDispatchLayer.out(ApplicationDispatchLayer.java:126)
at com.micromethod.sipmethod.server.sip.message.SipServletRequestImpl.send(SipServletRequestImpl.java:740)
at com.voxeo.moho.sip.SIPOutgoingCall.call(SIPOutgoingCall.java:120)
at com.voxeo.moho.sip.Media2NOJoinDelegate.doSdpEvent(Media2NOJoinDelegate.java:54)
... 7 more
2011-06-29 17:39:30.378 INFO [pool-16-thread-2] Message [[Event class=com.voxeo.moho.event.JoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-06-29 17:39:30.378 INFO [pool-16-thread-2] Received JoinCompleteEvent but Transfer verb is either already joined or no longer running
2011-06-29 17:39:30.379 INFO [pool-16-thread-2] Message [[Event class=com.voxeo.moho.event.CallCompleteEvent sourceClass=SIPOutgoingCall]]
2011-06-29 17:39:50.393 DEBUG [msctrl/2-t-4] #SIP#: The transaction was created: z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:39:50.398 DEBUG [msctrl/2-t-4] #SIP#: (o)[INVITE sip:[email protected] SIP/2.0\r\nContent-Type: application/sdp\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bKaswi55dhtwhg;rport\r\nCSeq: 1 INVITE\r\nContent-Length: 419\r\nCall-ID: 17il5m5hl6ckj\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: <sip:192.168.1.39:5060;transport=udp>\r\n\r\nv=0\r\no=- 11 11 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20006 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-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:39:50.899 DEBUG [Timer-13] #SIP#: InviteClientTransaction[_state=CALLING, _id=z9hG4bKaswi55dhtwhg] timerReSend is fired. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:00.438 DEBUG [msctrl/2-t-2] #SIP#: The transaction was created: z9hG4bK144sg8j5b8py3 #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:00.440 DEBUG [msctrl/2-t-2] #SIP#: (o)[INVITE sip:[email protected] SIP/2.0\r\nContent-Type: application/sdp\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bK144sg8j5b8py3;rport\r\nCSeq: 1 INVITE\r\nContent-Length: 417\r\nCall-ID: 1pbne7kz0v2wp\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=hjgefnefynm\r\nContact: <sip:192.168.1.39:5060;transport=udp>\r\n\r\nv=0\r\no=- 1 1 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20002 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-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:00.940 DEBUG [Timer-9] #SIP#: InviteClientTransaction[_state=CALLING, _id=z9hG4bK144sg8j5b8py3] timerReSend is fired. #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:10.438 DEBUG [msctrl/2-t-4] #SIP#: Send message to: /213.192.59.75:5060 by udp #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:10.439 DEBUG [msctrl/2-t-4] #SIP#: Connected to 213.192.59.75:5060/udp #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:10.440 DEBUG [MOHO-4] Start wait joinDelegate. CallID:17il5m5hl6ckj
2011-06-29 17:40:10.440 DEBUG [Timer-13] #SIP#: (o)[INVITE sip:[email protected] SIP/2.0\r\nContent-Type: application/sdp\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bKaswi55dhtwhg;rport\r\nCSeq: 1 INVITE\r\nContent-Length: 419\r\nCall-ID: 17il5m5hl6ckj\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: <sip:192.168.1.39:5060;transport=udp>\r\n\r\nv=0\r\no=- 11 11 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20006 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-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:10.441 DEBUG [Timer-22] destroyNetworkConnection
2011-06-29 17:40:10.442 DEBUG [Timer-22] #MSCTRL#: NC[ms2-2, nc1] moves state from [INITIALIZED] to [RELEASED]
2011-06-29 17:40:10.442 INFO [Timer-22] #MSCTRL#: MS[ms2-2] removes a MediaObject[mscontrol://192.168.1.39:10074/ms2-2/nc1]
2011-06-29 17:40:10.444 DEBUG [Timer-22] #MRCP#: (o)TEARDOWN rtsp://192.168.1.39:10074/mixer RTSP/1.0\r\nCseq: 2\r\nSession: 3695482078-2811000-0ab370b0-00000004\r\n\r\n #[3695482078-2811000-0ab370b0-00000004][192.168.1.39:10074][192.168.1.39:51754]
2011-06-29 17:40:10.446 DEBUG [mrcp/2-t-18] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695482078-2811000-0ab370b0-00000004\r\nCseq: 2\r\n\r\n #[3695482078-2811000-0ab370b0-00000004][192.168.1.39:10074][192.168.1.39:51754]
2011-06-29 17:40:10.446 DEBUG [Timer-22] #MSCTRL#: MS[ms2-2] moves state from [INITIALIZED] to [RELEASED]
2011-06-29 17:40:10.446 DEBUG [Timer-22] terminating call. Notifying joinDelegate conditaion. callID:17il5m5hl6ckj
2011-06-29 17:40:10.448 DEBUG [Timer-22] #SIP#: SessionManagementLayer send request: CANCEL sip:[email protected] #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:10.449 DEBUG [Timer-22] #SIP#: The transaction was created: z9hG4bKaswi55dhtwhgCANCEL #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:10.451 INFO [pool-16-thread-2] Message [[Event class=com.voxeo.moho.event.JoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-06-29 17:40:10.451 INFO [pool-16-thread-2] Received JoinCompleteEvent but Transfer verb is either already joined or no longer running
2011-06-29 17:40:10.452 INFO [pool-16-thread-2] Message [[Event class=com.voxeo.moho.event.CallCompleteEvent sourceClass=SIPOutgoingCall]]
2011-06-29 17:40:10.508 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: (i)[SIP/2.0 100 trying -- your call is important to us\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bKaswi55dhtwhg;rport=40324;received=46.64.16.97\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nServer: ser (3.2.0-dev2 (i386/linux))\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nWarning: 392 213.192.59.75:5060 "Noisy feedback tells: pid=30563 req_src_ip=46.64.16.97 req_src_port=40324 in_uri=sip:[email protected] out_uri=sip:[email protected]:53151;ob via_cnt==1"\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:10.508 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Receive 100/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:10.510 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: (o)[CANCEL sip:[email protected] SIP/2.0\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bKaswi55dhtwhg;rport\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\n\r\n] #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:10.817 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[SIP/2.0 180 Ringing\r\nTo: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=M4EDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTg>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:55647;ob>\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:10.823 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Receive 180/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:10.951 DEBUG [Timer-11] #SIP#: NonInviteClientTransaction[_state=TRYING, _id=z9hG4bKaswi55dhtwhgCANCEL] timerReSend is fired. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:10.953 DEBUG [Timer-11] #SIP#: (o)[CANCEL sip:[email protected] SIP/2.0\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bKaswi55dhtwhg;rport\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\n\r\n] #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:17.884 DEBUG [udp/0.0.0.0/5060-t-5] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=M4EDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTg>\r\nCSeq: 1 INVITE\r\nContent-Length: 253\r\nSupported: replaces, 100rel, timer, norefersub\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:55647;ob>\r\nSession-Expires: 1800;refresher=uac\r\n\r\nv=0\r\no=- 3518354410 3518354411 IN IP4 192.168.1.39\r\ns=pjmedia\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\na=X-nat:0\r\nm=audio 47980 RTP/AVP 0 101\r\na=rtcp:4005 IN IP4 192.168.1.39\r\na=rtpmap:0 PCMU/8000\r\na=sendrecv\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:17.885 DEBUG [udp/0.0.0.0/5060-t-5] #SIP#: Receive 200/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:18.376 DEBUG [udp/0.0.0.0/5060-t-6] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=M4EDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTg>\r\nCSeq: 1 INVITE\r\nContent-Length: 253\r\nSupported: replaces, 100rel, timer, norefersub\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:55647;ob>\r\nSession-Expires: 1800;refresher=uac\r\n\r\nv=0\r\no=- 3518354410 3518354411 IN IP4 192.168.1.39\r\ns=pjmedia\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\na=X-nat:0\r\nm=audio 47980 RTP/AVP 0 101\r\na=rtcp:4005 IN IP4 192.168.1.39\r\na=rtpmap:0 PCMU/8000\r\na=sendrecv\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:18.377 DEBUG [udp/0.0.0.0/5060-t-6] #SIP#: Receive 200/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:19.377 DEBUG [udp/0.0.0.0/5060-t-7] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=M4EDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTg>\r\nCSeq: 1 INVITE\r\nContent-Length: 253\r\nSupported: replaces, 100rel, timer, norefersub\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:55647;ob>\r\nSession-Expires: 1800;refresher=uac\r\n\r\nv=0\r\no=- 3518354410 3518354411 IN IP4 192.168.1.39\r\ns=pjmedia\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\na=X-nat:0\r\nm=audio 47980 RTP/AVP 0 101\r\na=rtcp:4005 IN IP4 192.168.1.39\r\na=rtpmap:0 PCMU/8000\r\na=sendrecv\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:19.379 DEBUG [udp/0.0.0.0/5060-t-7] #SIP#: Receive 200/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:20.573 DEBUG [msctrl/2-t-2] #SIP#: Send message to: /81.23.228.140:5060 by udp #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:20.575 DEBUG [msctrl/2-t-2] #SIP#: Connected to 81.23.228.140:5060/udp #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:20.576 DEBUG [Timer-22] destroyNetworkConnection
2011-06-29 17:40:20.576 DEBUG [Timer-22] #MSCTRL#: NC[ms2-3, nc1] moves state from [INITIALIZED] to [RELEASED]
2011-06-29 17:40:20.576 DEBUG [Timer-9] #SIP#: (o)[INVITE sip:[email protected] SIP/2.0\r\nContent-Type: application/sdp\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bK144sg8j5b8py3;rport\r\nCSeq: 1 INVITE\r\nContent-Length: 417\r\nCall-ID: 1pbne7kz0v2wp\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=hjgefnefynm\r\nContact: <sip:192.168.1.39:5060;transport=udp>\r\n\r\nv=0\r\no=- 1 1 IN IP4 192.168.1.39\r\ns=voxeo\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\nm=audio 20002 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-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:20.576 INFO [Timer-22] #MSCTRL#: MS[ms2-3] removes a MediaObject[mscontrol://192.168.1.39:10074/ms2-3/nc1]
2011-06-29 17:40:20.577 DEBUG [Timer-22] #MRCP#: (o)TEARDOWN rtsp://192.168.1.39:10074/mixer RTSP/1.0\r\nCseq: 2\r\nSession: 3695482074-25fcc00-0ab370b0-00000002\r\n\r\n #[3695482074-25fcc00-0ab370b0-00000002][192.168.1.39:10074][192.168.1.39:51752]
2011-06-29 17:40:20.584 DEBUG [mrcp/2-t-19] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695482074-25fcc00-0ab370b0-00000002\r\nCseq: 2\r\n\r\n #[3695482074-25fcc00-0ab370b0-00000002][192.168.1.39:10074][192.168.1.39:51752]
2011-06-29 17:40:20.585 DEBUG [Timer-22] #MSCTRL#: MS[ms2-3] moves state from [INITIALIZED] to [RELEASED]
2011-06-29 17:40:20.585 DEBUG [Timer-22] terminating call. Notifying joinDelegate conditaion. callID:1pbne7kz0v2wp
2011-06-29 17:40:20.586 DEBUG [Timer-22] #SIP#: SessionManagementLayer send request: CANCEL sip:[email protected] #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:20.587 DEBUG [Timer-22] #SIP#: The transaction was created: z9hG4bK144sg8j5b8py3CANCEL #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:20.587 INFO [Timer-22] Queued Event [TransferCompleteEvent[callId=b6222f50-99db-4d5c-a925-681f6329517c,verbId=7be702b6-7e2f-447d-b10e-09cf804253b4,reason=TIMEOUT,errorText=<null>]]
2011-06-29 17:40:20.589 INFO [pool-16-thread-2] Message [[Event class=com.voxeo.moho.event.JoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-06-29 17:40:20.589 INFO [pool-16-thread-2] Event [TransferCompleteEvent[callId=b6222f50-99db-4d5c-a925-681f6329517c,verbId=7be702b6-7e2f-447d-b10e-09cf804253b4,reason=TIMEOUT,errorText=<null>]]
2011-06-29 17:40:20.590 DEBUG [pool-16-thread-2] #XMPP#: (o)<presence from="[email protected]/7be702b6-7e2f-447d-b10e-09cf804253b4" to="[email protected]/voxeo"><complete xmlns="urn:xmpp:ozone:ext:1"><timeout xmlns="urn:xmpp:ozone:transfer:complete:1"/></complete></presence> #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:40:20.591 DEBUG [pool-16-thread-2] #XMPP#: Send message to: 127.0.0.1:51741 by xmpp #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:40:20.593 INFO [pool-16-thread-4] Message [[Event class=com.voxeo.moho.event.CallCompleteEvent sourceClass=SIPOutgoingCall]]
2011-06-29 17:40:21.377 DEBUG [udp/0.0.0.0/5060-t-8] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=M4EDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTg>\r\nCSeq: 1 INVITE\r\nContent-Length: 253\r\nSupported: replaces, 100rel, timer, norefersub\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:55647;ob>\r\nSession-Expires: 1800;refresher=uac\r\n\r\nv=0\r\no=- 3518354410 3518354411 IN IP4 192.168.1.39\r\ns=pjmedia\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\na=X-nat:0\r\nm=audio 47980 RTP/AVP 0 101\r\na=rtcp:4005 IN IP4 192.168.1.39\r\na=rtpmap:0 PCMU/8000\r\na=sendrecv\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:21.378 DEBUG [udp/0.0.0.0/5060-t-8] #SIP#: Receive 200/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:25.378 DEBUG [udp/0.0.0.0/5060-t-9] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=M4EDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTg>\r\nCSeq: 1 INVITE\r\nContent-Length: 251\r\nSupported: replaces, 100rel, timer, norefersub\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:53151;ob>\r\nSession-Expires: 1800;refresher=uac\r\n\r\nv=0\r\no=- 3518354410 3518354411 IN IP4 192.168.1.39\r\ns=pjmedia\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\na=X-nat:0\r\nm=audio 4004 RTP/AVP 0 101\r\na=rtcp:4005 IN IP4 192.168.1.39\r\na=rtpmap:0 PCMU/8000\r\na=sendrecv\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:25.380 DEBUG [udp/0.0.0.0/5060-t-9] #SIP#: Receive 200/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:29.376 DEBUG [udp/0.0.0.0/5060-t-11] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=M4EDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTg>\r\nCSeq: 1 INVITE\r\nContent-Length: 251\r\nSupported: replaces, 100rel, timer, norefersub\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:53151;ob>\r\nSession-Expires: 1800;refresher=uac\r\n\r\nv=0\r\no=- 3518354410 3518354411 IN IP4 192.168.1.39\r\ns=pjmedia\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\na=X-nat:0\r\nm=audio 4004 RTP/AVP 0 101\r\na=rtcp:4005 IN IP4 192.168.1.39\r\na=rtpmap:0 PCMU/8000\r\na=sendrecv\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:29.379 DEBUG [udp/0.0.0.0/5060-t-11] #SIP#: Receive 200/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:30.590 DEBUG [Timer-13] #SIP#: Send message to: /213.192.59.75:5060 by udp #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:30.593 DEBUG [Timer-13] #SIP#: Connected to 213.192.59.75:5060/udp #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:30.658 DEBUG [udp/0.0.0.0/5060-t-10] #SIP#: (i)[SIP/2.0 100 trying -- your call is important to us\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bKaswi55dhtwhg;rport=40324;received=46.64.16.97\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nServer: ser (3.2.0-dev2 (i386/linux))\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nWarning: 392 213.192.59.75:5060 "Noisy feedback tells: pid=30559 req_src_ip=46.64.16.97 req_src_port=40324 in_uri=sip:[email protected] out_uri=sip:[email protected]:53151;ob via_cnt==1"\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:30.659 DEBUG [udp/0.0.0.0/5060-t-10] #SIP#: Receive 100/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:30.664 DEBUG [Timer-13] #SIP#: NonInviteClientTransaction[_state=TRYING, _id=z9hG4bK144sg8j5b8py3CANCEL] timerReSend is fired. #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:30.665 DEBUG [Timer-13] #SIP#: (o)[CANCEL sip:[email protected] SIP/2.0\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bK144sg8j5b8py3;rport\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 1pbne7kz0v2wp\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=hjgefnefynm\r\n\r\n] #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:30.876 DEBUG [udp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 180 Ringing\r\nTo: <sip:[email protected]>;tag=fJRt3clVF.zgsY5sZa-vadm-iQhjFD3N\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=+X0DBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NWYtNGRmZTI4MTMtYzA5ZGRlOWI>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:55647;ob>\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:30.876 DEBUG [udp/0.0.0.0/5060-t-12] #SIP#: Receive 180/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:31.594 DEBUG [Timer-8] #SIP#: InviteClientTransaction[_state=PROCEEDING, _id=z9hG4bKaswi55dhtwhg] timerReSend is fired. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:32.441 DEBUG [Timer-8] #SIP#: InviteClientTransaction[_state=CALLING, _id=z9hG4bK144sg8j5b8py3] timerTimeout is fired. #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:32.441 DEBUG [Timer-8] #SIP#: InviteClientTransaction[_state=TERMINATED, _id=z9hG4bK144sg8j5b8py3] is released. #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:32.443 DEBUG [Timer-8] #SIP#: TransactionManagementLayer synthesized 408 timeout response: \n[SIP/2.0 408 Request Timeout\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bK144sg8j5b8py3;rport\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 1pbne7kz0v2wp\r\nFrom: <sip:[email protected]>;tag=hjgefnefynm\r\n\r\n] #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:32.444 DEBUG [Timer-8] #SIP#: (i)[SIP/2.0 408 Request Timeout\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bK144sg8j5b8py3;rport\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 1pbne7kz0v2wp\r\nFrom: <sip:[email protected]>;tag=hjgefnefynm\r\n\r\n] #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:32.444 DEBUG [Timer-8] #SIP#: SessionManagementLayer recv response: INVITE/408 #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:32.444 DEBUG [Timer-8] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:32.445 DEBUG [Timer-8] SIPCallImpl[SipSessionAdaptor[sessionid=ss_sb1xgdv9nuuo, appSessionId=sas_2-15-sm1qwgndaluwhc9tropo2],DISCONNECTED] is already terminated.
2011-06-29 17:40:32.445 DEBUG [Timer-8] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1qwgndaluwhc9tropo2], invalidateWhenReady: true
2011-06-29 17:40:32.446 DEBUG [Timer-8] #SIP#: processInvalidationWhenReady [ss_sb1xgdv9nuuo], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:32.446 DEBUG [Timer-8] #SIP#: processInvalidationWhenReady [sas_2-15-sm1qwgndaluwhc9tropo2], invalidateWhenReady: true
2011-06-29 17:40:32.446 DEBUG [Timer-8] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1qwgndaluwhc9tropo2], invalidateWhenReady: true
2011-06-29 17:40:32.446 DEBUG [Timer-8] #SIP#: processInvalidationWhenReady [ss_sb1xgdv9nuuo], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:32.446 DEBUG [Timer-8] #SIP#: processInvalidationWhenReady [sas_2-15-sm1qwgndaluwhc9tropo2], invalidateWhenReady: true
2011-06-29 17:40:33.398 DEBUG [udp/0.0.0.0/5060-t-13] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=M4EDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTg>\r\nCSeq: 1 INVITE\r\nContent-Length: 251\r\nSupported: replaces, 100rel, timer, norefersub\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:53151;ob>\r\nSession-Expires: 1800;refresher=uac\r\n\r\nv=0\r\no=- 3518354410 3518354411 IN IP4 192.168.1.39\r\ns=pjmedia\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\na=X-nat:0\r\nm=audio 4004 RTP/AVP 0 101\r\na=rtcp:4005 IN IP4 192.168.1.39\r\na=rtpmap:0 PCMU/8000\r\na=sendrecv\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:33.399 DEBUG [udp/0.0.0.0/5060-t-13] #SIP#: Receive 200/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:37.378 DEBUG [udp/0.0.0.0/5060-t-14] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=M4EDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTg>\r\nCSeq: 1 INVITE\r\nContent-Length: 251\r\nSupported: replaces, 100rel, timer, norefersub\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:53151;ob>\r\nSession-Expires: 1800;refresher=uac\r\n\r\nv=0\r\no=- 3518354410 3518354411 IN IP4 192.168.1.39\r\ns=pjmedia\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\na=X-nat:0\r\nm=audio 4004 RTP/AVP 0 101\r\na=rtcp:4005 IN IP4 192.168.1.39\r\na=rtpmap:0 PCMU/8000\r\na=sendrecv\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:37.379 DEBUG [udp/0.0.0.0/5060-t-14] #SIP#: Receive 200/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:41.379 DEBUG [udp/0.0.0.0/5060-t-15] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=M4EDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTg>\r\nCSeq: 1 INVITE\r\nContent-Length: 251\r\nSupported: replaces, 100rel, timer, norefersub\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:53151;ob>\r\nSession-Expires: 1800;refresher=uac\r\n\r\nv=0\r\no=- 3518354410 3518354411 IN IP4 192.168.1.39\r\ns=pjmedia\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\na=X-nat:0\r\nm=audio 4004 RTP/AVP 0 101\r\na=rtcp:4005 IN IP4 192.168.1.39\r\na=rtpmap:0 PCMU/8000\r\na=sendrecv\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:41.380 DEBUG [udp/0.0.0.0/5060-t-15] #SIP#: Receive 200/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:42.450 DEBUG [Timer-10] #SIP#: NonInviteClientTransaction[_state=TRYING, _id=z9hG4bKaswi55dhtwhgCANCEL] timerTimeout is fired. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:42.451 DEBUG [Timer-10] #SIP#: NonInviteClientTransaction[_state=TERMINATED, _id=z9hG4bKaswi55dhtwhgCANCEL] is released. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:42.452 DEBUG [Timer-10] #SIP#: TransactionManagementLayer synthesized 408 timeout response: \n[SIP/2.0 408 Request Timeout\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bKaswi55dhtwhg;rport\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\n\r\n] #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:42.452 DEBUG [Timer-10] #SIP#: (i)[SIP/2.0 408 Request Timeout\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bKaswi55dhtwhg;rport\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\n\r\n] #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:42.452 DEBUG [Timer-10] #SIP#: SessionManagementLayer recv response: CANCEL/408 #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:42.452 DEBUG [Timer-10] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:42.453 DEBUG [Timer-10] SIPCallImpl[SipSessionAdaptor[sessionid=ss_125lmu9son68j, appSessionId=sas_2-15-sm12rdpnf7serjktropo2],DISCONNECTED] is already terminated.
2011-06-29 17:40:42.453 DEBUG [Timer-10] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:42.453 DEBUG [Timer-10] #SIP#: processInvalidationWhenReady [ss_125lmu9son68j], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:42.453 DEBUG [Timer-10] #SIP#: processInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:42.453 DEBUG [Timer-10] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:42.453 DEBUG [Timer-10] #SIP#: processInvalidationWhenReady [ss_125lmu9son68j], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:42.454 DEBUG [Timer-10] #SIP#: processInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:45.380 DEBUG [udp/0.0.0.0/5060-t-16] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=M4EDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTg>\r\nCSeq: 1 INVITE\r\nContent-Length: 251\r\nSupported: replaces, 100rel, timer, norefersub\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:53151;ob>\r\nSession-Expires: 1800;refresher=uac\r\n\r\nv=0\r\no=- 3518354410 3518354411 IN IP4 192.168.1.39\r\ns=pjmedia\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\na=X-nat:0\r\nm=audio 4004 RTP/AVP 0 101\r\na=rtcp:4005 IN IP4 192.168.1.39\r\na=rtpmap:0 PCMU/8000\r\na=sendrecv\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:45.381 DEBUG [udp/0.0.0.0/5060-t-16] #SIP#: Receive 200/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:49.380 DEBUG [udp/0.0.0.0/5060-t-17] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=M4EDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTg>\r\nCSeq: 1 INVITE\r\nContent-Length: 251\r\nSupported: replaces, 100rel, timer, norefersub\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nContact: "zhao lu" <sip:[email protected]:53151;ob>\r\nSession-Expires: 1800;refresher=uac\r\n\r\nv=0\r\no=- 3518354410 3518354411 IN IP4 192.168.1.39\r\ns=pjmedia\r\nc=IN IP4 192.168.1.39\r\nt=0 0\r\na=X-nat:0\r\nm=audio 4004 RTP/AVP 0 101\r\na=rtcp:4005 IN IP4 192.168.1.39\r\na=rtpmap:0 PCMU/8000\r\na=sendrecv\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:49.382 DEBUG [udp/0.0.0.0/5060-t-17] #SIP#: Receive 200/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:49.873 DEBUG [udp/0.0.0.0/5060-t-18] #SIP#: (i)[BYE sip:46.64.16.97:40324;transport=udp SIP/2.0\r\nTo: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nVia: SIP/2.0/UDP 213.192.59.75;branch=z9hG4bKb5e8.66e47fc7.0\r\nVia: SIP/2.0/UDP 192.168.1.39:53151;received=46.64.16.97;rport=55647;branch=z9hG4bKPjCMZVxugImogjPseucUum1c9262Y1rFj3\r\nRecord-Route: <sip:213.192.59.75;ftag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz;avp=9ywDCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTgTCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTgTBgBzdGltZXIEADE4MDATBwBhY2NvdW50AwB5ZXM;lr=on>\r\nCSeq: 18393 BYE\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nP-hint: rr-enforced\r\nFrom: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\nMax-Forwards: 16\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:49.875 DEBUG [udp/0.0.0.0/5060-t-18] #SIP#: The transaction was created: z9hG4bKb5e8.66e47fc7.0 #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:49.875 DEBUG [udp/0.0.0.0/5060-t-18] #SIP#: Cannot found session. #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:49.876 DEBUG [udp/0.0.0.0/5060-t-18] #SIP#: (o)[SIP/2.0 481 Cannot found session\r\nTo: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nVia: SIP/2.0/UDP 213.192.59.75;branch=z9hG4bKb5e8.66e47fc7.0\r\nVia: SIP/2.0/UDP 192.168.1.39:53151;received=46.64.16.97;rport=55647;branch=z9hG4bKPjCMZVxugImogjPseucUum1c9262Y1rFj3\r\nRecord-Route: <sip:213.192.59.75;ftag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz;avp=9ywDCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTgTCQBkaWFsb2dfaWQWADc3NjMtNGRmZTI3ZjEtMWVlYTBlNTgTBgBzdGltZXIEADE4MDATBwBhY2NvdW50AwB5ZXM;lr=on>\r\nCSeq: 18393 BYE\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:49.876 DEBUG [udp/0.0.0.0/5060-t-18] #SIP#: Send message to: /213.192.59.75:5060 by udp #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:49.876 DEBUG [udp/0.0.0.0/5060-t-18] #SIP#: Connected to 213.192.59.75:5060/udp #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.593 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Send message to: /213.192.59.75:5060 by udp #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:50.593 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Connected to 213.192.59.75:5060/udp #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected]]
2011-06-29 17:40:50.593 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SessionManagementLayer recv response: INVITE/100 #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.593 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:50.594 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [ss_125lmu9son68j], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.594 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:50.595 DEBUG [udp/0.0.0.0/5060-t-17] #SIP#: SessionManagementLayer recv response: INVITE/200 #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.597 DEBUG [udp/0.0.0.0/5060-t-17] #SIP#: Add Path[ id=17il5m5hl6ckj-UvHVgXw-3tbA0ss7MduUxRD5MWkS16gz-1a2hy9joe4bk8, session=SipSessionImpl[_id=ss_125lmu9son68j, _parentId=sas_2-15-sm12rdpnf7serjktropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=17il5m5hl6ckj], party= CALLEE] #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.598 DEBUG [udp/0.0.0.0/5060-t-17] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.606 DEBUG [udp/0.0.0.0/5060-t-17] SIPCallImpl[SipSessionAdaptor[sessionid=ss_125lmu9son68j, appSessionId=sas_2-15-sm12rdpnf7serjktropo2],DISCONNECTED] is already terminated.
2011-06-29 17:40:50.608 DEBUG [udp/0.0.0.0/5060-t-17] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:50.608 DEBUG [udp/0.0.0.0/5060-t-17] #SIP#: processInvalidationWhenReady [ss_125lmu9son68j], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.609 DEBUG [udp/0.0.0.0/5060-t-17] #SIP#: processInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:50.611 DEBUG [udp/0.0.0.0/5060-t-16] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKaswi55dhtwhg] discards the response.
2011-06-29 17:40:50.611 DEBUG [udp/0.0.0.0/5060-t-15] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKaswi55dhtwhg] discards the response.
2011-06-29 17:40:50.615 DEBUG [udp/0.0.0.0/5060-t-14] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKaswi55dhtwhg] discards the response.
2011-06-29 17:40:50.616 DEBUG [udp/0.0.0.0/5060-t-13] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKaswi55dhtwhg] discards the response.
2011-06-29 17:40:50.618 DEBUG [udp/0.0.0.0/5060-t-12] #SIP#: The response will be droped: 180/INVITE #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.618 DEBUG [udp/0.0.0.0/5060-t-10] #SIP#: The response will be droped: 100/INVITE #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.619 DEBUG [udp/0.0.0.0/5060-t-11] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKaswi55dhtwhg] discards the response.
2011-06-29 17:40:50.619 DEBUG [udp/0.0.0.0/5060-t-9] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKaswi55dhtwhg] discards the response.
2011-06-29 17:40:50.620 DEBUG [udp/0.0.0.0/5060-t-8] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKaswi55dhtwhg] discards the response.
2011-06-29 17:40:50.622 DEBUG [udp/0.0.0.0/5060-t-7] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKaswi55dhtwhg] discards the response.
2011-06-29 17:40:50.622 DEBUG [udp/0.0.0.0/5060-t-6] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKaswi55dhtwhg] discards the response.
2011-06-29 17:40:50.623 DEBUG [udp/0.0.0.0/5060-t-5] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKaswi55dhtwhg] discards the response.
2011-06-29 17:40:50.623 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: The response will be droped: 180/INVITE #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.653 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[SIP/2.0 200 canceling\r\nTo: sip:[email protected];tag=ab7f724f44d6a86dac492bd71f480906-d67b\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bKaswi55dhtwhg;rport=40324;received=46.64.16.97\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nServer: ser (3.2.0-dev2 (i386/linux))\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nWarning: 392 213.192.59.75:5060 "Noisy feedback tells: pid=30558 req_src_ip=46.64.16.97 req_src_port=40324 in_uri=sip:[email protected] out_uri=sip:[email protected] via_cnt==1"\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.655 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Dropping response for unknown transaction: [SIP/2.0 200 canceling\r\nTo: <sip:[email protected]>;tag=ab7f724f44d6a86dac492bd71f480906-d67b\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bKaswi55dhtwhg;rport=40324;received=46.64.16.97\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nServer: ser (3.2.0-dev2 (i386/linux))\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\nWarning: 392 213.192.59.75:5060 "Noisy feedback tells: pid=30558 req_src_ip=46.64.16.97 req_src_port=40324 in_uri=sip:[email protected] out_uri=sip:[email protected] via_cnt==1"\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.728 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[SIP/2.0 487 Request Terminated\r\nTo: <sip:[email protected]>;tag=fJRt3clVF.zgsY5sZa-vadm-iQhjFD3N\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=+X0DBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NWYtNGRmZTI4MTMtYzA5ZGRlOWI>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.738 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Receive 487/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.741 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv response: INVITE/487 #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.743 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.744 DEBUG [udp/0.0.0.0/5060-t-3] SIPCallImpl[SipSessionAdaptor[sessionid=ss_125lmu9son68j, appSessionId=sas_2-15-sm12rdpnf7serjktropo2],DISCONNECTED] is already terminated.
2011-06-29 17:40:50.744 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:50.744 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_125lmu9son68j], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:50.745 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:51.170 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[SIP/2.0 487 Request Terminated\r\nTo: <sip:[email protected]>;tag=fJRt3clVF.zgsY5sZa-vadm-iQhjFD3N\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=+X0DBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NWYtNGRmZTI4MTMtYzA5ZGRlOWI>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:51.170 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Receive 487/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:51.171 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv response: INVITE/487 #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:51.171 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:51.171 DEBUG [udp/0.0.0.0/5060-t-3] SIPCallImpl[SipSessionAdaptor[sessionid=ss_125lmu9son68j, appSessionId=sas_2-15-sm12rdpnf7serjktropo2],DISCONNECTED] is already terminated.
2011-06-29 17:40:51.171 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:51.172 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_125lmu9son68j], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:51.172 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:52.170 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[SIP/2.0 487 Request Terminated\r\nTo: <sip:[email protected]>;tag=fJRt3clVF.zgsY5sZa-vadm-iQhjFD3N\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=+X0DBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NWYtNGRmZTI4MTMtYzA5ZGRlOWI>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:52.170 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Receive 487/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:52.171 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv response: INVITE/487 #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:52.171 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:52.171 DEBUG [udp/0.0.0.0/5060-t-3] SIPCallImpl[SipSessionAdaptor[sessionid=ss_125lmu9son68j, appSessionId=sas_2-15-sm12rdpnf7serjktropo2],DISCONNECTED] is already terminated.
2011-06-29 17:40:52.171 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:52.171 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_125lmu9son68j], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:52.172 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:52.588 DEBUG [Timer-12] #SIP#: NonInviteClientTransaction[_state=TRYING, _id=z9hG4bK144sg8j5b8py3CANCEL] timerTimeout is fired. #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:52.589 DEBUG [Timer-12] #SIP#: NonInviteClientTransaction[_state=TERMINATED, _id=z9hG4bK144sg8j5b8py3CANCEL] is released. #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:52.591 DEBUG [Timer-12] #SIP#: TransactionManagementLayer synthesized 408 timeout response: \n[SIP/2.0 408 Request Timeout\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bK144sg8j5b8py3;rport\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 1pbne7kz0v2wp\r\nFrom: <sip:[email protected]>;tag=hjgefnefynm\r\n\r\n] #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:52.591 DEBUG [Timer-12] #SIP#: (i)[SIP/2.0 408 Request Timeout\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;branch=z9hG4bK144sg8j5b8py3;rport\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 1pbne7kz0v2wp\r\nFrom: <sip:[email protected]>;tag=hjgefnefynm\r\n\r\n] #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:52.591 DEBUG [Timer-12] #SIP#: SessionManagementLayer recv response: CANCEL/408 #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:52.591 DEBUG [Timer-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:40:52.592 DEBUG [Timer-12] SIPCallImpl[SipSessionAdaptor[sessionid=ss_sb1xgdv9nuuo, appSessionId=sas_2-15-sm1qwgndaluwhc9tropo2],DISCONNECTED] is already terminated.
2011-06-29 17:40:52.592 DEBUG [Timer-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1qwgndaluwhc9tropo2], invalidateWhenReady: true
2011-06-29 17:40:52.592 DEBUG [Timer-12] #SIP#: processInvalidationWhenReady [ss_sb1xgdv9nuuo], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:52.592 DEBUG [Timer-12] #SIP#: server will automatically invalidate sipsession [ss_sb1xgdv9nuuo] #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:52.593 DEBUG [Timer-12] #SIP#: SipSessionImpl[_id=ss_sb1xgdv9nuuo, _parentId=sas_2-15-sm1qwgndaluwhc9tropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=1pbne7kz0v2wp] is invalidating. (s) #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:52.594 DEBUG [Timer-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm1qwgndaluwhc9tropo2], invalidateWhenReady: true
2011-06-29 17:40:52.594 DEBUG [Timer-12] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-15-sm1qwgndaluwhc9tropo2]
2011-06-29 17:40:52.594 DEBUG [Timer-12] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-15-sm1qwgndaluwhc9tropo2] is invalidating. (as)
2011-06-29 17:40:54.170 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[SIP/2.0 487 Request Terminated\r\nTo: <sip:[email protected]>;tag=fJRt3clVF.zgsY5sZa-vadm-iQhjFD3N\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8;avp=+X0DBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADc3NWYtNGRmZTI4MTMtYzA5ZGRlOWI>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:54.170 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Receive 487/INVITE, branch=z9hG4bKaswi55dhtwhg #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:54.170 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv response: INVITE/487 #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:54.171 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:54.171 DEBUG [udp/0.0.0.0/5060-t-3] SIPCallImpl[SipSessionAdaptor[sessionid=ss_125lmu9son68j, appSessionId=sas_2-15-sm12rdpnf7serjktropo2],DISCONNECTED] is already terminated.
2011-06-29 17:40:54.171 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:40:54.171 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_125lmu9son68j], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:40:54.171 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:41:00.629 DEBUG [Timer-9] #SIP#: Send message to: /81.23.228.140:5060 by udp #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:00.629 DEBUG [Timer-9] #SIP#: Connected to 81.23.228.140:5060/udp #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:00.630 DEBUG [Timer-9] #SIP#: InviteClientTransaction[_state=TERMINATED, _id=z9hG4bK144sg8j5b8py3] is released. #[N/A][N/A][N/A][N/A][?][?]
2011-06-29 17:41:07.250 DEBUG [SocketAcceptorIoProcessor-0.0] #CONNECTOR#: NIOTCPOutgoingConnection[/127.0.0.1:5222-->/127.0.0.1:51741] is closed.
2011-06-29 17:41:07.250 ERROR [SocketAcceptorIoProcessor-0.0] #CONNECTOR#: XMPPTcpConnector[/0.0.0.0] can not found ClientConnection: /127.0.0.1:51741 srcPort: 5222
2011-06-29 17:41:07.250 DEBUG [SocketAcceptorIoProcessor-0.0] #CONNECTOR#: NIOTCPIncomingConnection[/127.0.0.1:51741-->/127.0.0.1:5222] is closed.
2011-06-29 17:41:07.251 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)</stream:stream> #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][N/A]
2011-06-29 17:41:07.258 DEBUG [XMPPService-t-10] #XMPP#: XMPPSessionImpl: _id=xmpps_11v5jqjnrq0ee, _direction=RECEIVEStream, _sessionType=CLIENT, [email protected]/voxeo, _state=TERMINATED, _remoteAddr=/127.0.0.1, _remotePort=51741, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo2-0, _state=STARTED] is invalidating. (s) #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][null]
2011-06-29 17:41:07.259 DEBUG [XMPPService-t-10] #XMPP#: Close underlizing connection for session:XMPPSessionImpl: _id=xmpps_11v5jqjnrq0ee, _direction=RECEIVEStream, _sessionType=CLIENT, [email protected]/voxeo, _state=TERMINATED, _remoteAddr=/127.0.0.1, _remotePort=51741, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo2-0, _state=STARTED]
2011-06-29 17:41:07.262 DEBUG [XMPPService-t-10] #XMPP#: Invoke application:tropo2 ozone
2011-06-29 17:41:07.263 DEBUG [XMPPService-t-10] #XMPP#: Forwarding Request #[tropo2][null][xmpps_11v5jqjnrq0ee][[email protected]/voxeo, 127.0.0.1][127.0.0.1:51741][127.0.0.1:5222][xmpp][null]
2011-06-29 17:41:10.666 DEBUG [Timer-11] #SIP#: Send message to: /213.192.59.75:5060 by udp #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected]]
2011-06-29 17:41:10.667 DEBUG [Timer-11] #SIP#: Connected to 213.192.59.75:5060/udp #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected]]
2011-06-29 17:41:10.667 DEBUG [Timer-11] #SIP#: NonInviteClientTransaction[_state=TERMINATED, _id=z9hG4bKaswi55dhtwhgCANCEL] is released. #[N/A][N/A][N/A][N/A][?][?]
2011-06-29 17:41:10.687 DEBUG [Timer-13] #SIP#: Send message to: /81.23.228.140:5060 by udp #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected]][sip:[email protected]]
2011-06-29 17:41:10.692 DEBUG [Timer-13] #SIP#: Connected to 81.23.228.140:5060/udp #[tropo2][sas_2-15-sm1qwgndaluwhc9tropo2][1pbne7kz0v2wp][ss_sb1xgdv9nuuo][sip:[email protected](81.23.228.140:5060)][sip:[email protected]]
2011-06-29 17:41:10.694 DEBUG [Timer-13] #SIP#: NonInviteClientTransaction[_state=TERMINATED, _id=z9hG4bK144sg8j5b8py3CANCEL] is released. #[N/A][N/A][N/A][N/A][?][?]
2011-06-29 17:41:10.793 DEBUG [udp/0.0.0.0/5060-t-5] #SIP#: (i)[SIP/2.0 481 Call/Transaction Does Not Exist\r\nTo: <sip:[email protected]>;tag=z9hG4bK1bdb.8ab30ea5.0\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8>\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:10.794 DEBUG [udp/0.0.0.0/5060-t-5] #SIP#: Dropping response for unknown transaction: [SIP/2.0 481 Call/Transaction Does Not Exist\r\nTo: <sip:[email protected]>;tag=z9hG4bK1bdb.8ab30ea5.0\r\nVia: SIP/2.0/UDP 192.168.1.39:5060;rport=40324;received=46.64.16.97;branch=z9hG4bKaswi55dhtwhg\r\nRecord-Route: <sip:213.192.59.75;lr;ftag=1a2hy9joe4bk8>\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 17il5m5hl6ckj\r\nFrom: <sip:[email protected]>;tag=1a2hy9joe4bk8\r\n\r\n] #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:11.869 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[BYE sip:192.168.1.39:5060;transport=udp SIP/2.0\r\nTo: <sip:[email protected]:5060>;tag=j0ewmf0uqjz5\r\nVia: SIP/2.0/UDP 192.168.1.39:18568;branch=z9hG4bK-d8754z-024f04177058ba1c-1---d8754z-;rport\r\nCSeq: 2 BYE\r\nContent-Length: 0\r\nCall-ID: M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.\r\nUser-Agent: Bria 3 release 3.2 stamp 61503\r\nFrom: <sip:[email protected]>;tag=0881eb4e\r\nMax-Forwards: 70\r\nContact: <sip:[email protected]:18568>\r\n\r\n] #[N/A][N/A][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][N/A][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.870 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: The transaction was created: z9hG4bK-d8754z-024f04177058ba1c-1---d8754z- #[N/A][N/A][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][N/A][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.877 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Find Path[ id=M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.-0881eb4e-j0ewmf0uqjz5, path=ApplicationPath[_id=M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.-0881eb4e-j0ewmf0uqjz5, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_o5try4fdj5ae, appSessionId=sas_2-15-sm1pq3llcc2i3uxtropo2]]]]]] #[N/A][N/A][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][N/A][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.878 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv request: BYE #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.878 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ApplicationDispatchLayer invoke application: Controller with BYE #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.878 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.879 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1pq3llcc2i3uxtropo2], invalidateWhenReady: true
2011-06-29 17:41:11.879 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_o5try4fdj5ae], current State = CONFIRMED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.879 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1pq3llcc2i3uxtropo2], invalidateWhenReady: true
2011-06-29 17:41:11.880 INFO [pool-16-thread-4] Message [[Event class=com.voxeo.moho.sip.SIPDisconnectEventImpl sourceClass=SIPIncomingCall]]
2011-06-29 17:41:11.881 DEBUG [MOHO-11] destroyNetworkConnection
2011-06-29 17:41:11.881 DEBUG [MOHO-11] #MSCTRL#: NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] moves state from [INITIALIZED] to [RELEASED]
2011-06-29 17:41:11.882 INFO [MOHO-11] #MSCTRL#: MS[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] removes a MediaObject[mscontrol://192.168.1.39:10074/MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM./NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]
2011-06-29 17:41:11.882 DEBUG [MOHO-11] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] removes JoineeMrcpContext[mscontrol://192.168.1.39:10074/MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM./NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., 3695479077-25fbe00-0ab370b0-00000001, 3695479077-25fbe00-0ab370b0-00000001] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:41:11.883 DEBUG [MOHO-11] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] removed MrcpRecognizeListener[SigDet[IDLE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], ACTIVE] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:41:11.883 DEBUG [MOHO-11] #MSCTRL#: Remove MrcpRecognizeListener[SigDet[IDLE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], ACTIVE] #[3695479077-25fbe00-0ab370b0-00000001]
2011-06-29 17:41:11.883 DEBUG [MOHO-11] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] removes(NC[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., NC-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.], JoineeContext[RESOURCE_CONTAINER, RECV, null])
2011-06-29 17:41:11.884 DEBUG [MOHO-11] #MRCP#: (o)TEARDOWN rtsp://192.168.1.39:10074/recognizer/ RTSP/1.0\r\nCseq: 8\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:41:11.887 DEBUG [mrcp/2-t-20] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nCseq: 8\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:41:11.887 DEBUG [MOHO-11] #MRCP#: (o)TEARDOWN rtsp://192.168.1.39:10074/synthesizer/ RTSP/1.0\r\nCseq: 9\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:41:11.900 DEBUG [mrcp/2-t-21] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3695479077-25fbe00-0ab370b0-00000001\r\nCseq: 9\r\n\r\n #[3695479077-25fbe00-0ab370b0-00000001][192.168.1.39:10074][192.168.1.39:51750]
2011-06-29 17:41:11.911 DEBUG [MOHO-11] #MSCTRL#: MS[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] moves state from [INITIALIZED] to [RELEASED]
2011-06-29 17:41:11.911 DEBUG [MOHO-11] #MSCTRL#: MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] moves state from [INITIALIZED] to [RELEASED]
2011-06-29 17:41:11.912 DEBUG [MOHO-11] #MSCTRL#: Stopping Player[IDLE, MG[MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM., MG-M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]], isStopAll:true
2011-06-29 17:41:11.912 DEBUG [MOHO-11] terminating call. Notifying this. callID:M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.
2011-06-29 17:41:11.913 DEBUG [MOHO-11] #SIP#: SessionManagementLayer send response: BYE/200 #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.913 DEBUG [MOHO-11] #SIP#: (o)[SIP/2.0 200 OK\r\nTo: <sip:[email protected]:5060>;tag=j0ewmf0uqjz5\r\nVia: SIP/2.0/UDP 192.168.1.39:18568;branch=z9hG4bK-d8754z-024f04177058ba1c-1---d8754z-;rport=18568\r\nCSeq: 2 BYE\r\nContent-Length: 0\r\nCall-ID: M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.\r\nFrom: <sip:[email protected]>;tag=0881eb4e\r\n\r\n] #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.914 DEBUG [MOHO-11] #SIP#: Send message to: /192.168.1.39:18568 by udp #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.914 DEBUG [MOHO-11] #SIP#: Connected to 192.168.1.39:18568/udp #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](192.168.1.39:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.914 DEBUG [MOHO-11] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1pq3llcc2i3uxtropo2], invalidateWhenReady: true
2011-06-29 17:41:11.916 DEBUG [MOHO-11] #SIP#: processInvalidationWhenReady [ss_o5try4fdj5ae], current State = TERMINATED, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.916 DEBUG [MOHO-11] #SIP#: server will automatically invalidate sipsession [ss_o5try4fdj5ae] #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.917 DEBUG [MOHO-11] #SIP#: SipSessionImpl[_id=ss_o5try4fdj5ae, _parentId=sas_2-15-sm1pq3llcc2i3uxtropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=INVITE, _callId=M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.] is invalidating. (s) #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.921 DEBUG [MOHO-11] #SIP#: Remove Path[ id=M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.-0881eb4e-j0ewmf0uqjz5, session=SipSessionImpl[_id=ss_o5try4fdj5ae, _parentId=sas_2-15-sm1pq3llcc2i3uxtropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=true, _role=UAS, _method=INVITE, _callId=M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.]] #[tropo2][sas_2-15-sm1pq3llcc2i3uxtropo2][M2VmN2U5ZTI5ZjY3ZTA2YTUzYWZmYzUxMGU1MTkxYjM.][ss_o5try4fdj5ae][sip:[email protected](127.0.0.1:18568)][sip:[email protected]:5060(192.168.1.39:5060)]
2011-06-29 17:41:11.921 DEBUG [MOHO-11] #SIP#: processInvalidationWhenReady [sas_2-15-sm1pq3llcc2i3uxtropo2], invalidateWhenReady: true
2011-06-29 17:41:11.922 DEBUG [MOHO-11] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-15-sm1pq3llcc2i3uxtropo2]
2011-06-29 17:41:11.922 DEBUG [MOHO-11] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-15-sm1pq3llcc2i3uxtropo2] is invalidating. (as)
2011-06-29 17:41:11.923 INFO [pool-16-thread-4] Message [[Event class=com.voxeo.moho.event.CallCompleteEvent sourceClass=SIPIncomingCall]]
2011-06-29 17:41:11.926 INFO [pool-16-thread-4] Queued Event [EndEvent[callId=b6222f50-99db-4d5c-a925-681f6329517c,reason=HANGUP,errorText=<null>,headers=<null>]]
2011-06-29 17:41:11.927 INFO [pool-16-thread-4] Call cleanup [call=SIPCallImpl[SipSessionAdaptor[sessionid=ss_o5try4fdj5ae, appSessionId=sas_2-15-sm1pq3llcc2i3uxtropo2],DISCONNECTED]]
2011-06-29 17:41:11.927 INFO [pool-16-thread-4] Event [EndEvent[callId=b6222f50-99db-4d5c-a925-681f6329517c,reason=HANGUP,errorText=<null>,headers=<null>]]
2011-06-29 17:41:16.476 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[BYE sip:192.168.1.39:5060;transport=udp SIP/2.0\r\nTo: <sip:[email protected]>;tag=19hlty3elx8sn\r\nVia: SIP/2.0/UDP 192.168.1.39:53151;rport;branch=z9hG4bKPjsS6hf13-iDKhP2ydvR4BYVxQjQhTEpqv\r\nCSeq: 17819 BYE\r\nContent-Length: 0\r\nCall-ID: sun5IBsPjyCxX13yDlUw41bTHN8khjYN\r\nUser-Agent: Telephone 1.0.2\r\nFrom: "zhao lu" <sip:[email protected]>;tag=fI18IM2y0Km05GzyFT5XoFkcjipzfnvy\r\nMax-Forwards: 70\r\n\r\n] #[N/A][N/A][sun5IBsPjyCxX13yDlUw41bTHN8khjYN][N/A][sip:[email protected](192.168.1.39:53151)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:16.477 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: The transaction was created: z9hG4bKPjsS6hf13-iDKhP2ydvR4BYVxQjQhTEpqv #[N/A][N/A][sun5IBsPjyCxX13yDlUw41bTHN8khjYN][N/A][sip:[email protected](192.168.1.39:53151)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:16.477 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Cannot found session. #[N/A][N/A][sun5IBsPjyCxX13yDlUw41bTHN8khjYN][N/A][sip:[email protected](192.168.1.39:53151)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:16.478 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (o)[SIP/2.0 481 Cannot found session\r\nTo: <sip:[email protected]>;tag=19hlty3elx8sn\r\nVia: SIP/2.0/UDP 192.168.1.39:53151;rport=53151;branch=z9hG4bKPjsS6hf13-iDKhP2ydvR4BYVxQjQhTEpqv\r\nCSeq: 17819 BYE\r\nContent-Length: 0\r\nCall-ID: sun5IBsPjyCxX13yDlUw41bTHN8khjYN\r\nFrom: "zhao lu" <sip:[email protected]>;tag=fI18IM2y0Km05GzyFT5XoFkcjipzfnvy\r\n\r\n] #[N/A][N/A][sun5IBsPjyCxX13yDlUw41bTHN8khjYN][N/A][sip:[email protected](192.168.1.39:53151)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:16.479 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Send message to: /192.168.1.39:53151 by udp #[N/A][N/A][sun5IBsPjyCxX13yDlUw41bTHN8khjYN][N/A][sip:[email protected](192.168.1.39:53151)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:16.480 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Connected to 192.168.1.39:53151/udp #[N/A][N/A][sun5IBsPjyCxX13yDlUw41bTHN8khjYN][N/A][sip:[email protected](192.168.1.39:53151)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:21.880 DEBUG [Timer-9] #SIP#: NonInviteServerTransaction[_state=COMPLETED, _id=z9hG4bKb5e8.66e47fc7.0] timerRemoveTransaction is fired. #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:21.882 DEBUG [Timer-9] #SIP#: NonInviteServerTransaction[_state=TERMINATED, _id=z9hG4bKb5e8.66e47fc7.0] is released. #[N/A][N/A][17il5m5hl6ckj][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:22.597 DEBUG [Timer-11] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bKaswi55dhtwhg] timerRemoveTransaction is fired. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:22.597 DEBUG [Timer-11] #SIP#: InviteClientTransaction[_state=TERMINATED, _id=z9hG4bKaswi55dhtwhg] is released. #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:22.598 DEBUG [Timer-11] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
2011-06-29 17:41:22.598 DEBUG [Timer-11] #SIP#: processInvalidationWhenReady [ss_125lmu9son68j], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm12rdpnf7serjktropo2][17il5m5hl6ckj][ss_125lmu9son68j][sip:[email protected](213.192.59.75:5060)][sip:[email protected](192.168.1.39:5060)]
2011-06-29 17:41:22.598 DEBUG [Timer-11] #SIP#: processInvalidationWhenReady [sas_2-15-sm12rdpnf7serjktropo2], invalidateWhenReady: true
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment