56

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)
JoshDM
  • 4,939
  • 7
  • 43
  • 72
  • you'd get eofexception if the connection has been closed or reset. it sounds like you have a closed connection in the pool that you'd need to reconnect. have you configured retry-interval and/or reconnect-attempts? what's your jms configuration like? – eis Jan 10 '15 at 22:56
  • @eis - If I restart Jboss entirely, I still get this exception. There are no connections in the pool to have closed yet. I can connect just fine from the command prompt; it's within JBoss that I cannot. – JoshDM Jan 12 '15 at 15:32
  • On your JBoss 4 system, have you considered upgrading to HornetQ for its client libraries? It may simplify issues like this, I'm not sure the protocol compatibility between JBoss MQ and HornetQ. – John Ament May 13 '15 at 03:00
  • Also, which "JBoss" did you restart here? – John Ament May 13 '15 at 03:01
  • @JohnAment - the JBoss 7.2 system was restarted. I have no control over the server JBoss 4 system (I can only provide advice); I control the 7.2 client system. The JBoss 4 system will be replaced in 4 weeks time with a JBoss running HornetQ, and we have already tested successfully with that, but I am forced to wait. Unfortunately, the ongoing processes can't pend for 4 weeks, so I need to fix the current system now. – JoshDM May 13 '15 at 03:14
  • 1
    You might need to look into your transport layer here. At a basic level, try a continuous ping (or something) between the two systems, to confirm there aren't any intermittent breaks in the connection perhaps in the form of a timeout. A tool like Wireshark will also give you eyes on the payloads between both systems, to see what the message transmission looks like. The point here is that, you'll need to look beyond your own code to see what might be wrong. Like you already suspect, the problem may lie in the infrastructure (app server, network) – kolossus May 18 '15 at 14:27
  • Yeah, after my latest edit and today's error messages, I'm leaning towards timeout. – JoshDM May 18 '15 at 14:29
  • Except that I do clear everything and it continues to happen when I reestablish a new connection. – JoshDM May 18 '15 at 14:31
  • What do you mean by "clear everything" @JoshDM? If the link between your app servers is choppy, I don't think there's anything you can do, programmatically, to fix that (remember to tag me in your response to this comment) – kolossus May 18 '15 at 16:01
  • Sorry @kolossus, I meant using the `stop()` method to clear out the connection and then `start()` to reestablish it. – JoshDM May 18 '15 at 17:15
  • If you changed nothing on the app, it may be network problem. Check if broker is visible from the jboss machine, by executing "nc -z " on the jboss machine. – outdev May 18 '15 at 20:26
  • @ultracoms - from which jboss – JoshDM May 18 '15 at 20:44
  • I guess you have jms broker on dedicated machine, so check if clients (the jboss app) can "see" it. – outdev May 18 '15 at 20:51
  • Would a stale or full JMS File Store on the client be a potential problem here? How would I know if I have one, use one and check one? – JoshDM May 20 '15 at 14:35
  • Can you guarantee that when you startup your broker, no client is attempting to connect and that the queue is empty @JoshDM – kolossus May 21 '15 at 02:42
  • @kolossus - The client JBoss server featured here is the only consumer of the `receiveMessageQueue`; the code provided is what is used. I can't guarantee that the queue doesn't have messages that the client has not yet received. – JoshDM May 21 '15 at 02:47
  • What if you stop your JBoss and clear the standalone/tmp directory (and data too, unless you know you have something you need to keep there), then restart ? – user467257 Jun 10 '15 at 21:01
  • Stopping and starting on it's own randomly resolves it; not sure if that helps or not. – JoshDM Jun 10 '15 at 22:04

1 Answers1

2

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.

JoshDM
  • 4,939
  • 7
  • 43
  • 72