users@glassfish.java.net

ORB/IIOP listeners -- Connection timeout when server is not on localhost

From: <glassfish_at_javadesktop.org>
Date: Thu, 03 Apr 2008 06:24:28 PST

Hi all,

I'm facing some (in my eyes at least) stressful problem.

[b]On the server[/b] I deployed the following stateless session bean:

[i]@Stateless(name="TestBean", mappedName="ejb/TestBean")
public class TestBean implements ITestBean {

        @Override
        public String getTime() {
                return new Date().toString();
        }

}[/i]

No deployment descriptors needed according to GlassFish Project EJB ( [i]https://glassfish.dev.java.net/javaee5/ejb/examples/Sless.html[/i] )


[b]On the clientside[/b] I wrote following standalone program that is to call the method of the bean:

[i]import java.util.Properties;

import javax.naming.InitialContext;
import javax.naming.NamingException;

import nl.teamsoft.sjsas.ejb.ITestBean;

public class OrbTest {

        @SuppressWarnings("unchecked")
        public static void main(String[] args) {
                
                System.out.println("starting");

                Properties props = new Properties();
            props.setProperty("org.omg.CORBA.ORBInitialHost", "83.138.128.xxx");
// props.setProperty("org.omg.CORBA.ORBInitialHost", "localhost");
            props.setProperty("org.omg.CORBA.ORBInitialPort", "3700");

            try {
                        InitialContext ic = new InitialContext(props);
                        
                        ITestBean testBean = (ITestBean)ic.lookup("nl.teamsoft.sjsas.ejb.ITestBean");
                        System.out.println("the bean's time = " + testBean.getTime() );
                } catch (NamingException e) {
                        System.out.println("oops... " + e.getLocalizedMessage());
                        e.printStackTrace();
                }

                System.out.println("finished");
        }
}[/i]



[b]Starting simple[/b] I tested this from within my IDE (Eclipse Europa with GlassFish plugin) with the server installed on the same PC as where I run the client program from.
To make sure I added following property-values when running the program
-Dorg.omg.CORBA.ORBInitialHost=localhost
-Dorg.omg.CORBA.ORBInitialPort=3700
This test succeeded.

[b]Afterwards[/b] I deployed the bean on a server that resides on a physical other pc with a completely different IP-address.
Now I used the following property-values:
-Dorg.omg.CORBA.ORBInitialHost=83.138.128.xxx
-Dorg.omg.CORBA.ORBInitialPort=3700)
In this case the client program fails with a connection timeout of 30 secs (after which I stop the client program).

To make sure no networking block caused the problem, we configured the remote system to accept calls from our ip (80.127.125.92) on port 8080 and 3700.
So to my opinion that should not cause this problem.
But I may be wrong on this.


The console logging in Eclipse is as follows:

[i]starting
3-apr-2008 14:37:26 com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl <init>
WARNING: "IOP00410201: (COMM_FAILURE) Connection failure: socketType: IIOP_CLEAR_TEXT; hostname: [b]192.168.100.182; port: 3700[/b]"
org.omg.CORBA.COMM_FAILURE: vmcid: SUN minor code: 201 completed: No
        at com.sun.corba.ee.impl.logging.ORBUtilSystemException.connectFailure(ORBUtilSystemException.java:2690)
        at com.sun.corba.ee.impl.logging.ORBUtilSystemException.connectFailure(ORBUtilSystemException.java:2711)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.<init>(SocketOrChannelConnectionImpl.java:261)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.<init>(SocketOrChannelConnectionImpl.java:274)
        at com.sun.corba.ee.impl.transport.SocketOrChannelContactInfoImpl.createConnection(SocketOrChannelContactInfoImpl.java:130)
        at com.sun.corba.ee.impl.protocol.CorbaClientRequestDispatcherImpl.beginRequest(CorbaClientRequestDispatcherImpl.java:192)
        at com.sun.corba.ee.impl.protocol.CorbaClientDelegateImpl.request(CorbaClientDelegateImpl.java:181)
        at com.sun.corba.ee.impl.protocol.CorbaClientDelegateImpl.is_a(CorbaClientDelegateImpl.java:325)
        at org.omg.CORBA.portable.ObjectImpl._is_a(Unknown Source)
        at org.omg.CosNaming.NamingContextHelper.narrow(Unknown Source)
        at com.sun.enterprise.naming.SerialContext.narrowProvider(SerialContext.java:131)
        at com.sun.enterprise.naming.SerialContext.getRemoteProvider(SerialContext.java:220)
        at com.sun.enterprise.naming.SerialContext.getProvider(SerialContext.java:160)
        at com.sun.enterprise.naming.SerialContext.lookup(SerialContext.java:398)
        at javax.naming.InitialContext.lookup(Unknown Source)
        at nl.teamsoft.socket.OrbTest.main(OrbTest.java:34)
Caused by: java.lang.RuntimeException: java.net.ConnectException: Connection timed out: connect
        at com.sun.enterprise.iiop.IIOPSSLSocketFactory.createSocket(IIOPSSLSocketFactory.java:347)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.<init>(SocketOrChannelConnectionImpl.java:244)
        ... 13 more
Caused by: java.net.ConnectException: Connection timed out: connect
        at sun.nio.ch.Net.connect(Native Method)
        at sun.nio.ch.SocketChannelImpl.connect(Unknown Source)
        at com.sun.corba.ee.impl.orbutil.ORBUtility.openSocketChannel(ORBUtility.java:105)
        at com.sun.enterprise.iiop.IIOPSSLSocketFactory.createSocket(IIOPSSLSocketFactory.java:332)
        ... 14 more[/i]


The thing I noticed most here was the ip-address of the server (see above).
This is namely the internal ip-address of this system.


On the server I've set the finest loglevel for CORBA, EJB Container and Naming.
In the server.log I can see the socket being created:

[i][#|2008-04-03T13:36:56.810+0100|FINE|sun-appserver9.1|javax.enterprise.resource.corba|_ThreadID=23;_ThreadName=p: thread-pool-1; w: 50;ClassName=com.sun.enterprise.iiop.IIOPSSLSocketFactory;MethodName=setAcceptedSocketOptions;_RequestID=0caef0d9-f32a-46ce-9312-758296467379;|setAcceptedSocketOptions: SocketOrChannelAcceptorImpl[ASServerSocketChannel[sun.nio.ch.ServerSocketChannelImpl[/0.0.0.0:3700]] IIOP_CLEAR_TEXT true true] [b]ServerSocket[addr=/0.0.0.0,localport=3700] Socket[addr=/80.127.125.92,port=53020,localport=3700[/b]]|#]

[#|2008-04-03T13:36:56.919+0100|FINE|sun-appserver9.1|javax.enterprise.resource.corba.ee._CORBA_.rpc.transport|_ThreadID=23;_ThreadName=p: thread-pool-1; w: 50;ClassName=com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl;MethodName=createWorkerThreadHelper;Thread[p: thread-pool-1; w: 51,5,main];java.net.URLClassLoader_at_f19d6e;_RequestID=0caef0d9-f32a-46ce-9312-758296467379;|"IOP00710304: (INTERNAL) Worker thread Thread[p: thread-pool-1; w: 51,5,main] has been created with ClassLoader java.net.URLClassLoader_at_f19d6e"
org.omg.CORBA.INTERNAL: vmcid: SUN minor code: 304 completed: No
        at com.sun.corba.ee.impl.logging.ORBUtilSystemException.workerThreadCreated(ORBUtilSystemException.java:7492)
        at com.sun.corba.ee.impl.logging.ORBUtilSystemException.workerThreadCreated(ORBUtilSystemException.java:7516)
        at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl.createWorkerThreadHelper(ThreadPoolImpl.java:326)
        at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl.createWorkerThread(ThreadPoolImpl.java:341)
        at com.sun.corba.ee.impl.orbutil.threadpool.WorkQueueImpl.addWork(WorkQueueImpl.java:161)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.addMessageMediatorToWorkQueue(SocketOrChannelConnectionImpl.java:2090)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.parseBytesAndDispatchMessages(SocketOrChannelConnectionImpl.java:1964)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.doOptimizedReadStrategy(SocketOrChannelConnectionImpl.java:1718)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.doWork(SocketOrChannelConnectionImpl.java:1263)
        at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:555)
|#][/i]


 
[b]But:[/b]
[b]1[/b]. This almost immediately ends with an exception
[i](org.omg.CORBA.INTERNAL: vmcid: SUN minor code: 304 completed: No).[/i]

[b]and[/b]
[b]2[/b]. After 30 secs the ServerSocket seems to have switched to the internal IP-address:
[i][#|2008-04-03T13:37:27.419+0100|FINE|sun-appserver9.1|javax.enterprise.resource.corba.ee.S1AS-ORB.rpc.transport|_ThreadID=24;_ThreadName=p: thread-pool-1; w: 51;ClassName=com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl;MethodName=nonBlockingRead;SocketOrChannelConnectionImpl[ java.nio.channels.[b]SocketChannel[connected local=/192.168.100.182:3700 remote=/80.127.125.92:53020[/b]] ESTABLISHED true true];_RequestID=53a55b9f-c8cb-4180-a0f4-8a4762f6de73;|"IOP00410211: (COMM_FAILURE) IOException received when reading from connection SocketOrChannelConnectionImpl[ java.nio.channels.SocketChannel[connected local=/192.168.100.182:3700 remote=/80.127.125.92:53020] ESTABLISHED true true]"
org.omg.CORBA.COMM_FAILURE: vmcid: SUN minor code: 211 completed: No
        at com.sun.corba.ee.impl.logging.ORBUtilSystemException.ioexceptionWhenReadingConnection(ORBUtilSystemException.java:2946)
        at com.sun.corba.ee.impl.logging.ORBUtilSystemException.ioexceptionWhenReadingConnection(ORBUtilSystemException.java:2965)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.nonBlockingRead(SocketOrChannelConnectionImpl.java:2000)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.doOptimizedReadStrategy(SocketOrChannelConnectionImpl.java:1713)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.doWork(SocketOrChannelConnectionImpl.java:1263)
        at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:555)
Caused by: java.io.IOException: An existing connection was forcibly closed by the remote host
        at sun.nio.ch.SocketDispatcher.read0(Native Method)
        at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:25)
        at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
        at sun.nio.ch.IOUtil.read(IOUtil.java:206)
        at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.nonBlockingRead(SocketOrChannelConnectionImpl.java:1987)
        ... 3 more
|#][/i]

I think the problem here has something to do with the switch of ip-addresses the server performs.

Maybe I'm also overlooking things in my program.
Maybe I need to adjust the configuration of the server.
Maybe it all lies in the networking (configuration) between client system and remote system with firewalls and alike.

But because I'm out of ideas I turn to the gurus.

So if anyone has a clue as where to go from here, so I can get things working in our setting, I would be more than grateful?

Bart.
[Message sent by forum member 'bertusdotcom' (bertusdotcom)]

http://forums.java.net/jive/thread.jspa?messageID=267565