[jboss-user] [JNDI and Naming] - EJB (SLSB) invocation ignores read timeout, blocks indefinit
sumitsu
do-not-reply at jboss.com
Wed Dec 9 10:14:46 EST 2009
I have an application which is exposed as an EJB 3 stateless session bean, and which is running on a clustered environment of JBoss 4.2.3 instances under Java 6. In some cases, the service exposed by the SLSB never returns after invocation, and in that event, it is imperative that the client time out (and fail out with an Exception) after a relatively short interval.
Clients of the SLSB invoke it via JNDI, and the behavior observed is that even though the properties used to build the JNDI context specify both jnp.timeout and jnp.sotimeout (as prescribed by the NamingContextFactory documentation: http://www.jboss.org/community/wiki/NamingContextFactory), invocations of the SLSB block, and never time out.
I have verified this behavior by deploying a test version of the application which deliberately enters an infinite loop upon invocation, and therefore the clients should encounter the read timeout every time.
Server-Side Code:
| public void postData() {
| log.info("\n" +
| "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n" +
| "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n" +
| "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n" +
| " TIMEOUT TEST -- STALLING NOW" +
| "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n" +
| "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n" +
| "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n");
| Object nullRef = null;
| while (nullRef == null) {
| try {
| Thread.sleep(3600000);
| } catch (InterruptedException iEx) {
| // Do nothing.
| }
| }
| log.error("\n" +
| "??????????????????????????????????????????????????\n" +
| "??????????????????????????????????????????????????\n" +
| "??????????????????????????????????????????????????\n" +
| " TIMEOUT TEST -- OUT OF STALL ??" +
| " THIS SHOULD NEVER HAPPEN... TEST MUST NOT BE WORKING..." +
| "??????????????????????????????????????????????????\n" +
| "??????????????????????????????????????????????????\n" +
| "??????????????????????????????????????????????????\n");
| }
|
Client-Side Code:
| Properties jndiProps;
| jndiProps = new Properties();
| jndiProps.setProperty(Context.PROVIDER_URL, "jnp://node1:31501,jnp://node2:31601");
| jndiProps.setProperty(Context.INITIAL_CONTEXT_FACTORY, "org.jnp.interfaces.NamingContextFactory");
| jndiProps.setProperty(Context.URL_PKG_PREFIXES, "org.jboss.naming:org.jnp.interfaces");
| jndiProps.setProperty("jnp.socketFactory", "org.jnp.interfaces.TimedSocketFactory");
| jndiProps.setProperty("jnp.timeout", "1000");
| jndiProps.setProperty("jnp.sotimeout", "1000");
| jndiProps.setProperty("jnp.maxRetries", "1");
| jndiProps.setProperty("jnp.disableDiscovery", "true");
|
| String relayJndiName = RELAY_JNDI_NAME;
|
| log.info("ESBT at GSC: JNDI Connection Properties: " + jndiProps);
|
| Context jndiContext = new InitialContext(jndiProps);
|
| ServiceRelay relay =
| (ServiceRelay)
| PortableRemoteObject.narrow(jndiContext.lookup(relayJndiName),
| ServiceRelay.class);
| relay.postData();
|
Server-Side Logs:
| 07:35:10.317 INFO [relay.ServiceRelayBean]
| !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
| !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
| !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
| TIMEOUT TEST -- STALLING NOW!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
| !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
| !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
|
Client-Side Logs:
(actual IP addresses replaced by "(node1)"; 31516 is the EJB3 Server Bind Port specified in deploy/ejb3.deployer/META-INF/jboss-service.xml)
| 2009-12-08 21:22:43,408 INFO [(client)] ESBT at GSC: JNDI Connection Properties: {java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.provider.url=jnp://(node1):31500, jnp.disableDiscovery=true, jnp.timeout=1000, jnp.maxRetries=1, jnp.socketFactory=org.jnp.interfaces.TimedSocketFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces, jnp.sotimeout=1000}
|
| 2009-12-08 21:22:43,580 DEBUG [org.jboss.security.SecurityAssociation] Using ThreadLocal: false
|
| 2009-12-08 21:22:43,595 TRACE [org.jboss.security.SecurityAssociation] getPrincipal, principal=null
|
| 2009-12-08 21:22:43,626 TRACE [org.jboss.util.propertyeditor.PropertyEditors] Mapping properties for bean: SocketClientInvoker[485fcf29, socket://(node1):31516]
|
| 2009-12-08 21:22:43,626 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[485fcf29, socket://(node1):31516] constructed
|
| 2009-12-08 21:22:43,626 DEBUG [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[485fcf29, socket://(node1):31516] connecting
|
| 2009-12-08 21:22:43,626 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] Creating semaphore with size 50
|
| 2009-12-08 21:22:43,626 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[485fcf29, socket://(node1):31516] added new pool ([]) as ServerAddress[(node1):31516, NO enableTcpNoDelay timeout 0 ms, maxPoolSize=50]
|
| 2009-12-08 21:22:43,626 DEBUG [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[485fcf29, socket://(node1):31516] connected
|
| 2009-12-08 21:22:43,626 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[485fcf29, socket://(node1):31516](1) invoking InvocationRequest[409cb0f4, AOP, [advisedMethod=public abstract void com.(omitted).relay.ServiceRelay.postData(), metadata=[metaData={DISPATCHER={OID=[type=AS_ISvalue=jboss.j2ee:ear=Application.ear,jar=Application_Core.jar,name=ServiceRelay,service=EJB3]}, REMOTING={SUBSYSTEM=[type=AS_ISvalue=AOP], INVOKER_LOCATOR=[type=AS_ISvalue=InvokerLocator [socket://node1:31516/]]}, IS_LOCAL={GUID=[type=AS_ISvalue=jboss.j2ee:ear=Application.ear,jar=Application_Core.jar,name=ServiceRelay,service=EJB3,VMID=5bf119373c151ad7:621c5cda:1257036187f:-7951]}}], targetObject=null, arguments=[Ljava.lang.Object;@6f25844f]]
|
| 2009-12-08 21:22:43,642 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[485fcf29, socket://(node1):31516] obtained semaphore: 49
|
| 2009-12-08 21:22:43,642 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[485fcf29, socket://(node1):31516] creating socket
|
| 2009-12-08 21:22:43,642 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[485fcf29, socket://(node1):31516] created socket: Socket[addr=/node1,port=31516,localport=4117]
|
| 2009-12-08 21:22:43,642 TRACE [org.jboss.remoting.transport.socket.SocketWrapper] constructing org.jboss.remoting.transport.socket.ClientSocketWrapper instance for Socket[addr=/(node1),port=31516,localport=4117], using timeout 0
|
| 2009-12-08 21:22:43,642 TRACE [org.jboss.remoting.transport.socket.SocketWrapper] ClientSocketWrapper[Socket[addr=/(node1),port=31516,localport=4117].47171b26] setting timeout to 0
|
| 2009-12-08 21:22:43,642 TRACE [org.jboss.remoting.transport.socket.ClientSocketWrapper] ClientSocketWrapper[Socket[addr=/(node1),port=31516,localport=4117].47171b26] getting output stream from Socket[addr=/(node1),port=31516,localport=4117], org.jboss.remoting.marshal.serializable.SerializableMarshaller at 3df78040
|
| 2009-12-08 21:22:43,642 TRACE [org.jboss.remoting.serialization.impl.java.JavaSerializationManager] Creating ObjectOutputStream
|
| 2009-12-08 21:22:43,642 TRACE [org.jboss.remoting.transport.socket.ClientSocketWrapper] ClientSocketWrapper[Socket[addr=/(node1),port=31516,localport=4117].47171b26] getting input stream from Socket[addr=/(node1),port=31516,localport=4117], org.jboss.remoting.marshal.serializable.SerializableUnMarshaller at 151ca803
|
| 2009-12-08 21:22:43,642 TRACE [org.jboss.remoting.serialization.impl.java.JavaSerializationManager] Creating ObjectInputStreamWithClassLoader
|
| 2009-12-08 21:22:43,642 TRACE [org.jboss.remoting.transport.socket.SocketWrapper] ClientSocketWrapper[Socket[addr=/(node1),port=31516,localport=4117].47171b26] setting timeout to 0
|
| 2009-12-08 21:22:43,642 DEBUG [org.jboss.remoting.transport.socket.ClientSocketWrapper] reset timeout: 0
|
| 2009-12-08 21:22:43,642 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[485fcf29, socket://(node1):31516] writing version 22 on output stream
|
| 2009-12-08 21:22:43,642 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[485fcf29, socket://(node1):31516] writing invocation to marshaller
|
| 2009-12-08 21:22:43,658 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[485fcf29, socket://(node1):31516] done writing invocation to marshaller
|
| 2009-12-08 21:22:43,658 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[485fcf29, socket://(node1):31516] reading version from input stream
|
(I note that there are two TRACE-level logs on the client-side referencing setting or resetting the timeout to zero.)
The application server nodes are running under Solaris 10. On the client side, I have tried both Solaris and Windows XP, encountering the behavior noted above in each case. I have tried both the HA-JNDI port and the standard JNDI port, as well as specifying both a single URL and a list of all in the cluster, all to no effect.
Can anyone tell me how to enforce the read timeout? Am I missing something when I create the JNDI context? Am I misunderstanding something fundamental with regard to the read timeout / socket timeout?
Thanks in advance for any assistance anyone can offer.
Branden Smith
View the original post : http://www.jboss.org/index.html?module=bb&op=viewtopic&p=4269814#4269814
Reply to the post : http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&p=4269814
More information about the jboss-user
mailing list