Why are SpyJMSExceptions still thrown after recycling the client JBoss connection to remote queues?

Question

My application below communicates as a client on a JBoss 7.2.0 system to a receiver JNDI/JMS on a JBoss 4.2.1 system. It creates a Send Queue and a Receive Queue. We have been running just fine for 2 months straight with this configuration; no changes were made to either side. The local client app has the 4.2.1 jbossall-client.jar and jnp-client.jars installed.

After normal activity, we start receiving a org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.io.EOFException) at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:72) exception.

We restarted JBoss 7.2.0 without changing anything, and when we are establishing the receive queue, we are now receiving a org.jboss.mq.SpyJMSException: Cannot subscribe to this Destination: ; {...} Caused by: java.io.EOFException exception thrown from our code at QueueReceiver receiver = session.createReceiver(queue);. We also start throwing this same exception after the app has been running fine for days, but without activity over a multi-day period of time.

We had the 4.2.1 system restarted to see if that was the problem, but that fixed nothing. In fact, we can replicate this failure scenario by having both systems connect as normal, then recycle the 4.2.1 system. The errors start throwing once the 4.2.1 system is down, and the 7.2.0 system continues to fail to re-establish the connections once the 4.2.1 system is fully established (even when it SHOULD be capable of doing so).

Stopping then starting the app in JBoss does not fix this. Restarting JBoss has a 20% chance of fixing this (100% chance in the case of the forced failure scenario cited above). Undeploying, then redeploying the application usually fixes this.

What might be causing this?

This same war file works fine on our test system, which has an identical JBoss set-up. Communication with the target JBoss system via a test app from the command prompt using the same code works fine.

I suspect there is an issue with JBoss 7.2.0 itself, or is this possibly a timeout issue? How do I check or extend the timeout length; is that something doable from the client side? Even if it was timeout, I make the call to the stop() method before the rest of start() re-connects, and I still get the exception; in that scenario, it wouldn't be a timeout issue as a timeout would have reset.

Context Values:

connectionFactoryName=ConnectionFactory
contextFactoryName=org.jnp.interfaces.NamingContextFactory
packagePrefixes=org.jboss.naming:org.jnp.interfaces
providerUrl=MYSERVER:1099

Java Code:

private ContextContainer contextContainer = null;
private QueueConnection connection = null;
private QueueReceiver receiver = null;
private Queue sendQueue = null;
private Queue receiveQueue = null;
private String sendQueueName = null;
private String receiveQueueName = null;
private MessageHandler messageHandler = null;

protected synchronized void start() throws Exception {

    // NOTE: This position also has delay code (for pending multiple 
    // consecutive recycling requests), with an external method to 
    // reset the delay. It was removed for code clarity and has no 
    // effect on the issue being discussed.

    // Clear prior Connection
    stop();

    logger.info("Regenerating JMS for : " + this.getClass().getName());

    Context context = this.contextContainer.getContext();

    logger.info("Looking up factory : " + contextContainer.getConnectionFactoryName());

    QueueConnectionFactory connectionFactory = (QueueConnectionFactory)context.lookup(contextContainer.getConnectionFactoryName()); 

    // ESTABLISH SEND MESSAGE QUEUE
    logger.info("Looking up send queue : " + sendQueueName);

    sendQueue = (Queue)context.lookup(sendQueueName); 

    logger.info("Send Queue string : " + sendQueue);
    logger.info("Send Queue name   : " + sendQueue.getQueueName());
    logger.info("Creating Queue Connection");

    connection = connectionFactory.createQueueConnection();

    logger.info("Setting Exception Listener");

    connection.setExceptionListener(new ExceptionListener() {

        public void onException(JMSException ex) {

            logger.error("JMS Exception received on QueueConnection", ex);

            start();
        }
    });

    // ESTABLISH RECEIVE MESSAGE QUEUE
    logger.info("Looking up receive queue : " + receiveQueueName);

    receiveQueue = (Queue)context.lookup(receiveQueueName); 

    logger.info("Receive Queue string : " + receiveQueue);
    logger.info("Receive Queue name   : " + receiveQueue.getQueueName());
    logger.info("Creating JMS Session for Receiving");

    QueueSession session = connection.createQueueSession(false, Session.CLIENT_ACKNOWLEDGE);

    logger.info("Created Session " + session);      
    logger.info("Creating JMS Receiver for Queue \"" + receiveQueue.getQueueName() + "\"");

    // THIS IS THE LINE WHERE THE EXCEPTION IS THROWN!!!
    receiver = session.createReceiver(receiveQueue);

    logger.info("Setting Message Listener");

    receiver.setMessageListener(new MessageListener() {

        public void onMessage(Message message) {

            try {

                if (message instanceof ObjectMessage) {

                    Object obj = ((ObjectMessage) message).getObject();

                    //  UNRELATED METHOD FOR HANDLING THE MESSAGE
                    handleMessage(obj);

                } else {

                    throw new Exception("Received message of unexpected type " + message.getJMSType() + ", was expecting ObjectMessage");
                }

            } catch (Exception ex) {

                logger.error("Error processing incoming message.", ex);

            } finally {

                try {

                    message.acknowledge();
                    logger.info("Acknowledged message.");

                } catch (Exception ex) {

                    logger.error("Unable to acknowledge message.", ex);
                }
            }
        }
    });

    logger.info("Starting Queue Connection");

    connection.start();

    logger.info("Started Queue Connection");
}   

/**
 * Extinguish the existing connection.
 */
public synchronized void stop() {

    if (receiver != null) {

        try {

            logger.info("Nullifying Receiver Listener");
            receiver.setMessageListener(null);
            logger.info("Nullified Receiver Listener");

        } catch(Exception ex) {

            logger.warn("Exception nullifying Receiver Listener", ex);
        }

        try {

            logger.info("Closing Receiver");
            receiver.close();
            logger.info("Closed Receiver");

        } catch(Exception ex) {

            logger.warn("Exception closing Receiver", ex);

        } finally {

            receiver = null;
        }           
    }

    if (connection != null) {

        try {

            logger.info("Nullifying Exception Listener");
            connection.setExceptionListener(null);
            logger.info("Nullified Exception Listener");

        } catch (Exception ex) {

            logger.warn("Exception nullifying Exception Listener", ex);
        }

        try {

            logger.info("Stopping Queue Connection");
            connection.stop();
            logger.info("Stopped Queue Connection");

        } catch (Exception ex) {

            logger.warn("Exception stopping Queue Connection", ex);
        }

        try {

            logger.info("Closing Queue Connection");
            connection.close();
            logger.info("Closed Queue Connection");

        } catch (Exception ex) {

            logger.warn("Exception closing Queue Connection", ex);

        } finally {

            connection = null;
        }
    }
}

Log Output:

Setting Context Factory Class: org.jnp.interfaces.NamingContextFactory
Setting Package Prefixes: org.jboss.naming:org.jnp.interfaces
Setting Provider URL: MYSERVER:1099
Generating JMS for : MYPACKAGE.ConnectionHandler
Looking up factory : ConnectionFactory
Looking up send queue : queue/sendQueue
Send Queue string : QUEUE.sendQueue
Send Queue name   : sendQueue
Creating Queue Connection
Setting Exception Listener
Looking up receive queue : queue/receiveQueue
Receive Queue string : QUEUE.receiveQueue
Receive Queue name   : receiveQueue
Creating JMS Session for Receiving
Created Session SpySession@1903462020[tx=false ack=CLIENT txid=null RUNNING connection=Connection@1963631553[token=ConnectionToken:ID:273725/9966a9625bb094d33a37f72db71b3bb9 rcvstate=STOPPED]]
Creating JMS Receiver for Queue "receiveQueue"
Exception caught during initialization.
org.jboss.mq.SpyJMSException: Cannot subscribe to this Destination: ; - nested throwable: (java.io.EOFException)

Exception trace after normal activity:

JMS Exception received on QueueConnection
org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.io.EOFException)
at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:72)
at org.jboss.mq.Connection.asynchFailure(Connection.java:423)
at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:174)
at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:439)
at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:371)
at java.lang.Thread.run(Thread.java:744)
Caused by: java.io.EOFException
at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2766)
at java.io.ObjectInputStream.readByte(ObjectInputStream.java:916)
at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:316)
... 1 more

Exception trace after restart:

org.jboss.mq.SpyJMSException: Cannot subscribe to this Destination: ; - nested throwable: (java.io.EOFException)
    at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:72)
    at org.jboss.mq.SpyJMSException.rethrowAsJMSException(SpyJMSException.java:57)
    at org.jboss.mq.Connection.addConsumer(Connection.java:800)
    at org.jboss.mq.SpySession.addConsumer(SpySession.java:947)
    at org.jboss.mq.SpySession.createReceiver(SpySession.java:658)
    at org.jboss.mq.SpyQueueSession.createReceiver(SpyQueueSession.java)
    at org.jboss.mq.SpySession.createReceiver(SpySession.java:647)
    at org.jboss.mq.SpyQueueSession.createReceiver(SpyQueueSession.java)
    at MYPACKAGE.ConnectionHandler.start(ConnectionHandler.java:144)
    at MYPACKAGE.ConnectionHandler.initialize(ConnectionHandler.java:60)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1414)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1375)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1335)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:473)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory$1.run(AbstractAutowireCapableBeanFactory.java:409)
    at java.security.AccessController.doPrivileged(Native Method)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:380)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:264)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:261)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:185)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:164)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:429)
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:728)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:380)
    at org.springframework.web.context.ContextLoader.createWebApplicationContext(ContextLoader.java:255)
    at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:199)
    at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:45)
    at org.apache.catalina.core.StandardContext.contextListenerStart(StandardContext.java:3339)
    at org.apache.catalina.core.StandardContext.start(StandardContext.java:3777)
    at org.jboss.as.web.deployment.WebDeploymentService.doStart(WebDeploymentService.java:156)
    at org.jboss.as.web.deployment.WebDeploymentService.access$000(WebDeploymentService.java:60)
    at org.jboss.as.web.deployment.WebDeploymentService$1.run(WebDeploymentService.java:93)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:744)
    at org.jboss.threads.JBossThread.run(JBossThread.java:122)
Caused by: java.io.EOFException
    at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2766)
    at java.io.ObjectInputStream.readByte(ObjectInputStream.java:916)
    at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:316)
    at java.lang.Thread.run(Thread.java:744)

Answer 1

As noted in the question, the JBoss 4.2.1 server has been upgraded to 7.1.1 Final. Upgrading has resolved the issue and the client now works as expected, but unfortunately this solution does not explain the problem.