Skip to content

Instantly share code, notes, and snippets.

@zlu

zlu/sipmethod.log

Created August 15, 2011 15:35
Show Gist options
  • Save zlu/1147017 to your computer and use it in GitHub Desktop.
Save zlu/1147017 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
sipmethod.log
2011-08-15 16:26:54.445 DEBUG [pool-16-thread-30] #MSCTRL#: Add PlayListItem[0, 1, false, rtcs=null, optargs={BARGE_IN_ENABLED=false, BEHAVIOUR_IF_BUSY=QUEUE_IF_BUSY, JUMP_PLAYLIST_INCREMENT=1, PLAYER_FILE_FORMAT=FORMAT_INFERRED, PLAYER_ENABLED_EVENTS=[Ljavax.media.mscontrol.EventType;@1cdcfe5, PLAYER_AUDIO_CODEC=CODEC_INFERRED, PLAYER_START_OFFSET=0, PLAYER_START_PAUSED=false, PLAYER_MAX_DURATION=-1, PLAYER_JUMP_TIME=5000, VOLUME_CHANGE=3, VOICE_NAME=null},"<speak>\n <audio src="http://www.phono.com/audio/troporocks.mp3"/>\n </speak>"]
2011-08-15 16:26:54.445 DEBUG [pool-16-thread-30] #MSCTRL#: Find PlayListItem[IDLE, 0, 1, false]
2011-08-15 16:26:54.446 DEBUG [pool-16-thread-30] #MSCTRL#: Player[IDLE, MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]] starts playing PlayListItem[IDLE, 0, 1, false]
2011-08-15 16:26:54.446 DEBUG [pool-16-thread-30] #MSCTRL#: Player[ACTIVE, MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]] moves state from [IDLE] to [ACTIVE]
2011-08-15 16:26:54.446 DEBUG [pool-16-thread-30] #MSCTRL#: PlayListItem[0, 1] moves state from [IDLE] to [PLAYING]
2011-08-15 16:26:54.446 DEBUG [pool-16-thread-30] #MRCP#: (o)ANNOUNCE rtsp://10.35.132.225:10074/synthesizer/ RTSP/1.0\r\nCseq: 4\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\nContent-Type: application/mrcp\r\nContent-Length: 271\r\n\r\nSPEAK 120001 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: 79\r\n\r\n<speak>\n <audio src="http://www.phono.com/audio/troporocks.mp3"/>\n </speak> #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:26:54.448 DEBUG [mrcp/2-t-24] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\nCseq: 4\r\nContent-Type: application/mrcp\r\nContent-Length: 35\r\n\r\nMRCP/1.0 120001 200 IN-PROGRESS\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:26:54.449 DEBUG [pool-16-thread-30] #MSCTRL#: PlayListItem[0, 1] added (120001, 3456986709-2f61e00-0a3cde20-00000020)
2011-08-15 16:26:54.450 INFO [pool-16-thread-30] Reply [com.tropo.core.verb.VerbRef@39eaa7]
2011-08-15 16:26:54.450 DEBUG [pool-16-thread-30] #XMPP#: (o)<iq type="result" id="blather000d" from="[email protected]" to="[email protected]/voxeo"><ref xmlns="urn:xmpp:rayo:1" id="9556b13a-74e0-4aa1-9e86-6944310b769f"/></iq> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:54.450 DEBUG [pool-16-thread-30] #XMPP#: Send message to: 127.0.0.1:49253 by xmpp #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:54.598 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)<iq type="set" to="[email protected]" id="blather0010" from="[email protected]/voxeo">\n <dial xmlns="urn:xmpp:rayo:1" to="sip:[email protected]" from="sip:[email protected]">\n <join xmlns="urn:xmpp:rayo:join:1" direction="duplex" media="bridge" call-id="5d3fa68c-3772-49dc-a988-db29c650e5bb"/>\n </dial>\n</iq> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:54.598 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo
2011-08-15 16:26:54.598 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][null]
2011-08-15 16:26:54.598 DEBUG [XMPPService-t-40] <iq type="set" to="[email protected]" id="blather0010" from="[email protected]/voxeo">
<dial xmlns="urn:xmpp:rayo:1" to="sip:[email protected]" from="sip:[email protected]">
<join xmlns="urn:xmpp:rayo:join:1" direction="duplex" media="bridge" call-id="5d3fa68c-3772-49dc-a988-db29c650e5bb"/>
</dial>
</iq> :: xmpps_49qm5imqtp20
2011-08-15 16:26:54.599 INFO [pool-16-thread-30] Request [DialCommand[from=sip:[email protected],to=sip:[email protected],headers={},join=JoinCommand[callId=<null>,direction=DUPLEX,media=BRIDGE,to=5d3fa68c-3772-49dc-a988-db29c650e5bb,type=CALL]]]
2011-08-15 16:26:54.604 INFO [pool-16-thread-30] Reply [com.tropo.core.CallRef@17bbfb5]
2011-08-15 16:26:54.604 DEBUG [pool-16-thread-30] #XMPP#: (o)<iq type="result" id="blather0010" from="[email protected]" to="[email protected]/voxeo"><ref xmlns="urn:xmpp:rayo:1" id="e505e96c-91c1-4507-85b2-1483372f1534"/></iq> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:54.604 INFO [pool-16-thread-33] Message [SIPCallImpl[null,INITIALIZED]]
2011-08-15 16:26:54.604 DEBUG [pool-16-thread-30] #XMPP#: Send message to: 127.0.0.1:49253 by xmpp #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:54.606 INFO [MOHO-44] #MSCTRL#: MS[ms2-33] creates a MediaObject[BASIC, nc1, null]
2011-08-15 16:26:54.606 INFO [MOHO-44] #MSCTRL#: SdpPort[IDLE, NC[ms2-33, nc1]] generates a SDP offer
2011-08-15 16:26:54.606 DEBUG [MOHO-44] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-33, nc1]] moves state from [IDLE] to [UNDER_PROCESSING]
2011-08-15 16:26:54.606 DEBUG [msctrl/2-t-23] #MRCP#: load configuration from {maxThreadPool=2147483647, minThreadPool=25, MEDIAOBJECT_ID=nc1, com.voxeo.useLocalConfigurationOnGUTFailures=false}
2011-08-15 16:26:54.613 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)<iq type="set" to="[email protected]" id="blather0012" from="[email protected]/voxeo">\n <dial xmlns="urn:xmpp:rayo:1" to="sip:[email protected]" from="sip:[email protected]">\n <join xmlns="urn:xmpp:rayo:join:1" direction="duplex" media="bridge" call-id="5d3fa68c-3772-49dc-a988-db29c650e5bb"/>\n </dial>\n</iq> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:54.613 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo
2011-08-15 16:26:54.613 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][null]
2011-08-15 16:26:54.614 DEBUG [XMPPService-t-40] <iq type="set" to="[email protected]" id="blather0012" from="[email protected]/voxeo">
<dial xmlns="urn:xmpp:rayo:1" to="sip:[email protected]" from="sip:[email protected]">
<join xmlns="urn:xmpp:rayo:join:1" direction="duplex" media="bridge" call-id="5d3fa68c-3772-49dc-a988-db29c650e5bb"/>
</dial>
</iq> :: xmpps_49qm5imqtp20
2011-08-15 16:26:54.614 INFO [pool-16-thread-33] Request [DialCommand[from=sip:[email protected],to=sip:[email protected],headers={},join=JoinCommand[callId=<null>,direction=DUPLEX,media=BRIDGE,to=5d3fa68c-3772-49dc-a988-db29c650e5bb,type=CALL]]]
2011-08-15 16:26:54.618 INFO [pool-16-thread-33] Reply [com.tropo.core.CallRef@7657e3]
2011-08-15 16:26:54.618 INFO [pool-16-thread-30] Message [SIPCallImpl[null,INITIALIZED]]
2011-08-15 16:26:54.618 DEBUG [pool-16-thread-33] #XMPP#: (o)<iq type="result" id="blather0012" from="[email protected]" to="[email protected]/voxeo"><ref xmlns="urn:xmpp:rayo:1" id="c96db616-d86c-4050-a2af-cd0ba949a69d"/></iq> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:54.618 DEBUG [pool-16-thread-33] #XMPP#: Send message to: 127.0.0.1:49253 by xmpp #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:54.619 DEBUG [msctrl/2-t-23] #MRCP#: (o)SETUP rtsp://10.35.132.225:10074/mixer RTSP/1.0\r\nCseq: 1\r\n\r\n #[N/A][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:26:54.624 INFO [MOHO-47] #MSCTRL#: MS[ms2-34] creates a MediaObject[BASIC, nc1, null]
2011-08-15 16:26:54.624 INFO [MOHO-47] #MSCTRL#: SdpPort[IDLE, NC[ms2-34, nc1]] generates a SDP offer
2011-08-15 16:26:54.624 DEBUG [MOHO-47] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-34, nc1]] moves state from [IDLE] to [UNDER_PROCESSING]
2011-08-15 16:26:54.625 DEBUG [msctrl/2-t-25] #MRCP#: load configuration from {maxThreadPool=2147483647, minThreadPool=25, MEDIAOBJECT_ID=nc1, com.voxeo.useLocalConfigurationOnGUTFailures=false}
2011-08-15 16:26:54.633 DEBUG [mrcp/2-t-24] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\nTransport: RTP/AVP;unicast;client_port=65535-65536;server_port=20064-20065\r\nCseq: 1\r\nContent-Type: application/sdp\r\nContent-Length: 421\r\n\r\nv=0\r\no=- 12 12 IN IP4 10.35.132.225\r\ns=voxeo\r\nc=IN IP4 10.35.132.225\r\nt=0 0\r\nm=audio 20064 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][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:26:54.634 DEBUG [msctrl/2-t-23] #MSCTRL#: NC[ms2-33, nc1] initializes the ASR session. #[3456989327-2a90a00-0a3cde20-00000021]
2011-08-15 16:26:54.634 INFO [msctrl/2-t-23] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-15 16:26:54.634 DEBUG [msctrl/2-t-23] #MSCTRL#: SdpPort[SDP_NEGOTIATING, NC[ms2-33, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATING]
2011-08-15 16:26:54.634 DEBUG [msctrl/2-t-23] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATING, NC[ms2-33, nc1]], OFFER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 12 12 IN IP4 10.35.132.225\r\ns=voxeo\r\nc=IN IP4 10.35.132.225\r\nt=0 0\r\nm=audio 20064 RTP/AVP 0 8 101 115 116 111 9 3 117 112 113\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r\na=rtpmap:115 SPEEX/8000\r\na=rtpmap:116 SPEEX/16000\r\na=rtpmap:111 G726-32/8000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:3 GSM/8000\r\na=rtpmap:117 SPEEX/32000\r\na=rtpmap:112 L16/8000\r\na=rtpmap:113 L16/16000\r\na=ptime:20\r\n] to the application
2011-08-15 16:26:54.635 DEBUG [msctrl/2-t-23] #SIP#: Session creating: ss_kt2a5wfsrrjt #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:54.635 DEBUG [msctrl/2-t-23] #SIP#: SetRoutingDirective: NEW #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:54.636 DEBUG [msctrl/2-t-23] #SIP#: SessionManagementLayer send request: INVITE sip:[email protected] #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:54.636 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://10.35.132.225:10074/mixer RTSP/1.0\r\nCseq: 1\r\n\r\n #[N/A][10.35.132.225:10074][10.35.132.225:49261]
2011-08-15 16:26:54.642 DEBUG [mrcp/2-t-24] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456989346-27f3400-0a3cde20-00000022\r\nTransport: RTP/AVP;unicast;client_port=65535-65536;server_port=20066-20067\r\nCseq: 1\r\nContent-Type: application/sdp\r\nContent-Length: 421\r\n\r\nv=0\r\no=- 11 11 IN IP4 10.35.132.225\r\ns=voxeo\r\nc=IN IP4 10.35.132.225\r\nt=0 0\r\nm=audio 20066 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][10.35.132.225:10074][10.35.132.225:49261]
2011-08-15 16:26:54.642 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-34, nc1] initializes the ASR session. #[3456989346-27f3400-0a3cde20-00000022]
2011-08-15 16:26:54.642 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-15 16:26:54.643 DEBUG [msctrl/2-t-25] #MSCTRL#: SdpPort[SDP_NEGOTIATING, NC[ms2-34, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATING]
2011-08-15 16:26:54.643 DEBUG [msctrl/2-t-25] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATING, NC[ms2-34, nc1]], OFFER_GENERATED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 11 11 IN IP4 10.35.132.225\r\ns=voxeo\r\nc=IN IP4 10.35.132.225\r\nt=0 0\r\nm=audio 20066 RTP/AVP 0 8 101 115 116 111 9 3 117 112 113\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r\na=rtpmap:115 SPEEX/8000\r\na=rtpmap:116 SPEEX/16000\r\na=rtpmap:111 G726-32/8000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:3 GSM/8000\r\na=rtpmap:117 SPEEX/32000\r\na=rtpmap:112 L16/8000\r\na=rtpmap:113 L16/16000\r\na=ptime:20\r\n] to the application
2011-08-15 16:26:54.644 DEBUG [msctrl/2-t-25] #SIP#: Session creating: ss_7p4k2xwnzlvf #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:54.644 DEBUG [msctrl/2-t-25] #SIP#: SetRoutingDirective: NEW #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:54.644 DEBUG [msctrl/2-t-25] #SIP#: SessionManagementLayer send request: INVITE sip:[email protected] #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:54.818 DEBUG [msctrl/2-t-23] #SIP#: The transaction was created: z9hG4bK17pbrolqr28gg #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected]][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:54.819 DEBUG [msctrl/2-t-23] #SIP#: (o)[INVITE sip:[email protected] SIP/2.0\r\nContent-Type: application/sdp\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/TCP 10.35.132.225:5060;branch=z9hG4bK17pbrolqr28gg\r\nCSeq: 1 INVITE\r\nContent-Length: 421\r\nCall-ID: t2jgisxozbar\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=fa7cgtuosm3j\r\nContact: <sip:10.35.132.225:5060;transport=tcp>\r\n\r\nv=0\r\no=- 12 12 IN IP4 10.35.132.225\r\ns=voxeo\r\nc=IN IP4 10.35.132.225\r\nt=0 0\r\nm=audio 20064 RTP/AVP 0 8 101 115 116 111 9 3 117 112 113\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r\na=rtpmap:115 SPEEX/8000\r\na=rtpmap:116 SPEEX/16000\r\na=rtpmap:111 G726-32/8000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:3 GSM/8000\r\na=rtpmap:117 SPEEX/32000\r\na=rtpmap:112 L16/8000\r\na=rtpmap:113 L16/16000\r\na=ptime:20\r\n] #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected]][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:54.834 DEBUG [msctrl/2-t-25] #SIP#: The transaction was created: z9hG4bKueyocnqdck6u #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected]][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:54.834 DEBUG [msctrl/2-t-25] #SIP#: (o)[INVITE sip:[email protected] SIP/2.0\r\nContent-Type: application/sdp\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/TCP 10.35.132.225:5060;branch=z9hG4bKueyocnqdck6u\r\nCSeq: 1 INVITE\r\nContent-Length: 421\r\nCall-ID: 1snq97ug9l00m\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=8pwqzznq9zki\r\nContact: <sip:10.35.132.225:5060;transport=tcp>\r\n\r\nv=0\r\no=- 11 11 IN IP4 10.35.132.225\r\ns=voxeo\r\nc=IN IP4 10.35.132.225\r\nt=0 0\r\nm=audio 20066 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-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected]][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:54.863 DEBUG [msctrl/2-t-23] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected]][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:54.863 DEBUG [msctrl/2-t-23] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:54.872 DEBUG [msctrl/2-t-25] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected]][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:54.873 DEBUG [msctrl/2-t-25] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:54.902 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 100 trying -- your call is important to us\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/TCP 10.35.132.225:5060;branch=z9hG4bK17pbrolqr28gg;rport=65049;received=109.231.200.163\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: t2jgisxozbar\r\nServer: ser (3.2.0-dev2 (i386/linux))\r\nFrom: <sip:[email protected]>;tag=fa7cgtuosm3j\r\nWarning: 392 213.192.59.75:5060 "Noisy feedback tells: pid=19079 req_src_ip=109.231.200.163 req_src_port=65049 in_uri=sip:[email protected] out_uri=sip:[email protected]:51894;transport=tcp via_cnt==1"\r\n\r\n] #[N/A][N/A][t2jgisxozbar][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:26:54.903 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 100/INVITE, branch=z9hG4bK17pbrolqr28gg #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:54.903 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/100 #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:54.903 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-smxrq94xzh9hrltropo2], invalidateWhenReady: true
2011-08-15 16:26:54.903 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_kt2a5wfsrrjt], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:54.903 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-14-smxrq94xzh9hrltropo2], invalidateWhenReady: true
2011-08-15 16:26:54.935 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 100 trying -- your call is important to us\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/TCP 10.35.132.225:5060;branch=z9hG4bKueyocnqdck6u;rport=65049;received=109.231.200.163\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 1snq97ug9l00m\r\nServer: ser (3.2.0-dev2 (i386/linux))\r\nFrom: <sip:[email protected]>;tag=8pwqzznq9zki\r\nWarning: 392 213.192.59.75:5060 "Noisy feedback tells: pid=19079 req_src_ip=109.231.200.163 req_src_port=65049 in_uri=sip:[email protected] out_uri=sip:[email protected]:51183;transport=tcp via_cnt==1"\r\n\r\n] #[N/A][N/A][1snq97ug9l00m][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:26:55.020 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 100/INVITE, branch=z9hG4bKueyocnqdck6u #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:55.021 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/100 #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:55.021 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1tdbhbhllba6mtropo2], invalidateWhenReady: true
2011-08-15 16:26:55.037 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_7p4k2xwnzlvf], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:55.037 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm1tdbhbhllba6mtropo2], invalidateWhenReady: true
2011-08-15 16:26:55.074 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 180 Ringing\r\nTo: <sip:[email protected]>;tag=dbsBhHWv3QwgA2C6eTpyjB-BFm88YkI2\r\nVia: SIP/2.0/TCP 10.35.132.225:5060;rport=65049;received=109.231.200.163;branch=z9hG4bKueyocnqdck6u\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=8pwqzznq9zki;avp=kiQDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODctNGUzYWRjYzQtOTc0NTJmY2U>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 1snq97ug9l00m\r\nServer: Blink Lite 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=8pwqzznq9zki\r\nContact: <sip:[email protected]:55640;transport=tcp>\r\n\r\n] #[N/A][N/A][1snq97ug9l00m][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:26:55.074 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 180/INVITE, branch=z9hG4bKueyocnqdck6u #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:55.075 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/180 #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:55.075 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Add Path[ id=1snq97ug9l00m-dbsBhHWv3QwgA2C6eTpyjB-BFm88YkI2-8pwqzznq9zki, session=SipSessionImpl[_id=ss_7p4k2xwnzlvf, _parentId=sas_2-15-sm1tdbhbhllba6mtropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=1snq97ug9l00m], party= CALLEE] #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:55.076 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:26:55.076 DEBUG [tcp/0.0.0.0/5060-t-12] [SIP/2.0 180 Ringing
To: <sip:[email protected]>;tag=dbsBhHWv3QwgA2C6eTpyjB-BFm88YkI2
Via: SIP/2.0/TCP 10.35.132.225:5060;rport=65049;received=109.231.200.163;branch=z9hG4bKueyocnqdck6u
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Record-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=8pwqzznq9zki;avp=kiQDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODctNGUzYWRjYzQtOTc0NTJmY2U>
CSeq: 1 INVITE
Content-Length: 0
Call-ID: 1snq97ug9l00m
Server: Blink Lite 1.1.1 (MacOSX)
From: <sip:[email protected]>;tag=8pwqzznq9zki
Contact: <sip:[email protected]:55640;transport=tcp>
]
2011-08-15 16:26:55.076 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1tdbhbhllba6mtropo2], invalidateWhenReady: true
2011-08-15 16:26:55.076 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_7p4k2xwnzlvf], current State = EARLY, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:55.077 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm1tdbhbhllba6mtropo2], invalidateWhenReady: true
2011-08-15 16:26:55.083 INFO [pool-16-thread-30] Message [[Event class=com.voxeo.moho.sip.SIPRingEventImpl sourceClass=SIPOutgoingCall]]
2011-08-15 16:26:55.083 INFO [pool-16-thread-30] Queued Event [RingingEvent[callId=c96db616-d86c-4050-a2af-cd0ba949a69d]]
2011-08-15 16:26:55.084 INFO [pool-16-thread-30] Event [RingingEvent[callId=c96db616-d86c-4050-a2af-cd0ba949a69d]]
2011-08-15 16:26:55.085 DEBUG [pool-16-thread-30] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><ringing xmlns="urn:xmpp:rayo:1"/></presence> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:55.085 DEBUG [pool-16-thread-30] #XMPP#: Send message to: 127.0.0.1:49253 by xmpp #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:55.157 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 180 Ringing\r\nTo: <sip:[email protected]>;tag=MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv\r\nVia: SIP/2.0/TCP 10.35.132.225:5060;rport=65049;received=109.231.200.163;branch=z9hG4bK17pbrolqr28gg\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=fa7cgtuosm3j;avp=GzUDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODctNGUzYWRjYzQtOTc0NTJmY2Q>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: t2jgisxozbar\r\nServer: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=fa7cgtuosm3j\r\nContact: <sip:[email protected]:55746;transport=tcp>\r\n\r\n] #[N/A][N/A][t2jgisxozbar][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:26:55.158 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 180/INVITE, branch=z9hG4bK17pbrolqr28gg #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:55.158 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/180 #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:55.162 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Add Path[ id=t2jgisxozbar-MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv-fa7cgtuosm3j, session=SipSessionImpl[_id=ss_kt2a5wfsrrjt, _parentId=sas_2-14-smxrq94xzh9hrltropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=t2jgisxozbar], party= CALLEE] #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:55.163 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:26:55.163 DEBUG [tcp/0.0.0.0/5060-t-12] [SIP/2.0 180 Ringing
To: <sip:[email protected]>;tag=MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv
Via: SIP/2.0/TCP 10.35.132.225:5060;rport=65049;received=109.231.200.163;branch=z9hG4bK17pbrolqr28gg
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Record-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=fa7cgtuosm3j;avp=GzUDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODctNGUzYWRjYzQtOTc0NTJmY2Q>
CSeq: 1 INVITE
Content-Length: 0
Call-ID: t2jgisxozbar
Server: Blink Pro 1.1.1 (MacOSX)
From: <sip:[email protected]>;tag=fa7cgtuosm3j
Contact: <sip:[email protected]:55746;transport=tcp>
]
2011-08-15 16:26:55.166 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-smxrq94xzh9hrltropo2], invalidateWhenReady: true
2011-08-15 16:26:55.166 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_kt2a5wfsrrjt], current State = EARLY, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:55.166 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-14-smxrq94xzh9hrltropo2], invalidateWhenReady: true
2011-08-15 16:26:55.170 INFO [pool-16-thread-30] Message [[Event class=com.voxeo.moho.sip.SIPRingEventImpl sourceClass=SIPOutgoingCall]]
2011-08-15 16:26:55.170 INFO [pool-16-thread-30] Queued Event [RingingEvent[callId=e505e96c-91c1-4507-85b2-1483372f1534]]
2011-08-15 16:26:55.170 INFO [pool-16-thread-30] Event [RingingEvent[callId=e505e96c-91c1-4507-85b2-1483372f1534]]
2011-08-15 16:26:55.171 DEBUG [pool-16-thread-30] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><ringing xmlns="urn:xmpp:rayo:1"/></presence> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:55.171 DEBUG [pool-16-thread-30] #XMPP#: Send message to: 127.0.0.1:49253 by xmpp #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:57.244 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 200 OK\r\nContent-Type: application/sdp\r\nTo: <sip:[email protected]>;tag=MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv\r\nVia: SIP/2.0/TCP 10.35.132.225:5060;rport=65049;received=109.231.200.163;branch=z9hG4bK17pbrolqr28gg\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=fa7cgtuosm3j;avp=GzUDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODctNGUzYWRjYzQtOTc0NTJmY2Q>\r\nCSeq: 1 INVITE\r\nContent-Length: 241\r\nSupported: 100rel, norefersub\r\nCall-ID: t2jgisxozbar\r\nServer: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=fa7cgtuosm3j\r\nContact: <sip:[email protected]:55746;transport=tcp>\r\n\r\nv=0\r\no=- 3522410817 3522410818 IN IP4 10.35.132.225\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 13148 RTP/AVP 0 101\r\na=rtcp:50055\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n] #[N/A][N/A][t2jgisxozbar][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:26:57.245 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 200/INVITE, branch=z9hG4bK17pbrolqr28gg #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.246 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/200 #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.246 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:26:57.246 DEBUG [tcp/0.0.0.0/5060-t-12] [SIP/2.0 200 OK
Content-Type: application/sdp
To: <sip:[email protected]>;tag=MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv
Via: SIP/2.0/TCP 10.35.132.225:5060;rport=65049;received=109.231.200.163;branch=z9hG4bK17pbrolqr28gg
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Record-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=fa7cgtuosm3j;avp=GzUDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODctNGUzYWRjYzQtOTc0NTJmY2Q>
CSeq: 1 INVITE
Content-Length: 241
Supported: 100rel, norefersub
Call-ID: t2jgisxozbar
Server: Blink Pro 1.1.1 (MacOSX)
From: <sip:[email protected]>;tag=fa7cgtuosm3j
Contact: <sip:[email protected]:55746;transport=tcp>
v=0
o=- 3522410817 3522410818 IN IP4 10.35.132.225
s=Blink Pro 1.1.1 (MacOSX)
c=IN IP4 213.192.59.91
t=0 0
m=audio 13148 RTP/AVP 0 101
a=rtcp:50055
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
]
2011-08-15 16:26:57.251 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer send request: ACK sip:[email protected]:55746;transport=tcp #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:57.252 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (o)[ACK sip:[email protected]:55746;transport=tcp SIP/2.0\r\nTo: <sip:[email protected]>;tag=MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv\r\nVia: SIP/2.0/TCP 10.35.132.225:5060;branch=z9hG4bK1mr5nd6uil62u;x-sm-sid=b3d52dee-c1d2-40d9-9a8a-85cc4c67be5d;x-sm-nid=ss_kt2a5wfsrrjt\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nRoute: <sip:213.192.59.75;transport=tcp;lr;ftag=fa7cgtuosm3j;avp=GzUDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODctNGUzYWRjYzQtOTc0NTJmY2Q>\r\nCall-ID: t2jgisxozbar\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=fa7cgtuosm3j\r\n\r\n] #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected]][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.252 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Send message to: /213.192.59.75:5060 by tcp #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected]][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.258 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.259 INFO [tcp/0.0.0.0/5060-t-12] #MSCTRL#: SdpPort[SDP_NEGOTIATING, NC[ms2-33, nc1]] processes a SDP answer \nv=0\r\no=- 3522410817 3522410818 IN IP4 10.35.132.225\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 13148 RTP/AVP 0 101\r\na=rtcp:50055\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n
2011-08-15 16:26:57.259 DEBUG [tcp/0.0.0.0/5060-t-12] #MSCTRL#: SdpPort[UNDER_PROCESSING, NC[ms2-33, nc1]] moves state from [SDP_NEGOTIATING] to [UNDER_PROCESSING]
2011-08-15 16:26:57.261 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-15 16:26:57.261 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-smxrq94xzh9hrltropo2], invalidateWhenReady: true
2011-08-15 16:26:57.262 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_kt2a5wfsrrjt], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.268 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-14-smxrq94xzh9hrltropo2], invalidateWhenReady: true
2011-08-15 16:26:57.268 INFO [pool-16-thread-30] Message [[Event class=com.voxeo.moho.sip.SIPAnsweredEventImpl sourceClass=SIPOutgoingCall]]
2011-08-15 16:26:57.268 INFO [pool-16-thread-30] Queued Event [AnsweredEvent[callId=e505e96c-91c1-4507-85b2-1483372f1534]]
2011-08-15 16:26:57.268 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://10.35.132.225:10074/mixer RTSP/1.0\r\nCseq: 2\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\nContent-Type: application/sdp\r\nContent-Length: 241\r\n\r\nv=0\r\no=- 3522410817 3522410818 IN IP4 10.35.132.225\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 13148 RTP/AVP 0 101\r\na=rtcp:50055\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:26:57.268 INFO [pool-16-thread-30] Event [AnsweredEvent[callId=e505e96c-91c1-4507-85b2-1483372f1534]]
2011-08-15 16:26:57.269 DEBUG [pool-16-thread-30] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><answered xmlns="urn:xmpp:rayo:1"/></presence> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:57.269 DEBUG [pool-16-thread-30] #XMPP#: Send message to: 127.0.0.1:49253 by xmpp #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:57.275 DEBUG [mrcp/2-t-24] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\nCseq: 2\r\nContent-Type: application/sdp\r\nContent-Length: 179\r\n\r\nv=0\r\no=- 2662 2662 IN IP4 10.35.132.225\r\ns=voxeo\r\nc=IN IP4 10.35.132.225\r\nt=0 0\r\nm=audio 20064 RTP/AVP 0 101\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=ptime:20\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:26:57.275 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://10.35.132.225:10074/recognizer/ RTSP/1.0\r\nCseq: 3\r\nTransport: RTP/AVP;unicast;\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\nContent-Type: application/sdp\r\nContent-Length: 241\r\n\r\nv=0\r\no=- 3522410817 3522410818 IN IP4 10.35.132.225\r\ns=Blink Pro 1.1.1 (MacOSX)\r\nc=IN IP4 213.192.59.91\r\nt=0 0\r\nm=audio 13148 RTP/AVP 0 101\r\na=rtcp:50055\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:26:57.281 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)<iq type="set" to="[email protected]" id="blather0014" from="[email protected]/voxeo">\n <hangup xmlns="urn:xmpp:rayo:1"/>\n</iq> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:57.282 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo
2011-08-15 16:26:57.283 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][null]
2011-08-15 16:26:57.283 DEBUG [XMPPService-t-40] <iq type="set" to="[email protected]" id="blather0014" from="[email protected]/voxeo">
<hangup xmlns="urn:xmpp:rayo:1"/>
</iq> :: xmpps_49qm5imqtp20
2011-08-15 16:26:57.284 INFO [pool-16-thread-30] Request [HangupCommand[callId=c96db616-d86c-4050-a2af-cd0ba949a69d,headers={}]]
2011-08-15 16:26:57.284 DEBUG [pool-16-thread-30] destroyNetworkConnection
2011-08-15 16:26:57.284 DEBUG [pool-16-thread-30] #MSCTRL#: NC[ms2-34, nc1] moves state from [INITIALIZED] to [RELEASED]
2011-08-15 16:26:57.285 INFO [pool-16-thread-30] #MSCTRL#: MS[ms2-34] removes a MediaObject[mscontrol://10.35.132.225:10074/ms2-34/nc1]
2011-08-15 16:26:57.286 DEBUG [pool-16-thread-30] #MRCP#: (o)TEARDOWN rtsp://10.35.132.225:10074/mixer RTSP/1.0\r\nCseq: 2\r\nSession: 3456989346-27f3400-0a3cde20-00000022\r\n\r\n #[3456989346-27f3400-0a3cde20-00000022][10.35.132.225:10074][10.35.132.225:49261]
2011-08-15 16:26:57.289 DEBUG [mrcp/2-t-24] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\nTransport: RTP/AVP;unicast;client_port=13148-13149;server_port=20064-20065\r\nCseq: 3\r\n\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:26:57.289 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-33, nc1] updates the ASR session. #[3456989327-2a90a00-0a3cde20-00000021]
2011-08-15 16:26:57.289 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456989346-27f3400-0a3cde20-00000022\r\nCseq: 2\r\n\r\n #[3456989346-27f3400-0a3cde20-00000022][10.35.132.225:10074][10.35.132.225:49261]
2011-08-15 16:26:57.289 DEBUG [msctrl/2-t-25] #MRCP#: (o)SETUP rtsp://10.35.132.225:10074/synthesizer/ RTSP/1.0\r\nCseq: 4\r\nTransport: RTP/AVP;unicast;\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\n\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:26:57.295 DEBUG [pool-16-thread-30] #MSCTRL#: MS[ms2-34] moves state from [INITIALIZED] to [RELEASED]
2011-08-15 16:26:57.295 DEBUG [pool-16-thread-30] terminating call. Notifying joinDelegate conditaion. callID:1snq97ug9l00m
2011-08-15 16:26:57.307 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\nTransport: RTP/AVP;unicast;client_port=13148-13149;server_port=20064-20065\r\nCseq: 4\r\n\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:26:57.307 DEBUG [msctrl/2-t-25] #MSCTRL#: NC[ms2-33, nc1] updates the TTS session. #[3456989327-2a90a00-0a3cde20-00000021]
2011-08-15 16:26:57.309 INFO [msctrl/2-t-25] #MSCTRL#: No CodecPolicy is installed, just return back the initial offer
2011-08-15 16:26:57.309 DEBUG [msctrl/2-t-25] #MSCTRL#: SdpPort[SDP_NEGOTIATED, NC[ms2-33, nc1]] moves state from [UNDER_PROCESSING] to [SDP_NEGOTIATED]
2011-08-15 16:26:57.309 DEBUG [msctrl/2-t-25] #MSCTRL#: Return SdpPortEvt[SdpPort[SDP_NEGOTIATED, NC[ms2-33, nc1]], ANSWER_PROCESSED, NO_ERROR, null, NO_QUALIFIER, null, v=0\r\no=- 12 12 IN IP4 10.35.132.225\r\ns=voxeo\r\nc=IN IP4 10.35.132.225\r\nt=0 0\r\nm=audio 20064 RTP/AVP 0 8 101 115 116 111 9 3 117 112 113\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r\na=rtpmap:115 SPEEX/8000\r\na=rtpmap:116 SPEEX/16000\r\na=rtpmap:111 G726-32/8000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:3 GSM/8000\r\na=rtpmap:117 SPEEX/32000\r\na=rtpmap:112 L16/8000\r\na=rtpmap:113 L16/16000\r\na=ptime:20\r\n] to the application
2011-08-15 16:26:57.309 INFO [MOHO-44] #MSCTRL#: NC[ms2-33, nc1] joins to NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] in DUPLEX
2011-08-15 16:26:57.310 DEBUG [MOHO-44] #MSCTRL#: NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] rejoins to MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] in SEND
2011-08-15 16:26:57.310 INFO [MOHO-44] #MSCTRL#: NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] unjoins from MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]
2011-08-15 16:26:57.310 DEBUG [MOHO-44] #MSCTRL#: Stopping Player[ACTIVE, MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]], isStopAll:true
2011-08-15 16:26:57.312 DEBUG [pool-16-thread-30] #SIP#: SessionManagementLayer send request: CANCEL sip:[email protected] #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:57.313 DEBUG [pool-16-thread-30] #SIP#: The transaction was created: z9hG4bKueyocnqdck6uCANCEL #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:57.313 DEBUG [pool-16-thread-30] #SIP#: (o)[CANCEL sip:[email protected] SIP/2.0\r\nTo: sip:[email protected]\r\nVia: SIP/2.0/TCP 10.35.132.225:5060;branch=z9hG4bKueyocnqdck6u\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 1snq97ug9l00m\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=8pwqzznq9zki\r\n\r\n] #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:57.325 DEBUG [MOHO-44] #MSCTRL#: Find PlayListItem[PLAYING, 0, 1, false, speakIds=[120001]]
2011-08-15 16:26:57.325 DEBUG [MOHO-44] #MSCTRL#: Stopping PlayListItem[PLAYING, 0, 1, false, speakIds=[120001]]
2011-08-15 16:26:57.325 DEBUG [MOHO-44] #MRCP#: (o)ANNOUNCE rtsp://10.35.132.225:10074/synthesizer/ RTSP/1.0\r\nCseq: 5\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\nContent-Type: application/mrcp\r\nContent-Length: 56\r\n\r\nSTOP 120002 MRCP/1.0\r\nActive-Request-Id-List: 120001\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:26:57.338 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\nCseq: 5\r\nContent-Type: application/mrcp\r\nContent-Length: 64\r\n\r\nMRCP/1.0 120002 200 COMPLETE\r\nactive-request-id-list: 120001\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:26:57.348 DEBUG [MOHO-44] #MSCTRL#: Player[STOPPED[STOPPED], MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]] moves state from [ACTIVE] to [STOPPED[STOPPED]]
2011-08-15 16:26:57.348 DEBUG [MOHO-44] #MSCTRL#: MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] removes JoineeMrcpContext[mscontrol://10.35.132.225:10074/MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe/NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, 3456986709-2f61e00-0a3cde20-00000020, 3456986709-2f61e00-0a3cde20-00000020] #[3456986709-2f61e00-0a3cde20-00000020]
2011-08-15 16:26:57.348 DEBUG [MOHO-44] #MSCTRL#: MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] removed MrcpSpeakListener[Player[STOPPED[STOPPED], MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]], ACTIVE] #[3456986709-2f61e00-0a3cde20-00000020]
2011-08-15 16:26:57.348 DEBUG [MOHO-44] #MSCTRL#: NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] removes(MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-08-15 16:26:57.349 DEBUG [MOHO-44] #MSCTRL#: MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] removes(NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-08-15 16:26:57.349 INFO [MOHO-44] #MSCTRL#: NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] joins to MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] in SEND
2011-08-15 16:26:57.349 DEBUG [MOHO-44] #MSCTRL#: MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] adds JoineeMrcpContext[mscontrol://10.35.132.225:10074/MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe/NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, 3456986709-2f61e00-0a3cde20-00000020, 3456986709-2f61e00-0a3cde20-00000020] #[3456986709-2f61e00-0a3cde20-00000020]
2011-08-15 16:26:57.349 DEBUG [MOHO-44] #MSCTRL#: NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] adds(MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe], JoineeContext[RESOURCE_CONTAINER, SEND, null])
2011-08-15 16:26:57.349 DEBUG [MOHO-44] #MSCTRL#: MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] adds(NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe], JoineeContext[RESOURCE_CONTAINER, RECV, null])
2011-08-15 16:26:57.350 DEBUG [MOHO-44] #MRCP#: (o)ANNOUNCE rtsp://10.35.132.225:10074/mixer RTSP/1.0\r\nCseq: 5\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\nContent-Type: application/mrcp\r\nContent-Length: 202\r\n\r\nVOXEO-JOIN 40000 MRCP/1.0\r\nVendor-Specific-Parameters: Voxeo-Join-DTMF-Passthrough=true;Voxeo-Join-Listen-Only=false;Voxeo-Join-Talk-Only=false\r\nX-Voxeo-Join-ID: 3456986709-2f61e00-0a3cde20-00000020\r\n\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:26:57.348 DEBUG [mrcp/2-t-25] #MRCP#: Handling SPEAK-COMPLETE[120001] #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:26:57.350 DEBUG [mrcp/2-t-25] #MSCTRL#: Remove MrcpSpeakListener[Player[STOPPED[STOPPED], MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]], INVALID] #[3456986709-2f61e00-0a3cde20-00000020]
2011-08-15 16:26:57.350 DEBUG [mrcp/2-t-25] #MSCTRL#: Find PlayListItem[PLAYING, 0, 1, false, speakIds=[120001]]
2011-08-15 16:26:57.351 DEBUG [mrcp/2-t-25] #MSCTRL#: MrcpSpeakListener[Player[STOPPED[STOPPED], MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]], INVALID] handling with MrcpSpeakCompleteEvent[originalId:120001, requestId:120001, rc:0, duration:2905] #[3456986709-2f61e00-0a3cde20-00000020]
2011-08-15 16:26:57.351 DEBUG [mrcp/2-t-25] #MSCTRL#: PlayListItem[0, 1] removed (120001, 3456986709-2f61e00-0a3cde20-00000020)
2011-08-15 16:26:57.351 DEBUG [mrcp/2-t-25] #MSCTRL#: PlayListItem[0, 1] moves state from [PLAYING] to [IDLE]
2011-08-15 16:26:57.352 DEBUG [mrcp/2-t-25] #MSCTRL#: Player[IDLE, MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]] moves state from [STOPPED[STOPPED]] to [IDLE]
2011-08-15 16:26:57.352 DEBUG [mrcp/2-t-25] #MSCTRL#: clear up playList=[PlayListItem[IDLE, 0, 1, false]]
2011-08-15 16:26:57.352 DEBUG [mrcp/2-t-25] #MSCTRL#: Return PlayerEvent[Player[IDLE, MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]], PLAY_COMPLETED, NO_ERROR, null, STOPPED, null, null, 0, 2905] to the application
2011-08-15 16:26:57.353 INFO [pool-16-thread-33] Message [[Event class=com.voxeo.moho.event.MohoOutputCompleteEvent sourceClass=SIPIncomingCall]]
2011-08-15 16:26:57.353 INFO [pool-16-thread-33] Queued Event [SayCompleteEvent[callId=5d3fa68c-3772-49dc-a988-db29c650e5bb,verbId=9556b13a-74e0-4aa1-9e86-6944310b769f,reason=STOP,errorText=<null>]]
2011-08-15 16:26:57.353 INFO [pool-16-thread-33] Event [SayCompleteEvent[callId=5d3fa68c-3772-49dc-a988-db29c650e5bb,verbId=9556b13a-74e0-4aa1-9e86-6944310b769f,reason=STOP,errorText=<null>]]
2011-08-15 16:26:57.354 DEBUG [pool-16-thread-33] #XMPP#: (o)<presence from="[email protected]/9556b13a-74e0-4aa1-9e86-6944310b769f" to="[email protected]/voxeo"><complete xmlns="urn:xmpp:rayo:ext:1"><stop xmlns="urn:xmpp:rayo:ext:complete:1"/></complete></presence> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:57.354 DEBUG [pool-16-thread-33] #XMPP#: Send message to: 127.0.0.1:49253 by xmpp #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:57.358 DEBUG [pool-16-thread-30] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:57.359 DEBUG [pool-16-thread-30] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected]]
2011-08-15 16:26:57.359 INFO [pool-16-thread-30] Reply [null]
2011-08-15 16:26:57.360 DEBUG [pool-16-thread-30] #XMPP#: (o)<iq type="result" id="blather0014" from="[email protected]" to="[email protected]/voxeo"/> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:57.360 DEBUG [pool-16-thread-30] #XMPP#: Send message to: 127.0.0.1:49253 by xmpp #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:57.361 INFO [pool-16-thread-30] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPIncomingCall]]
2011-08-15 16:26:57.361 INFO [pool-16-thread-33] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-15 16:26:57.361 INFO [pool-16-thread-33] Message [[Event class=com.voxeo.moho.event.MohoCallCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-15 16:26:57.361 INFO [pool-16-thread-33] Queued Event [EndEvent[callId=c96db616-d86c-4050-a2af-cd0ba949a69d,reason=ERROR,errorText=<null>,headers=<null>]]
2011-08-15 16:26:57.362 INFO [pool-16-thread-33] Call cleanup [call=SIPCallImpl[SipSessionAdaptor[sessionid=ss_7p4k2xwnzlvf, appSessionId=sas_2-15-sm1tdbhbhllba6mtropo2],DISCONNECTED]]
2011-08-15 16:26:57.368 INFO [pool-16-thread-33] Event [EndEvent[callId=c96db616-d86c-4050-a2af-cd0ba949a69d,reason=ERROR,errorText=<null>,headers=<null>]]
2011-08-15 16:26:57.369 DEBUG [pool-16-thread-33] #XMPP#: (o)<presence from="[email protected]" to="[email protected]/voxeo"><end xmlns="urn:xmpp:rayo:1"><error/></end></presence> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:57.369 DEBUG [pool-16-thread-33] #XMPP#: Send message to: 127.0.0.1:49253 by xmpp #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:57.374 DEBUG [SocketAcceptorIoProcessor-0.0] #CONNECTOR#: NIOTCPOutgoingConnection[/127.0.0.1:5222-->/127.0.0.1:49253] is closed.
2011-08-15 16:26:57.377 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\nCseq: 5\r\nContent-Type: application/mrcp\r\nContent-Length: 34\r\n\r\nMRCP/1.0 40000 200 IN-PROGRESS\r\n\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:26:57.377 ERROR [SocketAcceptorIoProcessor-0.0] #CONNECTOR#: XMPPTcpConnector[/0.0.0.0] can not found ClientConnection: /127.0.0.1:49253 srcPort: 5222
2011-08-15 16:26:57.377 DEBUG [SocketAcceptorIoProcessor-0.0] #CONNECTOR#: NIOTCPIncomingConnection[/127.0.0.1:49253-->/127.0.0.1:5222] is closed.
2011-08-15 16:26:57.378 DEBUG [SocketAcceptorIoProcessor-0.0] #XMPP#: (i)</stream:stream> #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][N/A]
2011-08-15 16:26:57.379 DEBUG [MOHO-44] #MRCP#: (o)SETUP rtsp://10.35.132.225:10074/mixer RTSP/1.0\r\nCseq: 6\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:26:57.386 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\nTransport: RTP/AVP;unicast;client_port=4000-4001;server_port=20062-20063\r\nCseq: 6\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:26:57.388 DEBUG [MOHO-44] #MRCP#: (o)ANNOUNCE rtsp://10.35.132.225:10074/mixer RTSP/1.0\r\nCseq: 7\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\nContent-Type: application/mrcp\r\nContent-Length: 203\r\n\r\nVOXEO-JOIN 120003 MRCP/1.0\r\nVendor-Specific-Parameters: Voxeo-Join-DTMF-Passthrough=true;Voxeo-Join-Listen-Only=false;Voxeo-Join-Talk-Only=false\r\nX-Voxeo-Join-ID: 3456989327-2a90a00-0a3cde20-00000021\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:26:57.397 DEBUG [XMPPService-t-40] #XMPP#: XMPPSessionImpl: _id=xmpps_49qm5imqtp20, _direction=RECEIVEStream, _sessionType=CLIENT, [email protected]/voxeo, _state=TERMINATED, _remoteAddr=/127.0.0.1, _remotePort=49253, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo2-0, _state=STARTED] is invalidating. (s) #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][null]
2011-08-15 16:26:57.402 DEBUG [XMPPService-t-40] #XMPP#: Close underlizing connection for session:XMPPSessionImpl: _id=xmpps_49qm5imqtp20, _direction=RECEIVEStream, _sessionType=CLIENT, [email protected]/voxeo, _state=TERMINATED, _remoteAddr=/127.0.0.1, _remotePort=49253, _localPort=5222, _localJID=127.0.0.1, _application=ApplicationImpl[_symbolicName=tropo2-0, _state=STARTED]
2011-08-15 16:26:57.403 DEBUG [XMPPService-t-40] #XMPP#: Invoke application:tropo2 rayo
2011-08-15 16:26:57.411 DEBUG [XMPPService-t-40] #XMPP#: Forwarding Request #[tropo2][null][xmpps_49qm5imqtp20][[email protected]/voxeo, 127.0.0.1][127.0.0.1:49253][127.0.0.1:5222][xmpp][null]
2011-08-15 16:26:57.415 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 200 canceling\r\nTo: sip:[email protected];tag=ab7f724f44d6a86dac492bd71f480906-ca8c\r\nVia: SIP/2.0/TCP 10.35.132.225:5060;branch=z9hG4bKueyocnqdck6u;rport=65049;received=109.231.200.163\r\nCSeq: 1 CANCEL\r\nContent-Length: 0\r\nCall-ID: 1snq97ug9l00m\r\nServer: ser (3.2.0-dev2 (i386/linux))\r\nFrom: <sip:[email protected]>;tag=8pwqzznq9zki\r\nWarning: 392 213.192.59.75:5060 "Noisy feedback tells: pid=19079 req_src_ip=109.231.200.163 req_src_port=65049 in_uri=sip:[email protected] out_uri=sip:[email protected] via_cnt==1"\r\n\r\n] #[N/A][N/A][1snq97ug9l00m][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:26:57.416 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 200/CANCEL, branch=z9hG4bKueyocnqdck6u #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected]]
2011-08-15 16:26:57.422 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: NonInviteClientTransaction[_state=TERMINATED, _id=z9hG4bKueyocnqdck6uCANCEL] is released. #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected]]
2011-08-15 16:26:57.423 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1tdbhbhllba6mtropo2], invalidateWhenReady: true
2011-08-15 16:26:57.423 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_7p4k2xwnzlvf], current State = EARLY, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.423 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm1tdbhbhllba6mtropo2], invalidateWhenReady: true
2011-08-15 16:26:57.490 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[SIP/2.0 487 Request Terminated\r\nTo: <sip:[email protected]>;tag=dbsBhHWv3QwgA2C6eTpyjB-BFm88YkI2\r\nVia: SIP/2.0/TCP 10.35.132.225:5060;rport=65049;received=109.231.200.163;branch=z9hG4bKueyocnqdck6u\r\nAllow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;lr;ftag=8pwqzznq9zki;avp=kiQDBwBhY2NvdW50AwB5ZXMDBgBzdGltZXIEADE4MDADCQBkaWFsb2dfaWQWADRhODctNGUzYWRjYzQtOTc0NTJmY2U>\r\nCSeq: 1 INVITE\r\nContent-Length: 0\r\nCall-ID: 1snq97ug9l00m\r\nServer: Blink Lite 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=8pwqzznq9zki\r\n\r\n] #[N/A][N/A][1snq97ug9l00m][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:26:57.491 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Receive 487/INVITE, branch=z9hG4bKueyocnqdck6u #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.492 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (o)[ACK sip:[email protected] SIP/2.0\r\nTo: <sip:[email protected]>;tag=dbsBhHWv3QwgA2C6eTpyjB-BFm88YkI2\r\nVia: SIP/2.0/TCP 10.35.132.225:5060;branch=z9hG4bKueyocnqdck6u\r\nCSeq: 1 ACK\r\nContent-Length: 0\r\nCall-ID: 1snq97ug9l00m\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=8pwqzznq9zki\r\n\r\n] #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:57.506 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\nCseq: 7\r\nContent-Type: application/mrcp\r\nContent-Length: 35\r\n\r\nMRCP/1.0 120003 200 IN-PROGRESS\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:26:57.521 DEBUG [MOHO-44] #MSCTRL#: NC[ms2-33, nc1] adds(NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-08-15 16:26:57.521 DEBUG [MOHO-44] #MSCTRL#: NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] adds(NC[ms2-33, nc1], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-08-15 16:26:57.522 INFO [pool-16-thread-33] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-15 16:26:57.522 INFO [pool-16-thread-30] Message [[Event class=com.voxeo.moho.event.MohoJoinCompleteEvent sourceClass=SIPIncomingCall]]
2011-08-15 16:26:57.522 INFO [pool-16-thread-30] Queued Event [JoinedEvent[callId=5d3fa68c-3772-49dc-a988-db29c650e5bb,to=e505e96c-91c1-4507-85b2-1483372f1534,type=CALL]]
2011-08-15 16:26:57.523 INFO [pool-16-thread-30] Event [JoinedEvent[callId=5d3fa68c-3772-49dc-a988-db29c650e5bb,to=e505e96c-91c1-4507-85b2-1483372f1534,type=CALL]]
2011-08-15 16:26:57.543 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected]][sip:[email protected]]
2011-08-15 16:26:57.554 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Connected to 213.192.59.75:5060/tcp #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected]]
2011-08-15 16:26:57.558 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: InviteClientTransaction[_state=TERMINATED, _id=z9hG4bKueyocnqdck6u] is released. #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.558 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1tdbhbhllba6mtropo2], invalidateWhenReady: true
2011-08-15 16:26:57.558 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_7p4k2xwnzlvf], current State = EARLY, Vaild:true, Role:UAC, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.558 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm1tdbhbhllba6mtropo2], invalidateWhenReady: true
2011-08-15 16:26:57.559 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv response: INVITE/487 #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.559 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:26:57.559 DEBUG [tcp/0.0.0.0/5060-t-12] SIPCallImpl[SipSessionAdaptor[sessionid=ss_7p4k2xwnzlvf, appSessionId=sas_2-15-sm1tdbhbhllba6mtropo2],DISCONNECTED] is already terminated.
2011-08-15 16:26:57.559 INFO [MOHO-48] Actor CallActor is disposed. Ignoring message. [[Event class=com.voxeo.moho.sip.SIPDeniedEventImpl sourceClass=SIPOutgoingCall]]
2011-08-15 16:26:57.562 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1tdbhbhllba6mtropo2], invalidateWhenReady: true
2011-08-15 16:26:57.562 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_7p4k2xwnzlvf], current State = INITIAL, Vaild:true, Role:UAC, hasOngoingTransaction: false, OT: 0, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.563 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: server will automatically invalidate sipsession [ss_7p4k2xwnzlvf] #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.566 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipSessionImpl[_id=ss_7p4k2xwnzlvf, _parentId=sas_2-15-sm1tdbhbhllba6mtropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=1snq97ug9l00m] is invalidating. (s) #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.567 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Remove Path[ id=1snq97ug9l00m-dbsBhHWv3QwgA2C6eTpyjB-BFm88YkI2-8pwqzznq9zki, session=SipSessionImpl[_id=ss_7p4k2xwnzlvf, _parentId=sas_2-15-sm1tdbhbhllba6mtropo2, _handler=Controller, _state=INITIAL, _fresh=false, _valid=true, _unavailable=true, _role=UAC, _method=INVITE, _callId=1snq97ug9l00m]] #[tropo2][sas_2-15-sm1tdbhbhllba6mtropo2][1snq97ug9l00m][ss_7p4k2xwnzlvf][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:26:57.567 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-15-sm1tdbhbhllba6mtropo2], invalidateWhenReady: true
2011-08-15 16:26:57.567 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-15-sm1tdbhbhllba6mtropo2]
2011-08-15 16:26:57.568 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-15-sm1tdbhbhllba6mtropo2] is invalidating. (as)
2011-08-15 16:26:59.344 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:27:07.988 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: (i)[BYE sip:109.231.200.163:65049;transport=tcp SIP/2.0\r\nTo: <sip:[email protected]>;tag=fa7cgtuosm3j\r\nVia: SIP/2.0/TCP 213.192.59.75;branch=z9hG4bK8e68.ba43a777.0;i=f107\r\nVia: SIP/2.0/tcp 10.35.132.225:55746;received=109.231.200.163;rport=55746;branch=z9hG4bKPjgm.eywwSjgkmLY0dw.elFWbJFRAQe0s-\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;ftag=MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv;avp=TnIDCQBkaWFsb2dfaWQWADRhODctNGUzYWRjYzQtOTc0NTJmY2QTCQBkaWFsb2dfaWQWADRhODctNGUzYWRjYzQtOTc0NTJmY2QTBgBzdGltZXIEADE4MDATBwBhY2NvdW50AwB5ZXM;lr=on>\r\nCSeq: 13203 BYE\r\nContent-Length: 0\r\nCall-ID: t2jgisxozbar\r\nP-hint: rr-enforced\r\nUser-Agent: Blink Pro 1.1.1 (MacOSX)\r\nFrom: <sip:[email protected]>;tag=MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv\r\nMax-Forwards: 16\r\n\r\n] #[N/A][N/A][t2jgisxozbar][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:27:07.989 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: The transaction was created: z9hG4bK8e68.ba43a777.0 #[N/A][N/A][t2jgisxozbar][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:27:07.990 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: Find Path[ id=t2jgisxozbar-MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv-fa7cgtuosm3j, path=ApplicationPath[_id=t2jgisxozbar-MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv-fa7cgtuosm3j, _nodes=ApplicationPathList[_nodes=[ApplicationPathNode[_sipSession=SipSessionAdaptor[sessionid=ss_kt2a5wfsrrjt, appSessionId=sas_2-14-smxrq94xzh9hrltropo2]]]]]] #[N/A][N/A][t2jgisxozbar][N/A][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:27:07.990 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SessionManagementLayer recv request: BYE #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:27:07.990 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ApplicationDispatchLayer invoke application: Controller with BYE #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:27:07.990 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:27:07.991 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-smxrq94xzh9hrltropo2], invalidateWhenReady: true
2011-08-15 16:27:07.991 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [ss_kt2a5wfsrrjt], current State = CONFIRMED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:07.991 DEBUG [tcp/0.0.0.0/5060-t-12] #SIP#: processInvalidationWhenReady [sas_2-14-smxrq94xzh9hrltropo2], invalidateWhenReady: true
2011-08-15 16:27:07.991 DEBUG [MOHO-48] destroyNetworkConnection
2011-08-15 16:27:07.991 DEBUG [MOHO-48] #MSCTRL#: NC[ms2-33, nc1] moves state from [INITIALIZED] to [RELEASED]
2011-08-15 16:27:07.994 INFO [MOHO-48] #MSCTRL#: MS[ms2-33] removes a MediaObject[mscontrol://10.35.132.225:10074/ms2-33/nc1]
2011-08-15 16:27:07.994 DEBUG [MOHO-48] #MRCP#: (o)TEARDOWN rtsp://10.35.132.225:10074/mixer RTSP/1.0\r\nCseq: 8\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:27:07.995 INFO [pool-16-thread-30] Message [[Event class=com.voxeo.moho.sip.SIPHangupEventImpl sourceClass=SIPOutgoingCall]]
2011-08-15 16:27:07.995 INFO [pool-16-thread-30] Call is disconnecting. Unjoining peer [SIPCallImpl[SipSessionAdaptor[sessionid=ss_3047vtqjj42c, appSessionId=sas_2-14-smlus4kfx9rsjwtropo2],ANSWERED]]
2011-08-15 16:27:08.009 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\nCseq: 8\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:27:08.010 DEBUG [MOHO-48] #MRCP#: (o)TEARDOWN rtsp://10.35.132.225:10074/mixer RTSP/1.0\r\nCseq: 6\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\n\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:27:08.022 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\nCseq: 6\r\n\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:27:08.022 DEBUG [MOHO-48] #MSCTRL#: NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] removes(NC[ms2-33, nc1], JoineeContext[RESOURCE_CONTAINER, DUPLEX, null])
2011-08-15 16:27:08.022 DEBUG [MOHO-48] #MRCP#: (o)TEARDOWN rtsp://10.35.132.225:10074/recognizer/ RTSP/1.0\r\nCseq: 7\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\n\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:27:08.032 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\nCseq: 7\r\n\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:27:08.033 DEBUG [MOHO-48] #MRCP#: (o)TEARDOWN rtsp://10.35.132.225:10074/synthesizer/ RTSP/1.0\r\nCseq: 8\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\n\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:27:08.043 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456989327-2a90a00-0a3cde20-00000021\r\nCseq: 8\r\n\r\n #[3456989327-2a90a00-0a3cde20-00000021][10.35.132.225:10074][10.35.132.225:49260]
2011-08-15 16:27:08.043 DEBUG [MOHO-48] #MSCTRL#: MS[ms2-33] moves state from [INITIALIZED] to [RELEASED]
2011-08-15 16:27:08.044 DEBUG [MOHO-48] destroyNetworkConnection
2011-08-15 16:27:08.044 DEBUG [MOHO-48] #MSCTRL#: NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] moves state from [INITIALIZED] to [RELEASED]
2011-08-15 16:27:08.044 INFO [MOHO-48] #MSCTRL#: MS[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] removes a MediaObject[mscontrol://10.35.132.225:10074/MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe/NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]
2011-08-15 16:27:08.044 DEBUG [MOHO-48] #MSCTRL#: MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] removes JoineeMrcpContext[mscontrol://10.35.132.225:10074/MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe/NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, 3456986709-2f61e00-0a3cde20-00000020, 3456986709-2f61e00-0a3cde20-00000020] #[3456986709-2f61e00-0a3cde20-00000020]
2011-08-15 16:27:08.044 DEBUG [MOHO-48] #MSCTRL#: MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] removes(NC[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, NC-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe], JoineeContext[RESOURCE_CONTAINER, RECV, null])
2011-08-15 16:27:08.045 DEBUG [MOHO-48] #MRCP#: (o)TEARDOWN rtsp://10.35.132.225:10074/recognizer/ RTSP/1.0\r\nCseq: 9\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:27:08.054 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\nCseq: 9\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:27:08.055 DEBUG [MOHO-48] #MRCP#: (o)TEARDOWN rtsp://10.35.132.225:10074/synthesizer/ RTSP/1.0\r\nCseq: 10\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:27:08.065 DEBUG [mrcp/2-t-25] #MRCP#: (i)RTSP/1.0 200 OK\r\nSession: 3456986709-2f61e00-0a3cde20-00000020\r\nCseq: 10\r\n\r\n #[3456986709-2f61e00-0a3cde20-00000020][10.35.132.225:10074][10.35.132.225:49256]
2011-08-15 16:27:08.066 DEBUG [MOHO-48] #MSCTRL#: MS[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] moves state from [INITIALIZED] to [RELEASED]
2011-08-15 16:27:08.066 DEBUG [MOHO-48] #MSCTRL#: MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] moves state from [INITIALIZED] to [RELEASED]
2011-08-15 16:27:08.066 DEBUG [MOHO-48] #MSCTRL#: Stopping Player[IDLE, MG[MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe, MG-lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]], isStopAll:true
2011-08-15 16:27:08.067 DEBUG [MOHO-48] terminating call. Notifying this. callID:lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe
2011-08-15 16:27:08.067 DEBUG [MOHO-48] #SIP#: SessionManagementLayer send request: BYE sip:[email protected]:62922;ob #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected]][sip:[email protected]]
2011-08-15 16:27:08.067 INFO [pool-16-thread-33] Message [[Event class=com.voxeo.moho.event.MohoCallCompleteEvent sourceClass=SIPIncomingCall]]
2011-08-15 16:27:08.068 INFO [pool-16-thread-33] Queued Event [EndEvent[callId=5d3fa68c-3772-49dc-a988-db29c650e5bb,reason=HANGUP,errorText=<null>,headers=<null>]]
2011-08-15 16:27:08.068 DEBUG [MOHO-48] #SIP#: The transaction was created: z9hG4bK19gryrh4vrmkm #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected]][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.069 DEBUG [MOHO-48] #SIP#: (o)[BYE sip:[email protected]:62922;ob SIP/2.0\r\nTo: zlu-telephone <sip:[email protected]>;tag=nhlxHLnMW2bWtXHgif7RcWuz2fQwgf.6\r\nVia: SIP/2.0/UDP 10.35.132.225:5060;branch=z9hG4bK19gryrh4vrmkm;rport;x-sm-sid=b3d52dee-c1d2-40d9-9a8a-85cc4c67be5d;x-sm-nid=ss_3047vtqjj42c\r\nCSeq: 1 BYE\r\nContent-Length: 0\r\nCall-ID: lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=173e1n2v13oqt\r\n\r\n] #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected]][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.069 INFO [pool-16-thread-33] Call cleanup [call=SIPCallImpl[SipSessionAdaptor[sessionid=ss_3047vtqjj42c, appSessionId=sas_2-14-smlus4kfx9rsjwtropo2],DISCONNECTED]]
2011-08-15 16:27:08.069 DEBUG [MOHO-48] #SIP#: Send message to: /10.35.132.225:62922 by udp #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected]][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.070 DEBUG [MOHO-48] #SIP#: Connected to 10.35.132.225:62922/udp #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](10.35.132.225:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.070 DEBUG [MOHO-48] terminating call. Notifying this. callID:t2jgisxozbar
2011-08-15 16:27:08.071 INFO [pool-16-thread-33] Event [EndEvent[callId=5d3fa68c-3772-49dc-a988-db29c650e5bb,reason=HANGUP,errorText=<null>,headers=<null>]]
2011-08-15 16:27:08.071 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[SIP/2.0 200 OK\r\nTo: "zlu-telephone" <sip:[email protected]>;tag=nhlxHLnMW2bWtXHgif7RcWuz2fQwgf.6\r\nVia: SIP/2.0/UDP 10.35.132.225:5060;rport=5060;received=10.35.132.225;branch=z9hG4bK19gryrh4vrmkm;x-sm-sid=b3d52dee-c1d2-40d9-9a8a-85cc4c67be5d;x-sm-nid=ss_3047vtqjj42c\r\nCSeq: 1 BYE\r\nContent-Length: 0\r\nCall-ID: lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe\r\nFrom: <sip:[email protected]>;tag=173e1n2v13oqt\r\n\r\n] #[N/A][N/A][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][N/A][sip:[email protected](10.35.132.225:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.072 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Receive 200/BYE, branch=z9hG4bK19gryrh4vrmkm #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](10.35.132.225:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.072 DEBUG [MOHO-48] #SIP#: SessionManagementLayer send response: BYE/200 #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:27:08.072 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: NonInviteClientTransaction[_state=COMPLETED, _id=z9hG4bK19gryrh4vrmkm] is ready to release. #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](10.35.132.225:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.072 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv response: BYE/200 #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](10.35.132.225:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.073 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Controller, com.voxeo.moho.sip.SIPController] is forwarding. #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](10.35.132.225:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.074 DEBUG [udp/0.0.0.0/5060-t-3] SIPCallImpl[SipSessionAdaptor[sessionid=ss_3047vtqjj42c, appSessionId=sas_2-14-smlus4kfx9rsjwtropo2],DISCONNECTED] is already terminated.
2011-08-15 16:27:08.074 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-smlus4kfx9rsjwtropo2], invalidateWhenReady: true
2011-08-15 16:27:08.074 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_3047vtqjj42c], current State = TERMINATED, Vaild:true, Role:UAS, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.074 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: server will automatically invalidate sipsession [ss_3047vtqjj42c] #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.073 DEBUG [MOHO-48] #SIP#: Add Path[ id=t2jgisxozbar-MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv-fa7cgtuosm3j, session=SipSessionImpl[_id=ss_kt2a5wfsrrjt, _parentId=sas_2-14-smxrq94xzh9hrltropo2, _handler=Controller, _state=CONFIRMED, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=t2jgisxozbar], party= CALLER] #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.075 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipSessionImpl[_id=ss_3047vtqjj42c, _parentId=sas_2-14-smlus4kfx9rsjwtropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=INVITE, _callId=lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe] is invalidating. (s) #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.077 DEBUG [MOHO-48] #SIP#: (o)[SIP/2.0 200 OK\r\nTo: <sip:[email protected]>;tag=fa7cgtuosm3j\r\nVia: SIP/2.0/TCP 213.192.59.75;branch=z9hG4bK8e68.ba43a777.0;i=f107\r\nVia: SIP/2.0/tcp 10.35.132.225:55746;received=109.231.200.163;rport=55746;branch=z9hG4bKPjgm.eywwSjgkmLY0dw.elFWbJFRAQe0s-\r\nRecord-Route: <sip:213.192.59.75;transport=tcp;ftag=MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv;avp=TnIDCQBkaWFsb2dfaWQWADRhODctNGUzYWRjYzQtOTc0NTJmY2QTCQBkaWFsb2dfaWQWADRhODctNGUzYWRjYzQtOTc0NTJmY2QTBgBzdGltZXIEADE4MDATBwBhY2NvdW50AwB5ZXM;lr=on>\r\nCSeq: 13203 BYE\r\nContent-Length: 0\r\nCall-ID: t2jgisxozbar\r\nFrom: <sip:[email protected]>;tag=MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv\r\n\r\n] #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:27:08.077 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Remove Path[ id=lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe-nhlxHLnMW2bWtXHgif7RcWuz2fQwgf.6-173e1n2v13oqt, session=SipSessionImpl[_id=ss_3047vtqjj42c, _parentId=sas_2-14-smlus4kfx9rsjwtropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=true, _role=UAS, _method=INVITE, _callId=lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe]] #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.077 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-14-smlus4kfx9rsjwtropo2], invalidateWhenReady: true
2011-08-15 16:27:08.077 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-14-smlus4kfx9rsjwtropo2]
2011-08-15 16:27:08.077 DEBUG [MOHO-48] #SIP#: Find Connector: tcp:sip.iptel.org/213.192.59.75, 5060 #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:27:08.077 DEBUG [MOHO-48] #SIP#: Send message to: sip.iptel.org/213.192.59.75:5060 by tcp #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:27:08.078 DEBUG [MOHO-48] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-smxrq94xzh9hrltropo2], invalidateWhenReady: true
2011-08-15 16:27:08.078 DEBUG [MOHO-48] #SIP#: processInvalidationWhenReady [ss_kt2a5wfsrrjt], current State = TERMINATED, Vaild:true, Role:UAC, hasOngoingTransaction: true, OT: 1, ProcessingByApp: false, Fresh:false, invalidateWhenReady: true #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.078 DEBUG [MOHO-48] #SIP#: server will automatically invalidate sipsession [ss_kt2a5wfsrrjt] #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.082 DEBUG [MOHO-48] #SIP#: SipSessionImpl[_id=ss_kt2a5wfsrrjt, _parentId=sas_2-14-smxrq94xzh9hrltropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=false, _role=UAC, _method=INVITE, _callId=t2jgisxozbar] is invalidating. (s) #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.078 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-14-smlus4kfx9rsjwtropo2] is invalidating. (as)
2011-08-15 16:27:08.085 DEBUG [MOHO-48] #SIP#: Remove Path[ id=t2jgisxozbar-MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv-fa7cgtuosm3j, session=SipSessionImpl[_id=ss_kt2a5wfsrrjt, _parentId=sas_2-14-smxrq94xzh9hrltropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=true, _role=UAC, _method=INVITE, _callId=t2jgisxozbar]] #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.085 DEBUG [MOHO-48] #SIP#: Remove Path[ id=t2jgisxozbar-MXtyVqkUcQNrF-lFGS57wUwPGzYgbxfv-fa7cgtuosm3j, session=SipSessionImpl[_id=ss_kt2a5wfsrrjt, _parentId=sas_2-14-smxrq94xzh9hrltropo2, _handler=Controller, _state=TERMINATED, _fresh=false, _valid=true, _unavailable=true, _role=UAC, _method=INVITE, _callId=t2jgisxozbar]] #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:08.086 DEBUG [MOHO-48] #SIP#: processInvalidationWhenReady [sas_2-14-smxrq94xzh9hrltropo2], invalidateWhenReady: true
2011-08-15 16:27:08.086 DEBUG [MOHO-48] #SIP#: Container will automatically invalidate SipApplicationSession [sas_2-14-smxrq94xzh9hrltropo2]
2011-08-15 16:27:08.086 DEBUG [MOHO-48] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-14-smxrq94xzh9hrltropo2] is invalidating. (as)
2011-08-15 16:27:08.087 INFO [pool-16-thread-30] Peer unjoined [SIPCallImpl[SipSessionAdaptor[sessionid=ss_3047vtqjj42c, appSessionId=sas_2-14-smlus4kfx9rsjwtropo2],DISCONNECTED]]
2011-08-15 16:27:08.087 INFO [pool-16-thread-33] Message [[Event class=com.voxeo.moho.event.MohoCallCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-15 16:27:08.088 INFO [pool-16-thread-33] Queued Event [EndEvent[callId=e505e96c-91c1-4507-85b2-1483372f1534,reason=HANGUP,errorText=<null>,headers=<null>]]
2011-08-15 16:27:08.088 INFO [pool-16-thread-33] Call cleanup [call=SIPCallImpl[SipSessionAdaptor[sessionid=ss_kt2a5wfsrrjt, appSessionId=sas_2-14-smxrq94xzh9hrltropo2],DISCONNECTED]]
2011-08-15 16:27:08.089 INFO [pool-16-thread-33] Event [EndEvent[callId=e505e96c-91c1-4507-85b2-1483372f1534,reason=HANGUP,errorText=<null>,headers=<null>]]
2011-08-15 16:27:08.089 INFO [pool-16-thread-33] Actor is disposed. Ignoring message. [[Event class=com.voxeo.moho.event.MohoUnjoinCompleteEvent sourceClass=SIPOutgoingCall]]
2011-08-15 16:27:08.179 DEBUG [Timer-9] #SIP#: NonInviteServerTransaction[_state=PROCEEDING, _id=z9hG4bK8e68.ba43a777.0] timerRemoveTransaction is fired. #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:27:08.181 DEBUG [Timer-9] #SIP#: NonInviteServerTransaction[_state=TERMINATED, _id=z9hG4bK8e68.ba43a777.0] is released. #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:65049)]
2011-08-15 16:27:13.073 DEBUG [Timer-8] #SIP#: NonInviteClientTransaction[_state=COMPLETED, _id=z9hG4bK19gryrh4vrmkm] timerRemoveTransaction is fired. #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](10.35.132.225:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:13.074 DEBUG [Timer-8] #SIP#: NonInviteClientTransaction[_state=TERMINATED, _id=z9hG4bK19gryrh4vrmkm] is released. #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](10.35.132.225:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:14.345 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:27:24.038 DEBUG [Timer-8] #SIP#: InviteServerTransaction[_state=ACCEPTED, _id=z9hG4bKPjr4BulYO558x3b2E2xRXKAThmKNbKyiMy] timerRemoveTransaction is fired. #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:24.038 DEBUG [Timer-8] #SIP#: InviteServerTransaction[_state=TERMINATED, _id=z9hG4bKPjr4BulYO558x3b2E2xRXKAThmKNbKyiMy] is released. #[tropo2][sas_2-14-smlus4kfx9rsjwtropo2][lBz0ec67RnHeHid-5erBNa4uQ6tLUFSe][ss_3047vtqjj42c][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:29.247 DEBUG [Timer-9] #SIP#: InviteClientTransaction[_state=ACCEPTED, _id=z9hG4bK17pbrolqr28gg] timerRemoveTransaction is fired. #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:29.247 DEBUG [Timer-9] #SIP#: InviteClientTransaction[_state=TERMINATED, _id=z9hG4bK17pbrolqr28gg] is released. #[tropo2][sas_2-14-smxrq94xzh9hrltropo2][t2jgisxozbar][ss_kt2a5wfsrrjt][sip:[email protected](213.192.59.75:5060)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:27:29.346 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:27:44.347 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:27:59.347 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:28:14.347 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:28:29.348 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:28:44.348 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:28:59.349 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:29:14.350 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:29:24.337 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (i)[REGISTER sip:127.0.0.1 SIP/2.0\r\nTo: "zlu-telephone" <sip:[email protected]>\r\nExpires: 300\r\nVia: SIP/2.0/UDP 10.35.132.225:62922;rport;branch=z9hG4bKPjnBV-5EwGrwKEh1paJE9hV.aisDtWeP88\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nCSeq: 51155 REGISTER\r\nContent-Length: 0\r\nCall-ID: 1EzzbHcjXTx5dmxF88NFedjgF2UbFveU\r\nUser-Agent: Telephone 1.0.2\r\nFrom: "zlu-telephone" <sip:[email protected]>;tag=1-1ulG80WEGElOUiDtpxHOtLFQq1bir7\r\nMax-Forwards: 70\r\nContact: "zlu-telephone" <sip:[email protected]:62922;ob>\r\n\r\n] #[N/A][N/A][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][N/A][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.337 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: The transaction was created: z9hG4bKPjnBV-5EwGrwKEh1paJE9hV.aisDtWeP88 #[N/A][N/A][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][N/A][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.338 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Found [registrar] to handle the request by servlet mappings: SipServletSink[m_cond=request.method.equals("REGISTER"), m_context=ApplicationImpl[_symbolicName=registrar-1.0.0, _state=STARTED], m_wrapper=SipServletWrapper[Registrar, com.micromethod.sipservices.registrar.RegistrarService]]
2011-08-15 16:29:24.338 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipApplicationInfo: SipApplicationRouterInfo[ApplicationName=registrar, RouteModifier=NO_ROUTE, RouteRegion=null, SubscriberURI=sip:127.0.0.1, StateInfo=registrar] #[N/A][N/A][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][N/A][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.338 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Session creating: ss_jmkekhl25xnq #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.339 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Session created:SipSessionImpl[_id=ss_jmkekhl25xnq, _parentId=sas_2-15-sm1xc9xg9abtxj9registrar, _handler=Registrar, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UNKNOW, _method=REGISTER, _callId=1EzzbHcjXTx5dmxF88NFedjgF2UbFveU] #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.339 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer recv request: REGISTER #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.339 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ApplicationDispatchLayer invoke application: Registrar with REGISTER #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.340 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipServletWrapper[Registrar, com.micromethod.sipservices.registrar.RegistrarService] is forwarding. #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.352 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SessionManagementLayer send response: REGISTER/200 #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.353 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Add Path[ id=1EzzbHcjXTx5dmxF88NFedjgF2UbFveU-1-1ulG80WEGElOUiDtpxHOtLFQq1bir7-19b42sedjmv7, session=SipSessionImpl[_id=ss_jmkekhl25xnq, _parentId=sas_2-15-sm1xc9xg9abtxj9registrar, _handler=Registrar, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=REGISTER, _callId=1EzzbHcjXTx5dmxF88NFedjgF2UbFveU], party= CALLER] #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.353 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: (o)[SIP/2.0 200 OK\r\nTo: zlu-telephone <sip:[email protected]>;tag=19b42sedjmv7\r\nVia: SIP/2.0/UDP 10.35.132.225:62922;rport=62922;branch=z9hG4bKPjnBV-5EwGrwKEh1paJE9hV.aisDtWeP88;received=127.0.0.1\r\nCSeq: 51155 REGISTER\r\nContent-Length: 0\r\nCall-ID: 1EzzbHcjXTx5dmxF88NFedjgF2UbFveU\r\nFrom: zlu-telephone <sip:[email protected]>;tag=1-1ulG80WEGElOUiDtpxHOtLFQq1bir7\r\nContact: <sip:[email protected]:62922;ob>;expires=300;q=1.0\r\n\r\n] #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.354 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Send message to: /127.0.0.1:62922 by udp #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.357 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Connected to 127.0.0.1:62922/udp #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.357 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-15-sm1xc9xg9abtxj9registrar], invalidateWhenReady: true
2011-08-15 16:29:24.357 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [ss_jmkekhl25xnq], current State = INITIAL, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: true, Fresh:false, invalidateWhenReady: true #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.357 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: processInvalidationWhenReady [sas_2-15-sm1xc9xg9abtxj9registrar], invalidateWhenReady: true
2011-08-15 16:29:24.358 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-15-sm1xc9xg9abtxj9registrar] is invalidating. (as)
2011-08-15 16:29:24.359 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: SipSessionImpl[_id=ss_jmkekhl25xnq, _parentId=sas_2-15-sm1xc9xg9abtxj9registrar, _handler=Registrar, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=REGISTER, _callId=1EzzbHcjXTx5dmxF88NFedjgF2UbFveU] is invalidating. (s) #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:24.360 DEBUG [udp/0.0.0.0/5060-t-3] #SIP#: Remove Path[ id=1EzzbHcjXTx5dmxF88NFedjgF2UbFveU-1-1ulG80WEGElOUiDtpxHOtLFQq1bir7-19b42sedjmv7, session=SipSessionImpl[_id=ss_jmkekhl25xnq, _parentId=sas_2-15-sm1xc9xg9abtxj9registrar, _handler=Registrar, _state=INITIAL, _fresh=false, _valid=true, _unavailable=true, _role=UAS, _method=REGISTER, _callId=1EzzbHcjXTx5dmxF88NFedjgF2UbFveU]] #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:39.357 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:29:54.357 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:29:56.354 DEBUG [Timer-10] #SIP#: NonInviteServerTransaction[_state=COMPLETED, _id=z9hG4bKPjnBV-5EwGrwKEh1paJE9hV.aisDtWeP88] timerRemoveTransaction is fired. #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:29:56.354 DEBUG [Timer-10] #SIP#: NonInviteServerTransaction[_state=TERMINATED, _id=z9hG4bKPjnBV-5EwGrwKEh1paJE9hV.aisDtWeP88] is released. #[registrar][sas_2-15-sm1xc9xg9abtxj9registrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_jmkekhl25xnq][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:30:09.357 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:30:24.357 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:30:39.357 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:30:54.358 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:31:09.358 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:31:24.358 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:31:39.369 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:31:54.360 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:32:09.360 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:32:24.360 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:32:39.360 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:32:54.360 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:33:09.360 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:33:24.362 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:33:39.362 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:33:54.362 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:34:09.363 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:34:19.355 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: (i)[REGISTER sip:127.0.0.1 SIP/2.0\r\nTo: "zlu-telephone" <sip:[email protected]>\r\nExpires: 300\r\nVia: SIP/2.0/UDP 10.35.132.225:62922;rport;branch=z9hG4bKPj0100mnuZEO0QFd.nKHRj1SOxqppmQ23Q\r\nAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE\r\nAllow: OPTIONS\r\nCSeq: 51156 REGISTER\r\nContent-Length: 0\r\nCall-ID: 1EzzbHcjXTx5dmxF88NFedjgF2UbFveU\r\nUser-Agent: Telephone 1.0.2\r\nFrom: "zlu-telephone" <sip:[email protected]>;tag=Zay9znqKVd4zIoGCS9qROn-Eui2mDi5A\r\nMax-Forwards: 70\r\nContact: "zlu-telephone" <sip:[email protected]:62922;ob>\r\n\r\n] #[N/A][N/A][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][N/A][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.356 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: The transaction was created: z9hG4bKPj0100mnuZEO0QFd.nKHRj1SOxqppmQ23Q #[N/A][N/A][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][N/A][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.357 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Found [registrar] to handle the request by servlet mappings: SipServletSink[m_cond=request.method.equals("REGISTER"), m_context=ApplicationImpl[_symbolicName=registrar-1.0.0, _state=STARTED], m_wrapper=SipServletWrapper[Registrar, com.micromethod.sipservices.registrar.RegistrarService]]
2011-08-15 16:34:19.357 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SipApplicationInfo: SipApplicationRouterInfo[ApplicationName=registrar, RouteModifier=NO_ROUTE, RouteRegion=null, SubscriberURI=sip:127.0.0.1, StateInfo=registrar] #[N/A][N/A][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][N/A][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.357 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Session creating: ss_y5n3nncq5wg0 #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.358 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Session created:SipSessionImpl[_id=ss_y5n3nncq5wg0, _parentId=sas_2-14-smelq8bwfkcq1sregistrar, _handler=Registrar, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UNKNOW, _method=REGISTER, _callId=1EzzbHcjXTx5dmxF88NFedjgF2UbFveU] #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.358 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SessionManagementLayer recv request: REGISTER #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.358 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: ApplicationDispatchLayer invoke application: Registrar with REGISTER #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.358 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SipServletWrapper[Registrar, com.micromethod.sipservices.registrar.RegistrarService] is forwarding. #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.370 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SessionManagementLayer send response: REGISTER/200 #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.372 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Add Path[ id=1EzzbHcjXTx5dmxF88NFedjgF2UbFveU-Zay9znqKVd4zIoGCS9qROn-Eui2mDi5A-19ipvgigqtuk5, session=SipSessionImpl[_id=ss_y5n3nncq5wg0, _parentId=sas_2-14-smelq8bwfkcq1sregistrar, _handler=Registrar, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=REGISTER, _callId=1EzzbHcjXTx5dmxF88NFedjgF2UbFveU], party= CALLER] #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.372 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: (o)[SIP/2.0 200 OK\r\nTo: zlu-telephone <sip:[email protected]>;tag=19ipvgigqtuk5\r\nVia: SIP/2.0/UDP 10.35.132.225:62922;rport=62922;branch=z9hG4bKPj0100mnuZEO0QFd.nKHRj1SOxqppmQ23Q;received=127.0.0.1\r\nCSeq: 51156 REGISTER\r\nContent-Length: 0\r\nCall-ID: 1EzzbHcjXTx5dmxF88NFedjgF2UbFveU\r\nFrom: zlu-telephone <sip:[email protected]>;tag=Zay9znqKVd4zIoGCS9qROn-Eui2mDi5A\r\nContact: <sip:[email protected]:62922;ob>;expires=300;q=1.0\r\n\r\n] #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.373 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Send message to: /127.0.0.1:62922 by udp #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.373 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Connected to 127.0.0.1:62922/udp #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.373 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: ProcessSipSessionsInvalidationWhenReady [sas_2-14-smelq8bwfkcq1sregistrar], invalidateWhenReady: true
2011-08-15 16:34:19.373 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [ss_y5n3nncq5wg0], current State = INITIAL, Vaild:true, Role:UAS, hasOngoingTransaction: false, OT: 0, ProcessingByApp: true, Fresh:false, invalidateWhenReady: true #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.373 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: processInvalidationWhenReady [sas_2-14-smelq8bwfkcq1sregistrar], invalidateWhenReady: true
2011-08-15 16:34:19.376 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SipApplicationSessionImpl[_state=VALID, _id=sas_2-14-smelq8bwfkcq1sregistrar] is invalidating. (as)
2011-08-15 16:34:19.377 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: SipSessionImpl[_id=ss_y5n3nncq5wg0, _parentId=sas_2-14-smelq8bwfkcq1sregistrar, _handler=Registrar, _state=INITIAL, _fresh=false, _valid=true, _unavailable=false, _role=UAS, _method=REGISTER, _callId=1EzzbHcjXTx5dmxF88NFedjgF2UbFveU] is invalidating. (s) #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:19.377 DEBUG [udp/0.0.0.0/5060-t-4] #SIP#: Remove Path[ id=1EzzbHcjXTx5dmxF88NFedjgF2UbFveU-Zay9znqKVd4zIoGCS9qROn-Eui2mDi5A-19ipvgigqtuk5, session=SipSessionImpl[_id=ss_y5n3nncq5wg0, _parentId=sas_2-14-smelq8bwfkcq1sregistrar, _handler=Registrar, _state=INITIAL, _fresh=false, _valid=true, _unavailable=true, _role=UAS, _method=REGISTER, _callId=1EzzbHcjXTx5dmxF88NFedjgF2UbFveU]] #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:34.375 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:34:49.378 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:34:51.374 DEBUG [Timer-11] #SIP#: NonInviteServerTransaction[_state=COMPLETED, _id=z9hG4bKPj0100mnuZEO0QFd.nKHRj1SOxqppmQ23Q] timerRemoveTransaction is fired. #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:34:51.375 DEBUG [Timer-11] #SIP#: NonInviteServerTransaction[_state=TERMINATED, _id=z9hG4bKPj0100mnuZEO0QFd.nKHRj1SOxqppmQ23Q] is released. #[registrar][sas_2-14-smelq8bwfkcq1sregistrar][1EzzbHcjXTx5dmxF88NFedjgF2UbFveU][ss_y5n3nncq5wg0][sip:[email protected](127.0.0.1:62922)][sip:[email protected](10.35.132.225:5060)]
2011-08-15 16:35:04.375 WARN [udp/0.0.0.0/5060-t-4] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:35:19.375 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
2011-08-15 16:35:34.376 WARN [udp/0.0.0.0/5060-t-3] #SIP#: Illegal message: \r\n@T: java.io.EOFException: UnexpectedEndOfSipMsg\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.nextLine(SipImplementsFactory.java:546)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.parseMessage(SipImplementsFactory.java:233)\n at com.micromethod.sipmethod.server.sip.stack.SipImplementsFactory.createMessage(SipImplementsFactory.java:225)\n at com.micromethod.sipmethod.server.sip.impl.SIPServiceImpl.handle(SIPServiceImpl.java:461)\n at com.micromethod.sipmethod.server.connector.message.impl.MessageConnectorImpl.handle(MessageConnectorImpl.java:64)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.recv(SipUdpQueueConnection.java:91)\n at com.micromethod.sipmethod.server.connector.message.impl.udp.SipUdpQueueConnection.run(SipUdpQueueConnection.java:60)\n at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)\n at java.lang.Thread.run(Thread.java:680)\n
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment