Skip to main content

JXSE 2.6 issue

48 replies [Last post]
galato
Offline
Joined: 2007-07-06
Points: 0

After a jxse or a jxme peer connects to the rdv/rly and the connection is successful, during the discovery loop where the peer is looking for advertisements from the rdv it gets nothing back even though there is a pipe advertised there and the rdv prints the following message over and over each time a peer contacts it for advertisements:

RDV(Thread[PeerToPeerAdapter,5,main]): Has 1 peers connected to it

Apr 21, 2010 11:35:20 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Error in sending response
java.lang.NullPointerException

The code does not print the exception but I can trace it here:
net.jxta.impl.resolver.ResolverServiceImpl.java in routine sendResponse @ line 582.

Has anyone else had this issue with 2.6? Bare in mind the peers I am getting
these on are peers that work successfully with the 2.5.1 libs.

Thanks

Reply viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.
adamman71
Offline
Joined: 2007-01-31
Points: 0

I know what is happening. I have removed core protocols from the NPG, because they should only operate in the WPG:

// High-level Message Transports.
paramAdv.addProto(PeerGroup.routerProtoClassID, PeerGroup.refRouterProtoSpecID);
// paramAdv.addProto(PeerGroup.tlsProtoClassID, PeerGroup.refTlsProtoSpecID);
// paramAdv.addProto(CbJxDefs.msgtptClassID, CbJxDefs.cbjxMsgTransportSpecID);
// paramAdv.addProto(PeerGroup.relayProtoClassID, PeerGroup.refRelayProtoSpecID);

But, peers connect at the NPG level. I don't really know why the EndpointRouter should be registered at the WPG level from the NPG level (since the WPG has registered its own EndpointRouter listener) for JXME peers, but it does not look like real harm.

I have reactivated it at the NPG level and from tracing the code in debug mode, I see that a EndpointService:jxta-NetGroup/EndpointRouter listener is registered in the new .jar I have posted at the usual place.

That being said, if your JXME peers try to establish a secured connection at the NPG level, I would expect issues...

galato
Offline
Joined: 2007-07-06
Points: 0

Hey Jerome,

that's good info, thanks - so you suggest that JXME peers should connect only at the WPG level?

Regarding the new jar I am getting this on peer initialization:

Exception in thread "main" java.lang.NoClassDefFoundError: net/jxta/pipe/PipeMsgListener
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClassCond(Unknown Source)
at java.lang.ClassLoader.defineClass(Unknown Source)
at java.security.SecureClassLoader.defineClass(Unknown Source)
at java.net.URLClassLoader.defineClass(Unknown Source)
at java.net.URLClassLoader.access$000(Unknown Source)
at java.net.URLClassLoader$1.run(Unknown Source)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(Unknown Source)
at java.lang.ClassLoader.loadClass(Unknown Source)
at sun.misc.Launcher$AppClassLoader.loadClass(Unknown Source)
at java.lang.ClassLoader.loadClass(Unknown Source)
Caused by: java.lang.ClassNotFoundException: net.jxta.pipe.PipeMsgListener
at java.net.URLClassLoader$1.run(Unknown Source)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(Unknown Source)
at java.lang.ClassLoader.loadClass(Unknown Source)
at sun.misc.Launcher$AppClassLoader.loadClass(Unknown Source)
at java.lang.ClassLoader.loadClass(Unknown Source)
... 12 more

galato
Offline
Joined: 2007-07-06
Points: 0

Cancel that - my bad. A strange NFS issue with my nodes here so the jar didn't get updated correctly. It's fine now and the JXSE 2.6 peers connect to the 2.6 RDV in the same LAN.

First test with a peer behind a NAT (same exact peer as the one that I ran in the same LAN with the RDV) gives the following:

May 18, 2010 11:07:28 PM net.jxta.impl.endpoint.netty.NettyTransportClient getMessenger
INFO: Netty transport for protocol tcp failed to connect to tcp://128.20.32.192:9502/EndpointService:jxta-NetGroup/uuid-DEADBEEFDEAF... - Connection refused: no further information
May 18, 2010 11:07:29 PM net.jxta.logging.Logging logCheckedInfo
INFO: processing request to open connection to tcp://129.10.62.192:9501
May 18, 2010 11:07:30 PM net.jxta.impl.endpoint.netty.NettyTransportClient getMessenger
INFO: Netty transport for protocol tcp failed to connect to tcp://128.20.32.192:9501 - Connection refused: no further information
May 18, 2010 11:07:44 PM net.jxta.logging.Logging logCheckedInfo
INFO: processing request to open connection to tcp://128.20.32.192:9501
May 18, 2010 11:07:45 PM net.jxta.impl.endpoint.netty.NettyTransportClient getMessenger
INFO: Netty transport for protocol tcp failed to connect to tcp://128.20.32.192:9501 - Connection refused: no further information
May 18, 2010 11:07:57 PM net.jxta.logging.Logging logCheckedInfo
INFO: processing request to open connection to tcp://129.20.32.192:9502/EndpointService:jxta-NetGroup/uuid-DEADBEEFDEAF...
May 18, 2010 11:07:58 PM net.jxta.impl.endpoint.netty.NettyTransportClient getMessenger
INFO: Netty transport for protocol tcp failed to connect to tcp://128.20.32.192:9502/EndpointService:jxta-NetGroup/uuid-DEADBEEFDEAF... - Connection refused: no further information
May 18, 2010 11:07:59 PM net.jxta.logging.Logging logCheckedInfo
INFO: processing request to open connection to tcp://128.20.32.192:9501
May 18, 2010 11:08:00 PM net.jxta.impl.endpoint.netty.NettyTransportClient getMessenger
INFO: Netty transport for protocol tcp failed to connect to tcp://128.20.32.192:9501 - Connection refused: no further information

adamman71
Offline
Joined: 2007-01-31
Points: 0

About JXME peers, I really don't know. I know nothing about the JXME code...

About the test behind the NAT, can you indicate which TCP address belongs to which peer/LAN? I do not have enough information to understand what is happening. Thanks !!

galato
Offline
Joined: 2007-07-06
Points: 0

Sorry - my bad -

the IP address assigned to the peer behind the NAT is as expected 192.168.1.xx (43 in my case) and the IP address that you saw listed was the IP address of the public RDV/RLY - I isolated the error to the following couple of lines. The peer behind the NAT adds the seeds using:

config.addSeedRendezvous(new URI("tcp://128.20.32.192:9501"));
config.addSeedRelay(new URI("tcp://128.20.32.192:9502"));

And the result on the peer behind the NAT is what you saw:

May 18, 2010 11:07:28 PM net.jxta.impl.endpoint.netty.NettyTransportClient getMessenger
INFO: Netty transport for protocol tcp failed to connect to tcp://128.20.32.192:9502/EndpointService:jxta-NetGroup/uuid-DEADBEEFDEAF... - Connection refused: no further information
May 18, 2010 11:07:29 PM net.jxta.logging.Logging logCheckedInfo
INFO: processing request to open connection to tcp://128.20.32.192:9501

If I switch the libs to 2.5 then the above peer without any changes connects to the RDV/RLY at the above address. If this does not help let me know and I will see what else I can do.

Regarding the JXME peers although I understand that you don't know much about them I think its code was derived by the JXTA baseline so I am expecting the routing to be fairly similar. Since you have experience in this within the JXSE code may be you can tell me where I should be looking into and what I should look for and I will see if I can chase it in the JXME code. I tried following up on what Mohamed and Daniel B were suggesting but not knowing much about that part of the code didn't yield any results.

adamman71
Offline
Joined: 2007-01-31
Points: 0

It is the relayProtoClassID causing an issue now. I have reactivated all 4 protocols at the NPG level. I hate to do this, but... New .jar at same location.

// High-level Message Transports.
paramAdv.addProto(PeerGroup.routerProtoClassID, PeerGroup.refRouterProtoSpecID);
paramAdv.addProto(PeerGroup.tlsProtoClassID, PeerGroup.refTlsProtoSpecID);
paramAdv.addProto(CbJxDefs.msgtptClassID, CbJxDefs.cbjxMsgTransportSpecID);
paramAdv.addProto(PeerGroup.relayProtoClassID, PeerGroup.refRelayProtoSpecID);

I think there has been many modifications in JXTA since JXME code was created. One things for sure, the class implementation for the NPG have changed and I am pretty sure these won't match JXME 100%. Problem is that we need someone to invest time in JXME to make code up-to-date with latest development on that side...

galato
Offline
Joined: 2007-07-06
Points: 0

Ok I will give it a shot.

I agree - unless someone brings the JXME code up to date with where the JXSE is it will always lack. I know Nick (buzz lightyear) was starting to look into authentication for JXME but I am not sure how deep he will be going or much time he has. I wish I could invest the time (and I will try to get educated more on that baseline) but with two projects lurking it will take me a while to even get started. Unless I manage to make the project that depends on JXME a priority we'll see.

I still find it interesting (and you will see it in the spreadsheet when I send it back) that JXME peers behind NAT can communicate with JXSE 2.5 peers with no problems. Why would this case work at all anyway if anything else fails. Anyway I will keep digging.

adamman71
Offline
Joined: 2007-01-31
Points: 0

To summarize email exchanges:

i) I will not include latest JXME modifications in beta 3, because they don't solve the JXME RDV/Relay connectivity issues with 2.6 JXTA peers.
ii) It is now clear that we need someone to work on the JXME 2.4.1 code base to make it 'compatible' with the JXTA 2.6 baseline.
iii) I have created a task issue to keep track of the situation. I have attached the 'connectivity' OpenOffice XL sheet to it (c.f. https://jxta-jxse.dev.java.net/issues/show_bug.cgi?id=377).

That is as far as we can go with JXME peers for now.

galato
Offline
Joined: 2007-07-06
Points: 0

However, two JXSE 2.6 peers (not behind NAT) can connect with the 2.6 RDV/RLY, advertise their pipes and find each other's server pipes. One of the peers throws this two consecutive exceptions before connecting so I thought I would list it here in case it sheds some more light on an issue in the code. The JXME connectivity which is very crucial to what I need to do is still a big issue either in 2.5 and in 2.6:

May 18, 2010 2:32:25 PM net.jxta.impl.util.threads.LongTaskDetector run
WARNING: task of type [net.jxta.impl.endpoint.netty.NettyMessenger$1] still running after 2,305ms in thread JxtaWorker-3 , current stack:
java.lang.Throwable.getStackTraceElement(Native Method)
java.lang.Throwable.getOurStackTrace(Throwable.java:591)
java.lang.Throwable.getStackTrace(Throwable.java:582)
net.jxta.logging.Logging.logCheckedFine(Logging.java:239)
net.jxta.impl.cm.XIndiceAdvertisementCache.save(XIndiceAdvertisementCache.java:735)
net.jxta.impl.cm.CacheManager.save(CacheManager.java:274)
net.jxta.impl.discovery.DiscoveryServiceImpl.publish(DiscoveryServiceImpl.java:736)
net.jxta.impl.rendezvous.edge.EdgePeerRdvService.processConnectedReply(EdgePeerRdvService.java:731)
net.jxta.impl.rendezvous.edge.EdgePeerRdvService.access$200(EdgePeerRdvService.java:117)
net.jxta.impl.rendezvous.edge.EdgePeerRdvService$StdRdvEdgeProtocolListener.processIncomingMessage(EdgePeerRdvService.ja va:240)
net.jxta.impl.endpoint.EndpointServiceImpl.processIncomingMessage(EndpointServiceImpl.java:1027)
net.jxta.impl.endpoint.router.EndpointRouter.processIncomingMessage(EndpointRouter.java:1657)
net.jxta.impl.endpoint.EndpointServiceImpl.processIncomingMessage(EndpointServiceImpl.java:1027)
net.jxta.impl.endpoint.netty.NettyMessenger$1.run(NettyMessenger.java:148)
net.jxta.impl.util.threads.RunnableAsCallableWrapper.call(RunnableAsCallableWrapper.java:17)
net.jxta.impl.util.threads.RunMetricsWrapper.call(RunMetricsWrapper.java:50)
net.jxta.impl.util.threads.QueueTimeRunMetricsWrapper.call(QueueTimeRunMetricsWrapper.java:34)
net.jxta.impl.util.threads.RunMetricsWrapper.run(RunMetricsWrapper.java:93)
net.jxta.impl.util.threads.QueueTimeRunMetricsWrapper.run(QueueTimeRunMetricsWrapper.java:9)
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
java.lang.Thread.run(Unknown Source)

May 18, 2010 2:32:25 PM net.jxta.impl.util.threads.LongTaskDetector run
WARNING: task of type [net.jxta.impl.endpoint.netty.NettyMessenger$1] still running after 2,303ms in thread JxtaWorker-4 , current stack:
net.jxta.impl.xindice.core.filer.Paged$Page.read(Paged.java:1377)
net.jxta.impl.xindice.core.filer.Paged.getPage(Paged.java:326)
net.jxta.impl.xindice.core.filer.BTreeFiler.readRecord(BTreeFiler.java:145)
net.jxta.impl.xindice.core.filer.BTreeFiler.readRecord(BTreeFiler.java:131)
net.jxta.impl.cm.XIndiceAdvertisementCache.save(XIndiceAdvertisementCache.java:721)
net.jxta.impl.cm.CacheManager.save(CacheManager.java:274)
net.jxta.impl.discovery.DiscoveryServiceImpl.publish(DiscoveryServiceImpl.java:736)
net.jxta.impl.rendezvous.edge.EdgePeerRdvService.processConnectedReply(EdgePeerRdvService.java:731)
net.jxta.impl.rendezvous.edge.EdgePeerRdvService.access$200(EdgePeerRdvService.java:117)
net.jxta.impl.rendezvous.edge.EdgePeerRdvService$StdRdvEdgeProtocolListener.processIncomingMessage(EdgePeerRdvService.ja va:240)
net.jxta.impl.endpoint.EndpointServiceImpl.processIncomingMessage(EndpointServiceImpl.java:1027)
net.jxta.impl.endpoint.router.EndpointRouter.processIncomingMessage(EndpointRouter.java:1657)
net.jxta.impl.endpoint.EndpointServiceImpl.processIncomingMessage(EndpointServiceImpl.java:1027)
net.jxta.impl.endpoint.netty.NettyMessenger$1.run(NettyMessenger.java:148)
net.jxta.impl.util.threads.RunnableAsCallableWrapper.call(RunnableAsCallableWrapper.java:17)
net.jxta.impl.util.threads.RunMetricsWrapper.call(RunMetricsWrapper.java:50)
net.jxta.impl.util.threads.QueueTimeRunMetricsWrapper.call(QueueTimeRunMetricsWrapper.java:34)
net.jxta.impl.util.threads.RunMetricsWrapper.run(RunMetricsWrapper.java:93)
net.jxta.impl.util.threads.QueueTimeRunMetricsWrapper.run(QueueTimeRunMetricsWrapper.java:9)
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
java.lang.Thread.run(Unknown Source)

adamman71
Offline
Joined: 2007-01-31
Points: 0

OK. Great news for the JXTA peers' connection. Can't wait for your findings behind NAT. I'll take a deeper look at the JXME issue and let you know. The WARNING are performance info (pointers to what could be improved). Thanks for the info.

adamman71
Offline
Joined: 2007-01-31
Points: 0

I know what is happening. When building the .jar with Ant, it does not include OSGi properties files properly, but it does when using Maven. I bet you have a NPE earlier in your log file.

I have created a new .jar with the .properties files, still at: http://kenai.com/projects/jxse/pages/26BetaRel.

I have started JXTA using OSGi and I don't encounter the issue you mention. Let me know if you still do.

neunzert
Offline
Joined: 2010-04-26
Points: 0

Yes, I have the NPE at first. This problem starts with version jxse-10-May-2005 and is still in jxta16May2010.jar. With older versions I have no problems by starting.

Log from the version jxta16May2010:

Exception in startApp() : net.jxta.impl.rendezvous.RendezVousServiceImpl@53d3cf
java.lang.NullPointerException
Line 348 net.jxta.logging.Logging.checkForThrowables()
Line 294 net.jxta.logging.Logging.logCheckedInfo()
Line 509 net.jxta.impl.rendezvous.rpv.PeerView.()
Line 232 net.jxta.impl.rendezvous.rdv.RdvPeerRdvService.()
Line 345 net.jxta.impl.rendezvous.RendezVousServiceImpl.startApp()
Line 438 net.jxta.impl.peergroup.StdPeerGroup.startModules()
Line 648 net.jxta.impl.peergroup.StdPeerGroup.initFirst()
Line 151 net.jxta.impl.peergroup.ShadowPeerGroup.initFirst()
Line 968 net.jxta.impl.peergroup.GenericPeerGroup.init()
Line 737 net.jxta.impl.peergroup.GenericPeerGroup.loadModule()
Line 684 net.jxta.impl.peergroup.GenericPeerGroup.loadModule()
Line 452 net.jxta.impl.peergroup.PeerGroupInterface.loadModule()
Line 436 net.jxta.peergroup.NetPeerGroupFactory.newNetPeerGroup()
Line 216 net.jxta.peergroup.NetPeerGroupFactory.()
Line 410 net.jxta.platform.NetworkManager.startNetwork()
Line 187 dipl.cxfJxtaAdapter.peer.JxtaPeerImpl.start()
Line 83 dipl.cxfJxtaAdapter.peer.JxtaPeerImpl.()
Line 114 dipl.cxfJxtaAdapter.Activator.updated()
Line 959 org.apache.felix.cm.impl.ConfigurationManager$ManagedServiceUpdate.run()
Line 88 org.apache.felix.cm.impl.UpdateThread.run()

adamman71
Offline
Joined: 2007-01-31
Points: 0

Indeed there was a second bug. Sorry, it did not show in my tests for the first bug. I have uploaded a new .jar with the 2nd patch.

neunzert
Offline
Joined: 2010-04-26
Points: 0

Hi,

sorry that I bother you once again I tried to run my software with the new version and failed again, after that I tried it in a non OSGi environment and everything runs fine, have you tested the new version with Felix? When not it would be very good for me to know if it works.

Thanks a lot for your work here in the forum.

Bernd

SCHWERWIEGEND: No progress is being made in starting services after 7 iterations. Giving up.
The following services could not be started :
urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000305 : net.jxta.impl.discovery.DiscoveryServiceImpl@10b23cf
urn:jxta:uuid-DEADBEEFDEAFBABAFEEDBABE0000000405 : net.jxta.impl.pipe.PipeServiceImpl@5c2a25
13.05.2010 01:44:26 net.jxta.logging.Logging logCheckedSevere
SCHWERWIEGEND: Line 745 net.jxta.impl.peergroup.GenericPeerGroup.loadModule()
net.jxta.exception.PeerGroupException: Failed to start peer group services. res : -1Line 651 net.jxta.impl.peergroup.StdPeerGroup.initFirst()
Line 151 net.jxta.impl.peergroup.ShadowPeerGroup.initFirst()
Line 968 net.jxta.impl.peergroup.GenericPeerGroup.init()
Line 737 net.jxta.impl.peergroup.GenericPeerGroup.loadModule()
Line 684 net.jxta.impl.peergroup.GenericPeerGroup.loadModule()
Line 452 net.jxta.impl.peergroup.PeerGroupInterface.loadModule()
Line 436 net.jxta.peergroup.NetPeerGroupFactory.newNetPeerGroup()
Line 216 net.jxta.peergroup.NetPeerGroupFactory.()
Line 410 net.jxta.platform.NetworkManager.startNetwork()

adamman71
Offline
Joined: 2007-01-31
Points: 0

Hi Bernd, you are absolutely not bothering me at all. All your feedback is very welcome. To answer your question, no, I did not try to run the code from Felix. I will check this, now that I am 'back in the office'.

Thanks.

galato
Offline
Joined: 2007-07-06
Points: 0

That's good that someone else can verify that there is an error there since I am stuck messing around with debugging. I tried the same debug code, same libraries, same classpaths, both on Linux and on Windows and yet all I get is WARNING and INFO messages and not the FINE or FINER flags to work. I am wondering if the fact that I am using the app code that was once compiled with 2.5.1 (now is compiled with 2.6) presents such an issue - it shouldn't since it uses the java.util.logging.*.

Anyway, neunzart (is this your name?), you gets WARNUNG as a string - does that occur somewhere else in the code than the WARNING I get or is that a typo on your part?

Thanks

neunzert
Offline
Joined: 2010-04-26
Points: 0

I think not, it's exactly the same. (only in german)

For your problem with the logger just but

Logger.getLogger("net.jxta").setLevel(Level.FINER);

in your code, than it doesn't bother what is standing in the properties.

Bernd

galato
Offline
Joined: 2007-07-06
Points: 0

Hi Bernd,

I already have the right code segments (the Logger calls as you have it below) in my code but that didn't help. It is curious that I can see WARNING and INFO messages but I don't see FINE ,FINER etc. I removed all references to jxta.net.logging, cleaneup all the classpath, etc. Something is strange either at the OS/runtime level or in the code that I need to figure out.

I will let you know - this may be a topic for another thread anyway so I will stop it here - thanks.

adamman71
Offline
Joined: 2007-01-31
Points: 0

toString() on a null object is not going to help of course...

New .jar available at the same location.

I start an EDGE and a RDV from OSGi successfully and they connect. I also perform local publication and remote fetching. I don't get the reported errors.

neunzert
Offline
Joined: 2010-04-26
Points: 0

Now everything works well and finding the advs is faster than in 2.5.

Thanks, you're the best...

galato
Offline
Joined: 2007-07-06
Points: 0

That's excellent news - I am going to also try the latest code on my apps and let you know how it fairs. I will also include tests on the NAT issue even though as Jerome pointed out it may not be helping there. Since the biggest issue I had was to get two mobile devices (running MIDP2/CLDC JXME) which otherwise work if they are mixed with JXSE devices I am hoping the RDV 2.6 can help. Let's see ...

galato
Offline
Joined: 2007-07-06
Points: 0

I have been using these peers with 2.5 without issues on the authentication and I didn't change the code that does all that. With the latest 2.6 I am getting the issue below. I didn't get this with the previous 2.6 baselines that Jerome posted so far. Any ideas?

The peers prints the following:

[Thread[PeerToPeerAdapter,5,main]] is attempting to become a rendezvous for NetPeerGroup ...
===> Became rendezvous for group=[NetPeerGroup]
Group membership service is not PSE. (None Membership Service)
Exiting the application...

The code in the app where it quits is:

private void authenticateToPSE() {
MembershipService membershipService = null;
PSEMembershipService pseMembershipService = null;
String passwordString;

try {
// Get the MembershipService
membershipService = netpeergroup.getMembershipService();

// Checking if PSEMembershipService is initialized
if( !(membershipService instanceof PSEMembershipService) ) {
ModuleImplAdvertisement mia = (ModuleImplAdvertisement) membershipService.getImplAdvertisement();
System.out.println("Group membership service is not PSE. (" + mia.getDescription() + ")");
System.out.println("Exiting the application...");
System.exit(1);
}
// Get the PSEMemberhipService for authentication process
pseMembershipService = (PSEMembershipService) membershipService;

adamman71
Offline
Joined: 2007-01-31
Points: 0

The message you get makes sense. According to the specs, the NetPeerGroup and the WorldPeerGroup should welcome everyone. I have changed the membership service of the NPG to NoneMembershipService in commit 901, following rev 521 (see ShadowPeerGroup class for more details).

So, you need to remove your (membershipService instanceof PSEMembershipService) check for the NPG.

The PSE membership remains the default for other groups.

galato
Offline
Joined: 2007-07-06
Points: 0

I had to change a few more things other than the check so that the flow of code is the authentication routine is based solely on the MembershipService and not on the PSEMembershipService (casts etc.) and it worked as expected - thanks Jerome, I am going to go on and test the connectivity across NATs with the mobile devices now using the 2.6 RDV/RLY and see how things fair. I will let this thread know how it goes.

Once again thanks for keeping up with this ...

galato
Offline
Joined: 2007-07-06
Points: 0

When the two JXME peers attempt to connect to the 2.6 RDV/RLY (the latest beta jar) I get the following - no pipes manage to get advertised by any of the peers, If I switch the
RDV/RLY back to the 2.5 version the peers can connect (I am not even testing NAT yet):

May 18, 2010 3:32:12 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Line 1005 net.jxta.impl.endpoint.EndpointServiceImpl.processIncomingMessage()
No listener for 'tcp://128.40.32.192:9501/EndpointService:jxta-NetGroup/EndpointRouter' in group urn:jxta:jxta-WorldGroup "World PeerGroup"[1,24537094] / [4791372]
decodedServiceName :EndpointService:jxta-NetGroup/EndpointRouter decodedServiceParam :
May 18, 2010 3:32:13 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Line 1005 net.jxta.impl.endpoint.EndpointServiceImpl.processIncomingMessage()
No listener for 'tcp://128.40.32.192:9501/EndpointService:jxta-NetGroup/EndpointRouter' in group urn:jxta:jxta-WorldGroup "World PeerGroup"[1,24537094] / [4791372]
decodedServiceName :EndpointService:jxta-NetGroup/EndpointRouter decodedServiceParam :
May 18, 2010 3:32:14 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Line 1005 net.jxta.impl.endpoint.EndpointServiceImpl.processIncomingMessage()
No listener for 'tcp://128.40.32.192:9501/EndpointService:jxta-NetGroup/EndpointRouter' in group urn:jxta:jxta-WorldGroup "World PeerGroup"[1,24537094] / [4791372]
decodedServiceName :EndpointService:jxta-NetGroup/EndpointRouter decodedServiceParam :
May 18, 2010 3:32:15 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Line 1005 net.jxta.impl.endpoint.EndpointServiceImpl.processIncomingMessage()
No listener for 'tcp://128.40.32.192:9501/EndpointService:jxta-NetGroup/EndpointRouter' in group urn:jxta:jxta-WorldGroup "World PeerGroup"[1,24537094] / [4791372]
decodedServiceName :EndpointService:jxta-NetGroup/EndpointRouter decodedServiceParam :

adamman71
Offline
Joined: 2007-01-31
Points: 0

OK. Taking a look at it.

adamman71
Offline
Joined: 2007-01-31
Points: 0

Do you get this issue with JXTA peers? If not, can you already perform tests behind NATs to save time? Thanks !!!

galato
Offline
Joined: 2007-07-06
Points: 0

Hi Jerome,

I just posted what happens with the JXTA peers. Regarding testing them behind NAT I will do that in a few hours from a different location. I don't have that capability here but I do have two NAted networks in a controlled environment where I can do this testing easily
and let you know what happens.

Thanks much

fesaab
Offline
Joined: 2009-07-10
Points: 0

Hi, I'm getting this same problem and I tried to access the pre-alpha branch but it is password protected...

Is there any way to I get the new jar ? (I'm doing a college work... whether it's possible I really need it fast..).

Thanks a lot!

adamman71
Offline
Joined: 2007-01-31
Points: 0

A .jar has been made available at: http://kenai.com/projects/jxse/pages/26BetaRel.

neunzert
Offline
Joined: 2010-04-26
Points: 0

Hi,

it looks a little different now, but in my system the exception is still there.

Let me know what you need to solve the problem.

Thanks, for your work.

Bernd

10.05.2010 22:33:23 net.jxta.logging.Logging logCheckedWarning
WARNUNG: Line 608 net.jxta.impl.resolver.ResolverServiceImpl.sendResponse()
Error in sending response
java.lang.NullPointerException

adamman71
Offline
Joined: 2007-01-31
Points: 0

Uh....

I have posted a new .jar that should display more LOG info (still at http://kenai.com/projects/jxse/pages/26BetaRel). Can you run it in your environment and show the log? The stack traces should be displayed.

Thanks.

adamman71
Offline
Joined: 2007-01-31
Points: 0

Problem solved. I have committed a patch on the 2.6-pre-alpha branch. We will release beta 3 including it soon.

galato
Offline
Joined: 2007-07-06
Points: 0

Excellent new - thanks Jerome, I will run the beta once it is out.

neunzert
Offline
Joined: 2010-04-26
Points: 0

Hi,
I have the same problems with a very simple code example.
I took the code from the connectivity tutorial but RENDEZVOUS A together with the Modul Advertisement from the ServiceServer (publish and publish remote) and have problems after publishing the adv.
I switched to finer but there is are a lot of lines, here are the last 30.

FEIN: Responding to query #3 urn:jxta:uuid-59616261646162614E5047205032503352454E44455A464F9553A04103
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Searching for "!DOCTYPE" in range [0,118]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Search for "!DOCTYPE" [0,118]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Searching for "" in range [71,118]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Found element : "!DOCTYPE" [39,70]:[71,118]:[-1,-1]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Searching for "jxta:ResolverResponse" in range [71,118]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Search for "jxta:ResolverResponse" [71,118]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Searching for "" in range [95,118]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Prospective tag pair for "jxta:ResolverResponse" [72,94]:[95,118]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Recursing to search for "jxta:ResolverResponse" in [95,94]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Searching for "jxta:ResolverResponse" in range [95,94]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Search for "jxta:ResolverResponse" [95,94]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Tag "jxta:ResolverResponse" Not Found(2)
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Recursion result "jxta:ResolverResponse" [-1,-1]:[-1,-1]:[-1,-1]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Prospective tag "jxta:ResolverResponse" [95,118] is confirmed.
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Found element : "jxta:ResolverResponse" [72,94]:[95,94]:[95,118]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Scanning for children in range [95,94]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: Searching for "" in range [95,94]
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedFiner
FEINER: No tag found
28.04.2010 02:30:01 net.jxta.logging.Logging logCheckedWarning
WARNUNG: Error in sending response

adamman71
Offline
Joined: 2007-01-31
Points: 0

> FEIN: Responding to query #3 urn:jxta:uuid-59616261646162614E5047205032503352454E44455A464F9553A04103

This means that the error happens in DiscoveryServiceImpl.respond(). Thanks. I am taking a look at it.

adamman71
Offline
Joined: 2007-01-31
Points: 0

From the code, it seems like the sendResponse(String destPeer, ResolverResponseMsg response) is called with a null response on your side. The code is exactly the same between 2.5 RC3 and 2.6, and it is not called from core code itself. I believe it must be called from your application code.

Can you check?

Thanks,

Jérôme

galato
Offline
Joined: 2007-07-06
Points: 0

I know, I saw that as well. However, the exact same code on my side works nicely if I switch the libraries from 2.6 to 2.5 without any modifications. I will trace it a bit more carefully and let you know. If no work has been done in this functionality (pipe advertisements, pipe discovery) with 2.6, then it is very strange as to why 2.5 peers will be exhibiting this behavior. I will get back to you on this.

Thanks

galato
Offline
Joined: 2007-07-06
Points: 0

I apologize if I didn't make this clear originally but the error that you see is printed at the rendezvous/rly peer. The peer initializes fine (the application code) and then it waits for incoming requests. It does not do anything else and it certainly does not call sendResponse(String destPeer, ResolverResponseMsg response).

Once the jxse or jxme peer sends request to advertise a pipe or if it is looking for a pipe, the rendezvous/rly peer prints the messages out. Searching the baseline I can see calls to the sendResponse from the pipe, peer and discovery modules and that is in line with the fact that the exception occurs during discovery from remote peers.

I need to trace this a bit more carefully to see what I find.

adamman71
Offline
Joined: 2007-01-31
Points: 0

I retract. Indeed that method is called in core code. If you have a way to replicate the issue, let me know.

galato
Offline
Joined: 2007-07-06
Points: 0

It is a fairly large piece of software and a bit convoluted. I will try to isolate the parts that do this and see if I can build a test class out of them. In summary though these are the major steps:

Each of these edge peers (jxse or jxme) generate a server pipe using
pipeadv = (PipeAdvertisement) Advertisement();
pipeadv.setDescription(myPeerID);
peerPipe = new JxtaServerPipe(pg, pipeadv);

and then advertise it at their rendezvous using:
JXTADiscoveryService.remotePublish( (Advertisement) pipeadv);

Up to this point I cannot see the pipe advertisement on the rendezvous that I would otherwise be able to see in 2.5 which may be one source of the problem.

Then either type of peer (jxse or jxme) enter a loop searching for resources and
using this:

items = JXTADiscoveryService.getLocalAdvertisements(DiscoveryService.ADV, null, null);

and this

JXTADiscoveryService.getRemoteAdvertisements(null, DiscoveryService.ADV, null, null, 100, localDiscoveryListener);

During these discovery calls is when the rendezvous is printing out the NPE.message - one NPE message for each attempted discovery request.

adamman71
Offline
Joined: 2007-01-31
Points: 0

OK. I am trying to replicate the issue by generating getRemoteAdvs() and remotePublish() from a peer, but I don't get the NPEs.

But, can your try to run you application with fine logging: Logger.getLogger("net.jxta").setLevel(Level.FINE);

And tell me what is the last FINE log you get just before the NPE? It will help me locate the position in the code.

Thanks.

Jérôme

galato
Offline
Joined: 2007-07-06
Points: 0

Hey Jerome,

I don't see the Level.FINE but I will try the TRACE, ERROR, etc, that are available in the Level class and let you know if I can get the necessary info.

Thanks

galato
Offline
Joined: 2007-07-06
Points: 0

That's because I was using log4j - I switched over to java,util and used FINE and also tried FINEST . Still getting only:

Apr 24, 2010 10:47:01 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Error in sending response
java.lang.NullPointerException
Apr 24, 2010 10:47:03 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Error in sending response
java.lang.NullPointerException

adamman71
Offline
Joined: 2007-01-31
Points: 0

All of this starts to look like: https://jxta-jxse.dev.java.net/issues/show_bug.cgi?id=354

Can you perform a test with the example in the notes?

Thanks,

Jérôme

galato
Offline
Joined: 2007-07-06
Points: 0

Hey Jerome,

I did build the test class from the example and ran it but I am not sure (i) what I am expecting to see and (ii) how this is related to my issue.

The result of running the class is giving a lot of warnings - here are some:

Apr 25, 2010 11:34:18 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Stalled until there is an endpoint service
Apr 25, 2010 11:34:18 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Stalled until there is an endpoint service
EdgePeerRdvService: urn:jxta:jxta-NetGroup
Apr 25, 2010 11:34:18 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Rendezvous connection stalled until router is started!
Apr 25, 2010 11:34:18 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Stalled until there is a discovery service
Apr 25, 2010 11:34:18 PM net.jxta.logging.Logging logCheckedWarning
WARNING: 'useOnlySeeds' is true and no seed relay is set!
Apr 25, 2010 11:34:18 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Failed to connect to address :jxta://uuid-59616261646162614E50472050325033454447452041400080008003
Apr 25, 2010 11:34:18 PM net.jxta.logging.Logging logCheckedWarning
WARNING: failed to unregister discovery from resolver.
Apr 25, 2010 11:34:18 PM net.jxta.logging.Logging logCheckedWarning
WARNING: failed to unregister discovery from resolver.

Second, in my case I am getting the error at the rendezvous/relay peer and
not at the edge peer that is sending the advertisement to the super peer. Isn't
the example suggesting they are getting the error on the edge peer side?

Third, how is the logging in the reported issue showing exceptions trace when
in my case using the same logging it doesn't? I am afraid we may not be hitting
the same point in the code for these errors and we may be talking about two
different errors. Do you agree?

Finally in a related note, during the launching of my edge peers that cause my issue
on the rendezvous, I noticed the following exception along the way. Have you
seen this one before?

Apr 25, 2010 11:26:10 PM net.jxta.impl.util.threads.LongTaskDetector run
WARNING: task of type [net.jxta.impl.endpoint.netty.NettyMessenger$1] still running after 1,819ms in thread JxtaWorker-1, current stack:
net.jxta.impl.xindice.core.filer.Paged.writeValue(Paged.java:416)
net.jxta.impl.xindice.core.filer.BTreeFiler.writeRecord(BTreeFiler.java:201)
net.jxta.impl.cm.XIndiceAdvertisementCache.save(XIndiceAdvertisementCache.java:747)
net.jxta.impl.cm.CacheManager.save(CacheManager.java:274)
net.jxta.impl.discovery.DiscoveryServiceImpl.publish(DiscoveryServiceImpl.java:734)
net.jxta.impl.rendezvous.edge.EdgePeerRdvService.processConnectedReply(EdgePeerRdvService.java:731)
net.jxta.impl.rendezvous.edge.EdgePeerRdvService.access$200(EdgePeerRdvService.java:117)
net.jxta.impl.rendezvous.edge.EdgePeerRdvService$StdRdvEdgeProtocolListener.processIncomingMessage(EdgePeerRdvService.java:240)
net.jxta.impl.endpoint.EndpointServiceImpl.processIncomingMessage(EndpointServiceImpl.java:1027)
net.jxta.impl.endpoint.router.EndpointRouter.processIncomingMessage(EndpointRouter.java:1654)
net.jxta.impl.endpoint.EndpointServiceImpl.processIncomingMessage(EndpointServiceImpl.java:1027)
net.jxta.impl.endpoint.netty.NettyMessenger$1.run(NettyMessenger.java:147)
net.jxta.impl.util.threads.RunnableAsCallableWrapper.call(RunnableAsCallableWrapper.java:17)
net.jxta.impl.util.threads.RunMetricsWrapper.call(RunMetricsWrapper.java:47)
net.jxta.impl.util.threads.QueueTimeRunMetricsWrapper.call(QueueTimeRunMetricsWrapper.java:34)
net.jxta.impl.util.threads.RunMetricsWrapper.run(RunMetricsWrapper.java:90)
net.jxta.impl.util.threads.QueueTimeRunMetricsWrapper.run(QueueTimeRunMetricsWrapper.java:9)
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
java.lang.Thread.run(Thread.java:595)

Apr 25, 2010 11:26:10 PM net.jxta.impl.util.threads.RunMetricsWrapper call
WARNING: task of type [net.jxta.impl.endpoint.netty.NettyMessenger$1] took 1,820ms to complete in the shared executor

adamman71
Offline
Joined: 2007-01-31
Points: 0

I am assuming that the last test I asked you to perform does not cause an error. So I will assume that 354 is not related to your issue.

The LongTaskDetector warnings have been implemented to identify potential performance issues. These are no 'bugs'.

But, the fact that you don't get fine logging entries contradicts the following:

- DiscoveryServiceImpl: resolver.sendResponse (line 1057)
Preceeded by: Logging.logCheckedFine(LOG, "Responding to query #", query.getQueryId(), " ", query.getSrcPeer());

- DiscoveryServiceImpl: resolver.sendResponse (line 1169),
Preceeded by: Logging.logCheckedFine(LOG, "Remote publishing");

- PipeResolver: resolver.sendResponse (line 603),
Preceeded by: Logging.logCheckedFine(LOG, "Sending answer for query \'", query.getQueryId(), "\' to : ", responseDest);

- RouteResolver: resolver.sendResponse (line 1055),
Preceeded by: Logging.logCheckedFine(LOG, "we have a route build route response", route.display());

- RouteResolver: resolver.sendResponse (line 1144),
Preceeded by: Logging.logCheckedFine(LOG, "generate NACK Route response ", src);

- RouteResolver: resolver.sendResponse (line 1144),
Preceeded by: Logging.logCheckedFine(LOG, "generate NACK Route response ", src);

- PeerInfoService: resolver.sendResponse (line 519),
No fine logging around, but not used in your case

All the above are the calls to sendResponse() in core code. You should get fine logging entries. Can you check again for proper tracing set-up?

galato
Offline
Joined: 2007-07-06
Points: 0

I did run the test and I did explain what happened - I got a bunch of warnings but no error. However, my question was, is this test class and 354 exercising the potential code that may be causing my issue? The code that a rdv/rly would be executing?

Yes I did the same as you and traced what calls the sendResponse. Still no idea why it is not showing the trace. You can see that I am getting other logging messages for ex.

Apr 26, 2010 10:39:17 PM net.jxta.logging.Logging logCheckedWarning
WARNING: Error in sending response
java.lang.NullPointerException

No idea why the ones below do not get printed - unless the NPE is not caused anywhere near that method. Here is the debug setup:

Logger.getLogger("net.jxta").setLevel(Level.ALL);
or Logger.getLogger("net.jxta").setLevel(Level.FINE);

Let me check a few more things and let you know what else I find.

Thanks