Oct 23, 2007 2:46:57 PM net.jxta.impl.discovery.DiscoveryServiceImpl processSrdi FINE: Primary Key [Adv] key [MSID] value [urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE000000010206] exp [31535968922] Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.SrdiIndex add FINE: [discoverySrdi] Adding Adv/MSID = 'urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE000000030106' for urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.Indexer addToIndex FINE: looking up NameIndexer : AdvMSID Oct 23, 2007 2:46:57 PM net.jxta.impl.discovery.DiscoveryServiceImpl processSrdi FINE: Primary Key [Adv] key [MSID] value [urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE000000030106] exp [31535968875] Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 1 selected keys Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: KeySet has 1 selected keys Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] State before read(): HEADER, buffer stats : java.nio.HeapByteBuffer[pos=0 lim=4096 cap=4096], remaining :4,096 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 1,380 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096], remaining 1,380 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096], elements remaining 1,380 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] Processing message package header, buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096] Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.msgframing.MessagePackageHeader readHeader FINE: Parsing Package Header from byte buffer :java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096] Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] setting current state to body, Buffer stats :java.nio.HeapByteBuffer[pos=63 lim=1380 cap=4096], remaining elements 1,317: Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] Proccessing Message Body. expecting 1,803, java.nio.HeapByteBuffer[pos=63 lim=1380 cap=4096] elements remaining 1,317 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] State before read(): BODY, buffer stats : java.nio.HeapByteBuffer[pos=1317 lim=4096 cap=4096], remaining :2,779 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 0 selected keys Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpTransport updateChannelRegisterations FINE: Registering 1 channels with MessengerSelectorThread Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 1 selected keys Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: KeySet has 1 selected keys Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] State before read(): BODY, buffer stats : java.nio.HeapByteBuffer[pos=1317 lim=4096 cap=4096], remaining :2,779 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 486 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1803 cap=4096], remaining 1,803 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1803 cap=4096], elements remaining 1,803 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] Proccessing Message Body. expecting 1,803, java.nio.HeapByteBuffer[pos=0 lim=1803 cap=4096] elements remaining 1,803 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.WireFormatMessageBinary$Instantiator fromBuffer FINE: Reading net.jxta.endpoint.Message@32558929(0){30} from java.nio.HeapByteBuffer[pos=0 lim=1803 cap=4096] Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=1803 lim=1803 cap=4096], elements remaining 0 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] Processing message package header, buffer stats:java.nio.HeapByteBuffer[pos=1803 lim=1803 cap=4096] Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.msgframing.MessagePackageHeader readHeader FINE: Parsing Package Header from byte buffer :java.nio.HeapByteBuffer[pos=1803 lim=1803 cap=4096] Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] maintaining current state at header, buffer stats :java.nio.HeapByteBuffer[pos=1803 lim=1803 cap=4096] Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] State before read(): HEADER, buffer stats : java.nio.HeapByteBuffer[pos=0 lim=4096 cap=4096], remaining :4,096 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpMessenger$MessageProcessor run FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] calling EndpointService.demux(net.jxta.endpoint.Message@32558929(5){30}) Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 0 selected keys Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.tcp.TcpTransport updateChannelRegisterations FINE: Registering 1 channels with MessengerSelectorThread Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.EndpointServiceImpl processIncomingMessage FINE: Calling listener for 'EndpointService:uuid-4D79507269764174A547B26F757002/EndpointRouter' with net.jxta.endpoint.Message@32558929(7){30} Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.router.EndpointRouter processIncomingMessage FINE: Endpoint Router Message : src=jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 dest== jxta://uuid-59616261646162614E504720503250331EE6AFE8F9E6494E85289921EFB0329403/JxtaPropagate/uuid-4D79507269764174A547B26F757002 lastHop= jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 embedded radv= none Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.EndpointServiceImpl processIncomingMessage FINE: Calling listener for 'JxtaPropagate/uuid-4D79507269764174A547B26F757002' with net.jxta.endpoint.Message@32558929(8){30} Oct 23, 2007 2:46:57 PM net.jxta.impl.rendezvous.RendezVousServiceProvider processIncomingMessage FINE: Processing net.jxta.endpoint.Message@32558929(8){30}(0000000d-0000-1000-8014-eae96d47633a) for urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002Srdi from jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:46:57 PM net.jxta.impl.rendezvous.StdRendezVousService processReceivedMessage FINE: Received net.jxta.endpoint.Message@32558929(8){30} (0000000d-0000-1000-8014-eae96d47633a) from saruman C : 1198434 Oct 23, 2007 2:46:57 PM net.jxta.impl.rendezvous.RendezVousServiceProvider processReceivedMessage FINE: Calling local listener net.jxta.impl.resolver.ResolverServiceImpl$DemuxSrdi for [urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002Srdi] with net.jxta.endpoint.Message@32558929(8){30} (0000000d-0000-1000-8014-eae96d47633a) Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.EndpointServiceImpl processIncomingMessage FINE: Calling listener for 'urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002Srdi' with net.jxta.endpoint.Message@32558929(8){30} Oct 23, 2007 2:46:57 PM net.jxta.impl.resolver.ResolverServiceImpl$DemuxSrdi processIncomingMessage FINE: Demuxing an SRDI message from : jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:46:57 PM net.jxta.impl.resolver.ResolverServiceImpl processSrdi FINE: Processing an SRDI msg for : JxtaPipeResolver in Group ID:urn:jxta:uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:46:57 PM net.jxta.impl.pipe.PipeResolver processSrdi FINE: Received an SRDI messsage with 1 entries from urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.SrdiIndex add FINE: [pipeResolverSrdi] Adding JxtaUnicast/Id = 'urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904' for urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.Indexer addToIndex FINE: looking up NameIndexer : JxtaUnicastId Oct 23, 2007 2:46:57 PM net.jxta.impl.discovery.DiscoveryServiceImpl publish FINE: Publishing a jxta:RdvAdvertisement as Adv / uuid-4D79507269764174A547B26F757000006A7874613A5244768164B66572746973C17F4738213D112442BB423EEF62E856CA2596B001 expiration : 7200000 lifetime :31536000000 Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.Cm save FINE: Indexing {AdvRdvGroupId=urn:jxta:uuid-4D79507269764174A547B26F757002, AdvRdvServiceName=uuid-DEADBEEFDEAFBABAFEEDBABE0000000F05, AdvRdvPeerId=urn:jxta:uuid-59616261646162614E504720503250331EE6AFE8F9E6494E85289921EFB0329403} at 1026 Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.Indexer addToIndex FINE: looking up NameIndexer : AdvRdvGroupId Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.Indexer addToIndex FINE: looking up NameIndexer : AdvRdvServiceName Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.Indexer addToIndex FINE: looking up NameIndexer : AdvRdvPeerId Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.Cm save FINE: Stored {RdvGroupId=urn:jxta:uuid-4D79507269764174A547B26F757002, RdvServiceName=uuid-DEADBEEFDEAFBABAFEEDBABE0000000F05, RdvPeerId=urn:jxta:uuid-59616261646162614E504720503250331EE6AFE8F9E6494E85289921EFB0329403} at 1026 Oct 23, 2007 2:46:57 PM net.jxta.impl.pipe.WirePipe recordSeenMessage FINE: added 00000004-0000-1000-806d-de71b8a510e2 Oct 23, 2007 2:46:57 PM net.jxta.impl.pipe.InputPipeImpl processIncomingMessage FINE: Received net.jxta.endpoint.Message@7182746(0){34,33,32,31} from jxta://uuid-59616261646162614E504720503250331EE6AFE8F9E6494E85289921EFB0329403 for urn:jxta:uuid-59616261646162614E50472050325033DEADBEEFDEAFBABAFEEDBABE0000000F04 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.relay.RelayServer$RelayServerCache pipeMsgEvent FINE: pipeMsgEvent() discarding message no response PID defined, or loopback Oct 23, 2007 2:46:57 PM net.jxta.impl.pipe.WirePipe callLocalListeners FINE: Called 1 of 1 local listeners for urn:jxta:uuid-59616261646162614E50472050325033DEADBEEFDEAFBABAFEEDBABE0000000F04 Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.SrdiIndex query FINE: [pipeResolverSrdi] Querying for 2147483647 JxtaPropagate/Id = 'urn:jxta:uuid-59616261646162614E50472050325033DEADBEEFDEAFBABAFEEDBABE0000000F04' Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.Cm getIndexQuery FINE: Index query operator :1 Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.Indexer search FINE: Searching Index : JxtaPropagateId Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.SrdiIndex$SearchCallback indexInfo FINE: Found urn:jxta:uuid-59616261646162614E50472050325033DEADBEEFDEAFBABAFEEDBABE0000000F04 Oct 23, 2007 2:46:57 PM net.jxta.impl.cm.SrdiIndex query FINE: [pipeResolverSrdi] Returning 1 results for JxtaPropagate/Id = 'urn:jxta:uuid-59616261646162614E50472050325033DEADBEEFDEAFBABAFEEDBABE0000000F04' Oct 23, 2007 2:46:57 PM net.jxta.impl.pipe.WirePipe sendMessage FINE: Propagating net.jxta.endpoint.Message@25120699(0){33,32,31} to 0 subscriber peers. Oct 23, 2007 2:46:57 PM net.jxta.impl.rendezvous.StdRendezVousService propagate FINE: Propagating net.jxta.endpoint.Message@21731956(0){35,33,32,31}(TTL=1) to : svc name:jxta.service.wirepipe svc params:uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:46:57 PM net.jxta.impl.rendezvous.RendezVousServiceProvider updatePropHeader FINE: Added prop header for net.jxta.endpoint.Message@21731956(0){35,33,32,31} (00000005-0000-1000-806d-de71b8a510e2) TTL = 1 Oct 23, 2007 2:46:57 PM net.jxta.impl.rendezvous.StdRendezVousService propagate FINE: Propagated net.jxta.endpoint.Message@21731956(1){35,33,32,31} (00000005-0000-1000-806d-de71b8a510e2) to 0 peers. Oct 23, 2007 2:46:57 PM net.jxta.impl.pipe.WirePipe sendMessage FINE: Walking net.jxta.endpoint.Message@25120699(0){33,32,31} through peerview. Oct 23, 2007 2:46:57 PM net.jxta.impl.rendezvous.rdv.RdvPeerRdvService walk FINE: Undirected walk of net.jxta.endpoint.Message@8993129(0){36,33,32,31}(TTL=200) to : svc name:jxta.service.wirepipe svc params:uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:46:57 PM net.jxta.impl.rendezvous.limited.LimitedRangeWalker walkMessage FINE: Walking net.jxta.endpoint.Message@8993129(2){36,33,32,31} to urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000605/uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:46:57 PM net.jxta.impl.rendezvous.limited.LimitedRangeWalker walkMessage FINE: Creating new Walk Header for net.jxta.endpoint.Message@8993129(2){36,33,32,31} with TTL=200 Oct 23, 2007 2:46:57 PM net.jxta.impl.endpoint.relay.RelayServer$RelayServerCache run FINE: sleepTime=1200000 14:46:59.160|Timer-1| ||AnnounceService|announce Oct 23, 2007 2:46:59 PM net.jxta.impl.pipe.WirePipe recordSeenMessage FINE: added 00000006-0000-1000-806d-de71b8a510e2 Oct 23, 2007 2:46:59 PM net.jxta.impl.pipe.InputPipeImpl processIncomingMessage FINE: Received net.jxta.endpoint.Message@21694491(0){40,39,38,37} from jxta://uuid-59616261646162614E504720503250331EE6AFE8F9E6494E85289921EFB0329403 for urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504 Oct 23, 2007 2:46:59 PM net.jxta.impl.pipe.WirePipe callLocalListeners FINE: Called 1 of 1 local listeners for urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504 Oct 23, 2007 2:46:59 PM net.jxta.impl.cm.SrdiIndex query FINE: [pipeResolverSrdi] Querying for 2147483647 JxtaPropagate/Id = 'urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504' Oct 23, 2007 2:46:59 PM net.jxta.impl.cm.Cm getIndexQuery FINE: Index query operator :1 Oct 23, 2007 2:46:59 PM net.jxta.impl.cm.Indexer search FINE: Searching Index : JxtaPropagateId Oct 23, 2007 2:46:59 PM net.jxta.impl.cm.SrdiIndex$SearchCallback indexInfo FINE: Found urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504 Oct 23, 2007 2:46:59 PM net.jxta.impl.cm.SrdiIndex query FINE: [pipeResolverSrdi] Returning 2 results for JxtaPropagate/Id = 'urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504' Oct 23, 2007 2:46:59 PM net.jxta.impl.pipe.WirePipe sendMessage FINE: Propagating net.jxta.endpoint.Message@16865950(0){39,38,37} to 1 subscriber peers. Oct 23, 2007 2:46:59 PM net.jxta.impl.rendezvous.StdRendezVousService propagate FINE: Propagating net.jxta.endpoint.Message@31742556(0){41,39,38,37}(TTL=1) to : svc name:jxta.service.wirepipe svc params:uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:46:59 PM net.jxta.impl.rendezvous.RendezVousServiceProvider updatePropHeader FINE: Added prop header for net.jxta.endpoint.Message@31742556(0){41,39,38,37} (00000007-0000-1000-806d-de71b8a510e2) TTL = 1 Oct 23, 2007 2:46:59 PM net.jxta.impl.rendezvous.StdRendezVousService propagate FINE: Sending net.jxta.endpoint.Message@31742556(1){41,39,38,37} (00000007-0000-1000-806d-de71b8a510e2) to saruman C : 1196874 Oct 23, 2007 2:46:59 PM net.jxta.impl.rendezvous.StdRendezVousService propagate FINE: Propagated net.jxta.endpoint.Message@31742556(1){41,39,38,37} (00000007-0000-1000-806d-de71b8a510e2) to 1 peers. Oct 23, 2007 2:46:59 PM net.jxta.impl.pipe.WirePipe sendMessage FINE: Walking net.jxta.endpoint.Message@16865950(0){39,38,37} through peerview. Oct 23, 2007 2:46:59 PM net.jxta.impl.rendezvous.rdv.RdvPeerRdvService walk FINE: Undirected walk of net.jxta.endpoint.Message@20275290(0){43,39,38,37}(TTL=200) to : svc name:jxta.service.wirepipe svc params:uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:46:59 PM net.jxta.impl.rendezvous.limited.LimitedRangeWalker walkMessage FINE: Walking net.jxta.endpoint.Message@20275290(2){43,39,38,37} to urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000605/uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:46:59 PM net.jxta.impl.rendezvous.limited.LimitedRangeWalker walkMessage FINE: Creating new Walk Header for net.jxta.endpoint.Message@20275290(2){43,39,38,37} with TTL=200 Oct 23, 2007 2:46:59 PM net.jxta.impl.endpoint.router.EndpointRouter addressMessage FINE: Create a new EndpointRouterMessage jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903/JxtaPropagate/uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:46:59 PM net.jxta.impl.endpoint.router.EndpointRouter getGatewayAddress FINE: Searching local & remote for route for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:46:59 PM net.jxta.impl.endpoint.router.EndpointRouter getGatewayAddress FINE: Found direct route for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 via tcp://64.231.244.79:60618 Oct 23, 2007 2:46:59 PM net.jxta.impl.endpoint.router.RouterMessenger sendMessageBImpl FINE: Sending net.jxta.endpoint.Message@21555096(1){42,41,39,38,37} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:46:59 PM net.jxta.impl.endpoint.router.EndpointRouter sendOnLocalRoute FINE: Sending net.jxta.endpoint.Message@21555096(1){42,41,39,38,37} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 via net.jxta.impl.endpoint.BlockingMessenger$BlockingMessengerChannel@16fdac {tcp://64.231.244.79:60618} Oct 23, 2007 2:46:59 PM net.jxta.impl.endpoint.tcp.TcpMessenger sendMessageDirect FINE: Sending net.jxta.endpoint.Message@21555096(3){42,41,39,38,37} to tcp://64.231.244.79:60618/EndpointService:uuid-4D79507269764174A547B26F757002/EndpointRouter on connection tcp://64.231.244.79:60618 Oct 23, 2007 2:46:59 PM net.jxta.impl.endpoint.tcp.TcpMessenger xmitMessage FINE: Sending net.jxta.endpoint.Message@21555096(3){42,41,39,38,37} (2411) to tcp://69.159.39.151:9701 via 64.231.244.79:60618 Oct 23, 2007 2:46:59 PM net.jxta.impl.endpoint.tcp.TcpMessenger xmitMessage FINE: Sent 2,474 bytes net.jxta.endpoint.Message@21555096(3){42,41,39,38,37} successfully via 64.231.244.79:60,618 Oct 23, 2007 2:46:59 PM net.jxta.impl.endpoint.router.EndpointRouter sendOnLocalRoute FINE: Sent net.jxta.endpoint.Message@21555096(3){42,41,39,38,37} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:00 PM net.jxta.impl.endpoint.relay.RelayServerClient run FINE: stopped sending queued messages for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 1 selected keys Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: KeySet has 1 selected keys Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] State before read(): HEADER, buffer stats : java.nio.HeapByteBuffer[pos=0 lim=4096 cap=4096], remaining :4,096 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 1,380 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096], remaining 1,380 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096], elements remaining 1,380 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] Processing message package header, buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096] Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.msgframing.MessagePackageHeader readHeader FINE: Parsing Package Header from byte buffer :java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096] Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] setting current state to body, Buffer stats :java.nio.HeapByteBuffer[pos=63 lim=1380 cap=4096], remaining elements 1,317: Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] Proccessing Message Body. expecting 2,412, java.nio.HeapByteBuffer[pos=63 lim=1380 cap=4096] elements remaining 1,317 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] State before read(): BODY, buffer stats : java.nio.HeapByteBuffer[pos=1317 lim=4096 cap=4096], remaining :2,779 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 0 selected keys Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpTransport updateChannelRegisterations FINE: Registering 1 channels with MessengerSelectorThread Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 1 selected keys Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: KeySet has 1 selected keys Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 2,5,Group urn:jxta:jxta-WorldGroup] State before read(): BODY, buffer stats : java.nio.HeapByteBuffer[pos=1317 lim=4096 cap=4096], remaining :2,779 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 2,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 1,095 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=2412 cap=4096], remaining 2,412 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 2,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=2412 cap=4096], elements remaining 2,412 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 2,5,Group urn:jxta:jxta-WorldGroup] Proccessing Message Body. expecting 2,412, java.nio.HeapByteBuffer[pos=0 lim=2412 cap=4096] elements remaining 2,412 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.WireFormatMessageBinary$Instantiator fromBuffer FINE: Reading net.jxta.endpoint.Message@15206208(0){44} from java.nio.HeapByteBuffer[pos=0 lim=2412 cap=4096] Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 2,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=2412 lim=2412 cap=4096], elements remaining 0 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 2,5,Group urn:jxta:jxta-WorldGroup] Processing message package header, buffer stats:java.nio.HeapByteBuffer[pos=2412 lim=2412 cap=4096] Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.msgframing.MessagePackageHeader readHeader FINE: Parsing Package Header from byte buffer :java.nio.HeapByteBuffer[pos=2412 lim=2412 cap=4096] Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 2,5,Group urn:jxta:jxta-WorldGroup] maintaining current state at header, buffer stats :java.nio.HeapByteBuffer[pos=2412 lim=2412 cap=4096] Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 2,5,Group urn:jxta:jxta-WorldGroup] State before read(): HEADER, buffer stats : java.nio.HeapByteBuffer[pos=0 lim=4096 cap=4096], remaining :4,096 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger$MessageProcessor run FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] calling EndpointService.demux(net.jxta.endpoint.Message@15206208(13){44}) Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.EndpointServiceImpl processIncomingMessage FINE: Calling listener for 'EndpointService:uuid-4D79507269764174A547B26F757002/EndpointRouter' with net.jxta.endpoint.Message@15206208(15){44} Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.router.EndpointRouter processIncomingMessage FINE: Endpoint Router Message : src=jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 dest== jxta://uuid-59616261646162614E504720503250331EE6AFE8F9E6494E85289921EFB0329403/JxtaPropagate/uuid-4D79507269764174A547B26F757002 lastHop= jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 embedded radv= none Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.EndpointServiceImpl processIncomingMessage FINE: Calling listener for 'JxtaPropagate/uuid-4D79507269764174A547B26F757002' with net.jxta.endpoint.Message@15206208(16){44} Oct 23, 2007 2:47:02 PM net.jxta.impl.rendezvous.RendezVousServiceProvider processIncomingMessage FINE: Processing net.jxta.endpoint.Message@15206208(16){44}(00000011-0000-1000-8014-eae96d47633a) for jxta.service.wirepipe/uuid-4D79507269764174A547B26F757002 from jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:02 PM net.jxta.impl.rendezvous.StdRendezVousService processReceivedMessage FINE: Received net.jxta.endpoint.Message@15206208(16){44} (00000011-0000-1000-8014-eae96d47633a) from saruman C : 1193612 Oct 23, 2007 2:47:02 PM net.jxta.impl.rendezvous.RendezVousServiceProvider processReceivedMessage FINE: Calling local listener net.jxta.impl.pipe.WirePipeImpl for [jxta.service.wirepipe/uuid-4D79507269764174A547B26F757002] with net.jxta.endpoint.Message@15206208(16){44} (00000011-0000-1000-8014-eae96d47633a) Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.EndpointServiceImpl processIncomingMessage FINE: Calling listener for 'jxta.service.wirepipe/uuid-4D79507269764174A547B26F757002' with net.jxta.endpoint.Message@15206208(16){44} Oct 23, 2007 2:47:02 PM net.jxta.impl.pipe.WirePipe recordSeenMessage FINE: added 0000000f-0000-1000-8014-eae96d47633a Oct 23, 2007 2:47:02 PM net.jxta.impl.pipe.WirePipe processIncomingMessage FINE: Processing net.jxta.endpoint.Message@15206208(16){44} from jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 on urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504 Oct 23, 2007 2:47:02 PM net.jxta.impl.pipe.InputPipeImpl processIncomingMessage FINE: Received net.jxta.endpoint.Message@8066625(0){45,44} from jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 for urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 0 selected keys Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpTransport updateChannelRegisterations FINE: Registering 1 channels with MessengerSelectorThread 14:47:02.544|Executor - 5| ||AnnounceService|got announcement from saruman urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:02 PM net.jxta.impl.pipe.WirePipe callLocalListeners FINE: Called 1 of 1 local listeners for urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504 Oct 23, 2007 2:47:02 PM net.jxta.impl.pipe.WirePipe repropagate FINE: Repropagating net.jxta.endpoint.Message@7202313(2){46,44} on urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504 Oct 23, 2007 2:47:02 PM net.jxta.impl.pipe.NonBlockingWireOutputPipe INFO: Constructing for urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504 Oct 23, 2007 2:47:02 PM net.jxta.impl.pipe.WirePipe recordSeenMessage FINE: duplicate 0000000f-0000-1000-8014-eae96d47633a Oct 23, 2007 2:47:02 PM net.jxta.impl.cm.SrdiIndex query FINE: [pipeResolverSrdi] Querying for 2147483647 JxtaPropagate/Id = 'urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504' Oct 23, 2007 2:47:02 PM net.jxta.impl.cm.Cm getIndexQuery FINE: Index query operator :1 Oct 23, 2007 2:47:02 PM net.jxta.impl.cm.Indexer search FINE: Searching Index : JxtaPropagateId Oct 23, 2007 2:47:02 PM net.jxta.impl.cm.SrdiIndex$SearchCallback indexInfo FINE: Found urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504 Oct 23, 2007 2:47:02 PM net.jxta.impl.cm.SrdiIndex query FINE: [pipeResolverSrdi] Returning 2 results for JxtaPropagate/Id = 'urn:jxta:uuid-4D79507269764174A547B26F757000004D656E6F416E4E6FB56EA3655069706504' Oct 23, 2007 2:47:02 PM net.jxta.impl.pipe.WirePipe sendMessage FINE: Propagating net.jxta.endpoint.Message@18439211(0){47,46,44} to 1 subscriber peers. Oct 23, 2007 2:47:02 PM net.jxta.impl.rendezvous.StdRendezVousService propagate FINE: Propagating net.jxta.endpoint.Message@32643052(0){48,47,46,44}(TTL=1) to : svc name:jxta.service.wirepipe svc params:uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:47:02 PM net.jxta.impl.rendezvous.RendezVousServiceProvider updatePropHeader FINE: Updating propagation header (00000011-0000-1000-8014-eae96d47633a) TTL: 200-->1 Oct 23, 2007 2:47:02 PM net.jxta.impl.rendezvous.RendezVousServiceProvider updatePropHeader FINE: Updated prop header for net.jxta.endpoint.Message@32643052(0){48,47,46,44} (00000011-0000-1000-8014-eae96d47633a) TTL = 1 Oct 23, 2007 2:47:02 PM net.jxta.impl.rendezvous.StdRendezVousService propagate FINE: Sending net.jxta.endpoint.Message@32643052(2){48,47,46,44} (00000011-0000-1000-8014-eae96d47633a) to saruman C : 1193535 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.router.EndpointRouter addressMessage FINE: Create a new EndpointRouterMessage jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903/JxtaPropagate/uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.router.EndpointRouter getGatewayAddress FINE: Searching local & remote for route for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.router.EndpointRouter getGatewayAddress FINE: Found direct route for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 via tcp://64.231.244.79:60618 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.router.RouterMessenger sendMessageBImpl FINE: Sending net.jxta.endpoint.Message@6627600(1){49,48,47,46,44} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.router.EndpointRouter sendOnLocalRoute FINE: Sending net.jxta.endpoint.Message@6627600(1){49,48,47,46,44} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 via net.jxta.impl.endpoint.BlockingMessenger$BlockingMessengerChannel@16fdac {tcp://64.231.244.79:60618} Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger sendMessageDirect FINE: Sending net.jxta.endpoint.Message@6627600(3){49,48,47,46,44} to tcp://64.231.244.79:60618/EndpointService:uuid-4D79507269764174A547B26F757002/EndpointRouter on connection tcp://64.231.244.79:60618 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger xmitMessage FINE: Sending net.jxta.endpoint.Message@6627600(3){49,48,47,46,44} (2504) to tcp://69.159.39.151:9701 via 64.231.244.79:60618 Oct 23, 2007 2:47:02 PM net.jxta.impl.rendezvous.StdRendezVousService propagate FINE: Propagated net.jxta.endpoint.Message@32643052(2){48,47,46,44} (00000011-0000-1000-8014-eae96d47633a) to 1 peers. Oct 23, 2007 2:47:02 PM net.jxta.impl.pipe.WirePipe sendMessage FINE: Walking net.jxta.endpoint.Message@18439211(0){47,46,44} through peerview. Oct 23, 2007 2:47:02 PM net.jxta.impl.rendezvous.rdv.RdvPeerRdvService walk FINE: Undirected walk of net.jxta.endpoint.Message@13468632(0){50,47,46,44}(TTL=200) to : svc name:jxta.service.wirepipe svc params:uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:47:02 PM net.jxta.impl.rendezvous.limited.LimitedRangeWalker walkMessage FINE: Walking net.jxta.endpoint.Message@13468632(2){50,47,46,44} to urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000605/uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:47:02 PM net.jxta.impl.rendezvous.limited.LimitedRangeWalker walkMessage FINE: Creating new Walk Header for net.jxta.endpoint.Message@13468632(2){50,47,46,44} with TTL=200 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.tcp.TcpMessenger xmitMessage FINE: Sent 2,567 bytes net.jxta.endpoint.Message@6627600(3){49,48,47,46,44} successfully via 64.231.244.79:60,618 Oct 23, 2007 2:47:02 PM net.jxta.impl.endpoint.router.EndpointRouter sendOnLocalRoute FINE: Sent net.jxta.endpoint.Message@6627600(3){49,48,47,46,44} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 p -->p 14:47:05.092|main| ||ConversationService|Attempting to establish a connection to saruman 14:47:05.169|main| ||ConversationService|send PingMessage message to saruman Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeServiceImpl createInputPipe FINE: Create JxtaUnicast InputPipe for urn:jxta:uuid-4D79507269764174A547B26F757000005E1BF2B0960E421F9C909CB1A232205304 Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.InputPipeImpl INFO: Creating InputPipe for urn:jxta:uuid-4D79507269764174A547B26F757000005E1BF2B0960E421F9C909CB1A232205304 of type JxtaUnicast with listener Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeResolver register FINE: Registering local InputPipe for urn:jxta:uuid-4D79507269764174A547B26F757000005E1BF2B0960E421F9C909CB1A232205304 Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.SrdiIndex add FINE: [pipeResolverSrdi] Adding JxtaUnicast/Id = 'urn:jxta:uuid-4D79507269764174A547B26F757000005E1BF2B0960E421F9C909CB1A232205304' for urn:jxta:uuid-59616261646162614E504720503250331EE6AFE8F9E6494E85289921EFB0329403 Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.Indexer addToIndex FINE: looking up NameIndexer : JxtaUnicastId Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeResolver pushSrdi FINE: Replicating an add Pipe SRDI entry for pipe [urn:jxta:uuid-4D79507269764174A547B26F757000005E1BF2B0960E421F9C909CB1A232205304] of type JxtaUnicast Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeServiceImpl createOutputPipe FINE: Create JxtaUnicast OutputPipe for urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeServiceImpl addOutputPipeListener FINE: Adding pipe listener for pipe urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 and query 5 Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeResolver addListener FINE: adding listener for urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 / 5 Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeResolver sendPipeQuery FINE: Undirected query (5) for urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.SrdiIndex query FINE: [pipeResolverSrdi] Querying for 100 JxtaUnicast/Id = 'urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904' Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.Cm getIndexQuery FINE: Index query operator :1 Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.Indexer search FINE: Searching Index : JxtaUnicastId Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.SrdiIndex$SearchCallback indexInfo FINE: Found urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.SrdiIndex query FINE: [pipeResolverSrdi] Returning 1 results for JxtaUnicast/Id = 'urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904' Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeResolver sendPipeQuery FINE: Using SRDI cache results for directed query (5) for urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 Oct 23, 2007 2:47:05 PM net.jxta.impl.resolver.ResolverServiceImpl sendQuery FINE: sending query to resolver handler: JxtaPipeResolver Oct 23, 2007 2:47:05 PM net.jxta.impl.resolver.ResolverServiceImpl sendQuery FINE: Sending query with route info to urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.resolver.ResolverServiceImpl sendMessage FINE: No route info available to send a response Oct 23, 2007 2:47:05 PM net.jxta.impl.resolver.ResolverServiceImpl sendMessage FINE: Creating a messenger immediate for :jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903/urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002ORes Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl getCanonicalMessenger FINE: Get Messenger for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 by net.jxta.impl.resolver.ResolverServiceImpl.sendMessage(ResolverServiceImpl.java:1049) Oct 23, 2007 2:47:05 PM net.jxta.impl.resolver.ResolverServiceImpl sendMessage FINE: Sending net.jxta.endpoint.Message@15680772(1){52} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903/urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002ORes uuid-4D79507269764174A547B26F757002ORes Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter addressMessage FINE: Create a new EndpointRouterMessage jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903/urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002ORes Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter getGatewayAddress FINE: Searching local & remote for route for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter getGatewayAddress FINE: Found direct route for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 via tcp://64.231.244.79:60618 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.RouterMessenger sendMessageBImpl FINE: Sending net.jxta.endpoint.Message@15680772(2){52} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter sendOnLocalRoute FINE: Sending net.jxta.endpoint.Message@15680772(2){52} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 via net.jxta.impl.endpoint.BlockingMessenger$BlockingMessengerChannel@16fdac {tcp://64.231.244.79:60618} Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger sendMessageDirect FINE: Sending net.jxta.endpoint.Message@15680772(4){52} to tcp://64.231.244.79:60618/EndpointService:uuid-4D79507269764174A547B26F757002/EndpointRouter on connection tcp://64.231.244.79:60618 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger xmitMessage FINE: Sending net.jxta.endpoint.Message@15680772(4){52} (2181) to tcp://69.159.39.151:9701 via 64.231.244.79:60618 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger xmitMessage FINE: Sent 2,244 bytes net.jxta.endpoint.Message@15680772(4){52} successfully via 64.231.244.79:60,618 Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeResolver findLocal FINE: Find local InputPipe for urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 Oct 23, 2007 2:47:05 PM net.jxta.util.JxtaBiDiPipe connect FINE: Waiting for 10000 msec Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter sendOnLocalRoute FINE: Sent net.jxta.endpoint.Message@15680772(4){52} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.IncomingUnicastServer run INFO: Server accepted connection from 64.231.244.79:60,620 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger INFO: Connection from 64.231.244.79:60620 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.WelcomeMessage getByteBuffer FINE: Sending welcome message of size:148 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger startMessenger FINE: welcome message sent Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] State before read(): WELCOME, buffer stats : java.nio.HeapByteBuffer[pos=0 lim=4096 cap=4096], remaining :4,096 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 288 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=288 cap=4096], remaining 288 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=288 cap=4096], elements remaining 288 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.WelcomeMessage read FINE: Reading a buffer of size :288 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.WelcomeMessage read FINE: Buffer size :288 Welcome End-Of-Message pos :286 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.WelcomeMessage read FINE: buffer stats :java.nio.HeapByteBuffer[pos=288 lim=288 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.WelcomeMessage parseWelcome FINE: Successfuly parsed a welcome message :JXTAHELLO tcp://69.77.161.28:9701/EndpointService:uuid-4D79507269764174A547B26F757002/urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002IRes tcp://69.159.39.151:9701 urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 0 1.1 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processWelcome FINE: Creating a logical address from : JXTAHELLO tcp://69.77.161.28:9701/EndpointService:uuid-4D79507269764174A547B26F757002/urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002IRes tcp://69.159.39.151:9701 urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 0 1.1 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processWelcome FINE: Hello from tcp://69.159.39.151:9701 [urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processWelcome FINE: Registering Messenger from 64.231.244.79:60620 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl messengerReady FINE: New net.jxta.impl.endpoint.tcp.TcpMessenger@162ba99 {tcp://64.231.244.79:60620} for : tcp://64.231.244.79:60620 (jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903) Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl messengerReady FINE: New net.jxta.impl.endpoint.tcp.TcpMessenger@162ba99 {tcp://64.231.244.79:60620} for : tcp://64.231.244.79:60620 (jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903) Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.relay.RelayServer messengerReady FINE: messengerReady Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.Destinations$Wisdom addIncomingMessenger FINE: Accepted new incoming messenger for tcp://64.231.244.79:60620 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl messengerReady FINE: net.jxta.impl.endpoint.tcp.TcpTransport@2524dbad-->net.jxta.impl.endpoint.BlockingMessenger$BlockingMessengerChannel@c8c7d6 {tcp://64.231.244.79:60620} (tcp://69.77.161.28:9701/urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002IRes) claimed by net.jxta.impl.endpoint.router.EndpointRouter@b85c17 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl messengerReady FINE: net.jxta.impl.endpoint.tcp.TcpTransport@2524dbad-->net.jxta.impl.endpoint.tcp.TcpMessenger@162ba99 {tcp://64.231.244.79:60620} (tcp://69.77.161.28:9701/EndpointService:uuid-4D79507269764174A547B26F757002/urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002IRes) claimed by net.jxta.impl.endpoint.EndpointServiceImpl@6d2380 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 0 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport updateChannelRegisterations FINE: Registering 1 channels with MessengerSelectorThread Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 1 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: KeySet has 1 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] State before read(): HEADER, buffer stats : java.nio.HeapByteBuffer[pos=0 lim=4096 cap=4096], remaining :4,096 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 1,380 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096], remaining 1,380 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096], elements remaining 1,380 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] Processing message package header, buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.MessagePackageHeader readHeader FINE: Parsing Package Header from byte buffer :java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] setting current state to body, Buffer stats :java.nio.HeapByteBuffer[pos=63 lim=1380 cap=4096], remaining elements 1,317: Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] Proccessing Message Body. expecting 2,823, java.nio.HeapByteBuffer[pos=63 lim=1380 cap=4096] elements remaining 1,317 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] State before read(): BODY, buffer stats : java.nio.HeapByteBuffer[pos=1317 lim=4096 cap=4096], remaining :2,779 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 0 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport updateChannelRegisterations FINE: Registering 1 channels with MessengerSelectorThread Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 1 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: KeySet has 1 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] State before read(): BODY, buffer stats : java.nio.HeapByteBuffer[pos=1317 lim=4096 cap=4096], remaining :2,779 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 1,380 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=2697 cap=4096], remaining 2,697 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=2697 cap=4096], elements remaining 2,697 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] Proccessing Message Body. expecting 2,823, java.nio.HeapByteBuffer[pos=0 lim=2697 cap=4096] elements remaining 2,697 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] State before read(): BODY, buffer stats : java.nio.HeapByteBuffer[pos=2697 lim=4096 cap=4096], remaining :1,399 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 126 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=2823 cap=4096], remaining 2,823 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=2823 cap=4096], elements remaining 2,823 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] Proccessing Message Body. expecting 2,823, java.nio.HeapByteBuffer[pos=0 lim=2823 cap=4096] elements remaining 2,823 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.WireFormatMessageBinary$Instantiator fromBuffer FINE: Reading net.jxta.endpoint.Message@31701975(0){53} from java.nio.HeapByteBuffer[pos=0 lim=2823 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=2823 lim=2823 cap=4096], elements remaining 0 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] Processing message package header, buffer stats:java.nio.HeapByteBuffer[pos=2823 lim=2823 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.MessagePackageHeader readHeader FINE: Parsing Package Header from byte buffer :java.nio.HeapByteBuffer[pos=2823 lim=2823 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] maintaining current state at header, buffer stats :java.nio.HeapByteBuffer[pos=2823 lim=2823 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger$MessageProcessor run FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] calling EndpointService.demux(net.jxta.endpoint.Message@31701975(3){53}) Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl processIncomingMessage FINE: Calling listener for 'EndpointService:uuid-4D79507269764174A547B26F757002/urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002IRes' with net.jxta.endpoint.Message@31701975(5){53} Oct 23, 2007 2:47:05 PM net.jxta.impl.resolver.ResolverServiceImpl$DemuxResponse processIncomingMessage FINE: Demuxing a response from tcp://69.159.39.151:9701 Oct 23, 2007 2:47:05 PM net.jxta.impl.resolver.ResolverServiceImpl processResponse FINE: Process response to query #5 with JxtaPipeResolver Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeResolver processResponse FINE: got a response for '5' Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] State before read(): HEADER, buffer stats : java.nio.HeapByteBuffer[pos=0 lim=4096 cap=4096], remaining :4,096 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 0 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport updateChannelRegisterations FINE: Registering 1 channels with MessengerSelectorThread Oct 23, 2007 2:47:05 PM net.jxta.impl.discovery.DiscoveryServiceImpl publish FINE: Publishing a jxta:PA as Peers / uuid-4D79507269764174A547B26F757000006A7874613A504175B569A42D34443739B885F3FE00197694DEA787F1D91928DFC477CEF101 expiration : 7200000 lifetime :7200000 Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.Cm save FINE: Indexing {PeersName=saruman, PeersPID=urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903} at 1034 Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.Indexer addToIndex FINE: looking up NameIndexer : PeersName Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.Indexer addToIndex FINE: looking up NameIndexer : PeersPID Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.Cm save FINE: Stored {Name=saruman, PID=urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903} at 1034 Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeResolver processResponse FINE: DB Expiration 9223372036854775807 > 600000 overriding attempt to decrease lifetime Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeResolver callListener FINE: Calling Pipe resolver listener for urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.NonBlockingOutputPipe INFO: Constructing for urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.NonBlockingOutputPipe startServiceThread INFO: Thread start : Worker Thread for NonBlockingOutputPipe : urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 worker state : ACQUIREMESSENGER queue closed : false number in queue : 0 number queued : 0 number dequeued : 0 Oct 23, 2007 2:47:05 PM net.jxta.util.JxtaBiDiPipe connect FINE: Sending a backchannel message Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeServiceImpl removeOutputPipeListener FINE: Removing listener for query 5 Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.NonBlockingOutputPipe run FINE: NON-BLOCKING WORKER AT STATE : ACQUIREMESSENGER Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.NonBlockingOutputPipe run FINE: Getting messenger to 'urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903' for pipe urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl getCanonicalMessenger FINE: Get Messenger for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 by net.jxta.impl.pipe.NonBlockingOutputPipe.run(NonBlockingOutputPipe.java:528) Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.NonBlockingOutputPipe run FINE: NON-BLOCKING WORKER AT STATE : SENDMESSAGES 1200000 until verify. Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeResolver removeListener FINE: removing listener for urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 / 5 Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.NonBlockingOutputPipe send FINE: Queuing net.jxta.endpoint.Message@23826509(4){51} for pipe urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 Oct 23, 2007 2:47:05 PM net.jxta.util.JxtaBiDiPipe connect FINE: Waiting for 10000 msec for back channel to be established Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.NonBlockingOutputPipe run FINE: Sending net.jxta.endpoint.Message@23826509(4){51} on urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter addressMessage FINE: Create a new EndpointRouterMessage jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903/PipeService/urn:jxta:uuid-4D79507269764174A547B26F75700000CAF2B607F5FB40A3B527BC93D8D9CC1904 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter getGatewayAddress FINE: Searching local & remote for route for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter getGatewayAddress FINE: Found direct route for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 via tcp://64.231.244.79:60620 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.RouterMessenger sendMessageBImpl FINE: Sending net.jxta.endpoint.Message@23826509(5){51} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter sendOnLocalRoute FINE: Sending net.jxta.endpoint.Message@23826509(5){51} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 via net.jxta.impl.endpoint.BlockingMessenger$BlockingMessengerChannel@c8c7d6 {tcp://64.231.244.79:60620} Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger sendMessageDirect FINE: Sending net.jxta.endpoint.Message@23826509(7){51} to tcp://64.231.244.79:60620/EndpointService:uuid-4D79507269764174A547B26F757002/EndpointRouter on connection tcp://64.231.244.79:60620 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger xmitMessage FINE: Sending net.jxta.endpoint.Message@23826509(7){51} (2283) to tcp://69.159.39.151:9701 via 64.231.244.79:60620 Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.NonBlockingOutputPipe run FINE: NON-BLOCKING WORKER AT STATE : SENDMESSAGES 1199987 until verify. Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger xmitMessage FINE: Sent 2,346 bytes net.jxta.endpoint.Message@23826509(7){51} successfully via 64.231.244.79:60,620 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter sendOnLocalRoute FINE: Sent net.jxta.endpoint.Message@23826509(7){51} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.IncomingUnicastServer run INFO: Server accepted connection from 64.231.244.79:60,621 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger INFO: Connection from 64.231.244.79:60621 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.WelcomeMessage getByteBuffer FINE: Sending welcome message of size:148 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger startMessenger FINE: welcome message sent Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 2,5,Group urn:jxta:jxta-WorldGroup] State before read(): WELCOME, buffer stats : java.nio.HeapByteBuffer[pos=0 lim=4096 cap=4096], remaining :4,096 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 2,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 292 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=292 cap=4096], remaining 292 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 2,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=292 cap=4096], elements remaining 292 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.WelcomeMessage read FINE: Reading a buffer of size :292 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.WelcomeMessage read FINE: Buffer size :292 Welcome End-Of-Message pos :290 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.WelcomeMessage read FINE: buffer stats :java.nio.HeapByteBuffer[pos=292 lim=292 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.WelcomeMessage parseWelcome FINE: Successfuly parsed a welcome message :JXTAHELLO tcp://69.77.161.28:9701/EndpointService:uuid-4D79507269764174A547B26F757002/PipeService/urn:jxta:uuid-4D79507269764174A547B26F757000005E1BF2B0960E421F9C909CB1A232205304 tcp://69.159.39.151:9701 urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 0 1.1 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processWelcome FINE: Creating a logical address from : JXTAHELLO tcp://69.77.161.28:9701/EndpointService:uuid-4D79507269764174A547B26F757002/PipeService/urn:jxta:uuid-4D79507269764174A547B26F757000005E1BF2B0960E421F9C909CB1A232205304 tcp://69.159.39.151:9701 urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 0 1.1 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processWelcome FINE: Hello from tcp://69.159.39.151:9701 [urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processWelcome FINE: Registering Messenger from 64.231.244.79:60621 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl messengerReady FINE: New net.jxta.impl.endpoint.tcp.TcpMessenger@1de007d {tcp://64.231.244.79:60621} for : tcp://64.231.244.79:60621 (jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903) Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl messengerReady FINE: New net.jxta.impl.endpoint.tcp.TcpMessenger@1de007d {tcp://64.231.244.79:60621} for : tcp://64.231.244.79:60621 (jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903) Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.relay.RelayServer messengerReady FINE: messengerReady Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.Destinations$Wisdom addIncomingMessenger FINE: Accepted new incoming messenger for tcp://64.231.244.79:60621 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl messengerReady FINE: net.jxta.impl.endpoint.tcp.TcpTransport@2524dbad-->net.jxta.impl.endpoint.BlockingMessenger$BlockingMessengerChannel@1f243d1 {tcp://64.231.244.79:60621} (tcp://69.77.161.28:9701/PipeService/urn:jxta:uuid-4D79507269764174A547B26F757000005E1BF2B0960E421F9C909CB1A232205304) claimed by net.jxta.impl.endpoint.router.EndpointRouter@b85c17 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl messengerReady FINE: net.jxta.impl.endpoint.tcp.TcpTransport@2524dbad-->net.jxta.impl.endpoint.tcp.TcpMessenger@1de007d {tcp://64.231.244.79:60621} (tcp://69.77.161.28:9701/EndpointService:uuid-4D79507269764174A547B26F757002/PipeService/urn:jxta:uuid-4D79507269764174A547B26F757000005E1BF2B0960E421F9C909CB1A232205304) claimed by net.jxta.impl.endpoint.EndpointServiceImpl@6d2380 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 0 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport updateChannelRegisterations FINE: Registering 1 channels with MessengerSelectorThread Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 1 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: KeySet has 1 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] State before read(): HEADER, buffer stats : java.nio.HeapByteBuffer[pos=0 lim=4096 cap=4096], remaining :4,096 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 1,380 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096], remaining 1,380 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096], elements remaining 1,380 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] Processing message package header, buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.MessagePackageHeader readHeader FINE: Parsing Package Header from byte buffer :java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] setting current state to body, Buffer stats :java.nio.HeapByteBuffer[pos=63 lim=1380 cap=4096], remaining elements 1,317: Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] Proccessing Message Body. expecting 1,803, java.nio.HeapByteBuffer[pos=63 lim=1380 cap=4096] elements remaining 1,317 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] State before read(): BODY, buffer stats : java.nio.HeapByteBuffer[pos=1317 lim=4096 cap=4096], remaining :2,779 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 486 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1803 cap=4096], remaining 1,803 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1803 cap=4096], elements remaining 1,803 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] Proccessing Message Body. expecting 1,803, java.nio.HeapByteBuffer[pos=0 lim=1803 cap=4096] elements remaining 1,803 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.WireFormatMessageBinary$Instantiator fromBuffer FINE: Reading net.jxta.endpoint.Message@5825185(0){54} from java.nio.HeapByteBuffer[pos=0 lim=1803 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=1803 lim=1803 cap=4096], elements remaining 0 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] Processing message package header, buffer stats:java.nio.HeapByteBuffer[pos=1803 lim=1803 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.MessagePackageHeader readHeader FINE: Parsing Package Header from byte buffer :java.nio.HeapByteBuffer[pos=1803 lim=1803 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] maintaining current state at header, buffer stats :java.nio.HeapByteBuffer[pos=1803 lim=1803 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 1,5,Group urn:jxta:jxta-WorldGroup] State before read(): HEADER, buffer stats : java.nio.HeapByteBuffer[pos=0 lim=4096 cap=4096], remaining :4,096 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger$MessageProcessor run FINE: Thread[Executor - 5,5,Group urn:jxta:jxta-WorldGroup] calling EndpointService.demux(net.jxta.endpoint.Message@5825185(5){54}) Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl processIncomingMessage FINE: Calling listener for 'EndpointService:uuid-4D79507269764174A547B26F757002/EndpointRouter' with net.jxta.endpoint.Message@5825185(7){54} Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 0 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter processIncomingMessage FINE: Endpoint Router Message : src=jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 dest== jxta://uuid-59616261646162614E504720503250331EE6AFE8F9E6494E85289921EFB0329403/JxtaPropagate/uuid-4D79507269764174A547B26F757002 lastHop= jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 embedded radv= none Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport updateChannelRegisterations FINE: Registering 1 channels with MessengerSelectorThread Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl processIncomingMessage FINE: Calling listener for 'JxtaPropagate/uuid-4D79507269764174A547B26F757002' with net.jxta.endpoint.Message@5825185(8){54} Oct 23, 2007 2:47:05 PM net.jxta.impl.rendezvous.RendezVousServiceProvider processIncomingMessage FINE: Processing net.jxta.endpoint.Message@5825185(8){54}(00000012-0000-1000-8014-eae96d47633a) for urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002Srdi from jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.rendezvous.StdRendezVousService processReceivedMessage FINE: Received net.jxta.endpoint.Message@5825185(8){54} (00000012-0000-1000-8014-eae96d47633a) from saruman C : 1190434 Oct 23, 2007 2:47:05 PM net.jxta.impl.rendezvous.RendezVousServiceProvider processReceivedMessage FINE: Calling local listener net.jxta.impl.resolver.ResolverServiceImpl$DemuxSrdi for [urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002Srdi] with net.jxta.endpoint.Message@5825185(8){54} (00000012-0000-1000-8014-eae96d47633a) Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl processIncomingMessage FINE: Calling listener for 'urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000205/uuid-4D79507269764174A547B26F757002Srdi' with net.jxta.endpoint.Message@5825185(8){54} Oct 23, 2007 2:47:05 PM net.jxta.impl.resolver.ResolverServiceImpl$DemuxSrdi processIncomingMessage FINE: Demuxing an SRDI message from : jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.resolver.ResolverServiceImpl processSrdi FINE: Processing an SRDI msg for : JxtaPipeResolver in Group ID:urn:jxta:uuid-4D79507269764174A547B26F757002 Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.PipeResolver processSrdi FINE: Received an SRDI messsage with 1 entries from urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.SrdiIndex add FINE: [pipeResolverSrdi] Adding JxtaUnicast/Id = 'urn:jxta:uuid-4D79507269764174A547B26F757000001CE3DEF717374CB2A40ECFA905E5933A04' for urn:jxta:uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 1 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: KeySet has 1 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] State before read(): HEADER, buffer stats : java.nio.HeapByteBuffer[pos=0 lim=4096 cap=4096], remaining :4,096 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 1,380 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096], remaining 1,380 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096], elements remaining 1,380 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] Processing message package header, buffer stats:java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.cm.Indexer addToIndex FINE: looking up NameIndexer : JxtaUnicastId Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.MessagePackageHeader readHeader FINE: Parsing Package Header from byte buffer :java.nio.HeapByteBuffer[pos=0 lim=1380 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] setting current state to body, Buffer stats :java.nio.HeapByteBuffer[pos=63 lim=1380 cap=4096], remaining elements 1,317: Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] Proccessing Message Body. expecting 2,122, java.nio.HeapByteBuffer[pos=63 lim=1380 cap=4096] elements remaining 1,317 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 3,5,Group urn:jxta:jxta-WorldGroup] State before read(): BODY, buffer stats : java.nio.HeapByteBuffer[pos=1317 lim=4096 cap=4096], remaining :2,779 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 0 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport updateChannelRegisterations FINE: Registering 1 channels with MessengerSelectorThread Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 1 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: KeySet has 1 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] State before read(): BODY, buffer stats : java.nio.HeapByteBuffer[pos=1317 lim=4096 cap=4096], remaining :2,779 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] SocketChannel.read() == 805 bytes. Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=2122 cap=4096], remaining 2,122 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=0 lim=2122 cap=4096], elements remaining 2,122 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] Proccessing Message Body. expecting 2,122, java.nio.HeapByteBuffer[pos=0 lim=2122 cap=4096] elements remaining 2,122 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.WireFormatMessageBinary$Instantiator fromBuffer FINE: Reading net.jxta.endpoint.Message@10282147(0){55} from java.nio.HeapByteBuffer[pos=0 lim=2122 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processBuffer FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] processBuffer(class java.util.concurrent.atomic.AtomicReference). Buffer stats:java.nio.HeapByteBuffer[pos=2122 lim=2122 cap=4096], elements remaining 0 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] Processing message package header, buffer stats:java.nio.HeapByteBuffer[pos=2122 lim=2122 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.msgframing.MessagePackageHeader readHeader FINE: Parsing Package Header from byte buffer :java.nio.HeapByteBuffer[pos=2122 lim=2122 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger processHeader FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] maintaining current state at header, buffer stats :java.nio.HeapByteBuffer[pos=2122 lim=2122 cap=4096] Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger read FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] State before read(): HEADER, buffer stats : java.nio.HeapByteBuffer[pos=0 lim=4096 cap=4096], remaining :4,096 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger$MessageProcessor run FINE: Thread[Executor - 4,5,Group urn:jxta:jxta-WorldGroup] calling EndpointService.demux(net.jxta.endpoint.Message@10282147(5){55}) Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 0 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl processIncomingMessage FINE: Calling listener for 'EndpointService:uuid-4D79507269764174A547B26F757002/PipeService/urn:jxta:uuid-4D79507269764174A547B26F757000005E1BF2B0960E421F9C909CB1A232205304' with net.jxta.endpoint.Message@10282147(7){55} Oct 23, 2007 2:47:05 PM net.jxta.impl.pipe.InputPipeImpl processIncomingMessage FINE: Received net.jxta.endpoint.Message@10282147(7){55} from tcp://69.159.39.151:9701 for urn:jxta:uuid-4D79507269764174A547B26F757000005E1BF2B0960E421F9C909CB1A232205304 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport updateChannelRegisterations FINE: Registering 1 channels with MessengerSelectorThread Oct 23, 2007 2:47:05 PM net.jxta.util.JxtaBiDiPipe pipeMsgEvent FINE: Pipe message arrived Oct 23, 2007 2:47:05 PM net.jxta.util.JxtaBiDiPipe pipeMsgEvent FINE: Recevied a pipe Advertisement :saruman Oct 23, 2007 2:47:05 PM net.jxta.util.JxtaBiDiPipe pipeMsgEvent FINE: Recevied an Peer Advertisement :saruman Oct 23, 2007 2:47:05 PM net.jxta.util.JxtaBiDiPipe getDirectMessenger FINE: Creating a Direct Messenger Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger INFO: Creating new TCP Connection to : tcp://69.159.39.151:9701 / 69.159.39.151:9701 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger FINE: Connecting to 69.159.39.151:9701 via 0.0.0.0:0 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport getMessenger WARNING: Could not get messenger for tcp://69.159.39.151:9701/EndpointService:uuid-4D79507269764174A547B26F757002/PipeService/urn:jxta:uuid-4D79507269764174A547B26F757000001CE3DEF717374CB2A40ECFA905E5933A04 : Connection refused Oct 23, 2007 2:47:05 PM net.jxta.util.JxtaBiDiPipe lightweightOutputPipe FINE: Creating a lightweightOutputPipe() Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.EndpointServiceImpl getCanonicalMessenger FINE: Get Messenger for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 by net.jxta.util.JxtaBiDiPipe.lightweightOutputPipe(JxtaBiDiPipe.java:1090) Oct 23, 2007 2:47:05 PM net.jxta.util.JxtaBiDiPipe pipeMsgEvent FINE: Reliability set to :true Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport$MessengerSelectorThread run FINE: MessengerSelector has 0 selected keys Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpTransport updateChannelRegisterations FINE: Unregistering 1 channels with MessengerSelectorThread Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger closeImpl INFO: Normal close (open 18ms) of socket to : tcp://69.159.39.151:9701 / 69.159.39.151:9701 Oct 23, 2007 2:47:05 PM net.jxta.impl.util.pipe.reliable.ReliableInputStream INFO: Listener based ReliableInputStream created Oct 23, 2007 2:47:05 PM net.jxta.util.JxtaBiDiPipe setBound FINE: Pipe Bound :true 14:47:05.786|main| ||ConversationService|connected to saruman Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.WireFormatMessageBinary$binaryMessageProxy sendToStream FINE: Sending net.jxta.endpoint.Message@15865423(5){56} to java.io.ByteArrayOutputStream@26655428 Oct 23, 2007 2:47:05 PM net.jxta.impl.util.pipe.reliable.ReliableOutputStream$Retransmitter INFO: STARTED Reliable Retransmitter, RTO = 600000 Oct 23, 2007 2:47:05 PM net.jxta.impl.util.pipe.reliable.ReliableOutputStream writeBuffer FINE: Reliable WRITE : seqn#1 length=887 Oct 23, 2007 2:47:05 PM net.jxta.impl.util.pipe.reliable.ReliableOutputStream writeBuffer FINE: Retrans Enqueue added seqn#1 retrQ.size()=1 Oct 23, 2007 2:47:05 PM net.jxta.impl.util.pipe.reliable.OutgoingMsgrAdaptor send FINE: Sending a Message jmsg. 1 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter addressMessage FINE: Create a new EndpointRouterMessage jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903/PipeService/urn:jxta:uuid-4D79507269764174A547B26F757000001CE3DEF717374CB2A40ECFA905E5933A04 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter getGatewayAddress FINE: Searching local & remote for route for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter getGatewayAddress FINE: Found direct route for jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 via tcp://64.231.244.79:60621 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.RouterMessenger sendMessageBImpl FINE: Sending net.jxta.endpoint.Message@8254986(2){57} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter sendOnLocalRoute FINE: Sending net.jxta.endpoint.Message@8254986(2){57} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 via net.jxta.impl.endpoint.BlockingMessenger$BlockingMessengerChannel@1f243d1 {tcp://64.231.244.79:60621} Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger sendMessageDirect FINE: Sending net.jxta.endpoint.Message@8254986(4){57} to tcp://64.231.244.79:60621/EndpointService:uuid-4D79507269764174A547B26F757002/EndpointRouter on connection tcp://64.231.244.79:60621 Oct 23, 2007 2:47:05 PM net.jxta.impl.util.pipe.reliable.ReliableOutputStream writeBuffer FINE: SENT : seqn#1 length=887 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger xmitMessage FINE: Sending net.jxta.endpoint.Message@8254986(4){57} (1752) to tcp://69.159.39.151:9701 via 64.231.244.79:60621 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.tcp.TcpMessenger xmitMessage FINE: Sent 1,815 bytes net.jxta.endpoint.Message@8254986(4){57} successfully via 64.231.244.79:60,621 Oct 23, 2007 2:47:05 PM net.jxta.impl.endpoint.router.EndpointRouter sendOnLocalRoute FINE: Sent net.jxta.endpoint.Message@8254986(4){57} to jxta://uuid-59616261646162614E504720503250337F28AA3ECF504A35942EBB3C5BDFCD4903 Oct 23, 2007 2:47:05 PM net.jxta.impl.util.pipe.reliable.ReliableOutputStream$Retransmitter run FINE: lastAccessed=1193165225753 idle for 152