JMS Problem on clean install of Jboss-4.2.2.GA
jagthedrummer Jan 30, 2008 2:52 PMHello everyone. I'm trying to get a very simple JMS example running with a clean install of JBoss-4.2.2.GA. I'm trying to use one of the pre-configured example topics which is registered in JNDI under "topic/testTopic".
I have a simple listener and a simple publisher which both run without throwing any errors on the client side, though some errors are thrown on the server side. When I run the message publishing code it acts like it sends a message, but the listener never gets it.
Here's my code for the listener, the publisher, and the log trace from the period directly after trying to send a message.
If anyone has any ideas on what I'm missing I would appreciate the tip.
Thanks,
Jeremy
Topic Listener:
---------------------------------------------------------------------------
package com.dcom.cms.node.test; import javax.jms.*; import javax.naming.*; class TopicListenerTest implements javax.jms.MessageListener { public static void main(String[] args) throws InterruptedException, NamingException, JMSException { new TopicListenerTest(); while (true) { System.out.println("."); Thread.sleep(10000); } } public TopicListenerTest() throws NamingException, JMSException { InitialContext jndiContext = new InitialContext(); ConnectionFactory factory = (ConnectionFactory) jndiContext .lookup("ConnectionFactory"); Topic topic = (Topic) jndiContext.lookup("topic/testTopic"); Connection connect = (Connection) factory.createConnection(); Session session = ((Connection) connect).createSession(false, Session.AUTO_ACKNOWLEDGE); MessageConsumer consumer = session.createConsumer(topic); consumer.setMessageListener(this); connect.start(); } public void onMessage(Message message) { System.out.println("we have a message"); } }
Topic Publisher:
---------------------------------------------------------------------------
package com.dcom.cms.node.test; import javax.jms.*; import javax.naming.*; class TopicPublisherTest { public static void main(String[] args) throws NamingException, JMSException { new TopicPublisherTest(); } public TopicPublisherTest() throws NamingException, JMSException { InitialContext jndiContext = new InitialContext(); ConnectionFactory factory = (ConnectionFactory) jndiContext.lookup("ConnectionFactory"); Topic topic = (Topic) jndiContext.lookup("topic/testTopic"); Connection connect = factory.createConnection( ); Session session = connect.createSession(true,0); MessageProducer producer = session.createProducer(topic); TextMessage textMsg = session.createTextMessage( ); textMsg.setText("testing"); producer.send(textMsg); connect.close( ); } }
Server Log:
---------------------------------------------------------------------------
2008-01-30 13:38:51,373 TRACE [org.jboss.mq.il.uil2.UILServerILService] Accepted connection: Socket[addr=/127.0.1.1,port=52621,localport=8093] 2008-01-30 13:38:51,373 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : getThreadGroup 2008-01-30 13:38:51,373 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : getThreadGroup 2008-01-30 13:38:51,373 TRACE [org.jboss.mq.il.uil2.SocketManager] start called java.lang.Exception: Start stack trace at org.jboss.mq.il.uil2.SocketManager.start(SocketManager.java:112) at org.jboss.mq.il.uil2.UILServerILService.run(UILServerILService.java:171) at java.lang.Thread.run(Thread.java:595) 2008-01-30 13:38:51,374 DEBUG [org.jboss.mq.il.uil2.SocketManager] Begin ReadTask.run Thread[UIL2.SocketManager.ReadTask#5 client=127.0.1.1:52621,5,JBossMQ Server Threads] 2008-01-30 13:38:51,374 DEBUG [org.jboss.mq.il.uil2.SocketManager] Begin WriteTask.run Thread[UIL2.SocketManager.WriteTask#6 client=127.0.1.1:52621,5,JBossMQ Server Threads] 2008-01-30 13:38:51,374 DEBUG [org.jboss.mq.il.uil2.SocketManager] Created ObjectOutputStream 2008-01-30 13:38:51,443 DEBUG [org.jboss.mq.il.uil2.SocketManager] Created ObjectInputStream 2008-01-30 13:38:51,443 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_authenticate, msgID: 1 2008-01-30 13:38:51,443 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.CheckUserMsg3116185[msgType: m_authenticate, msgID: 1, error: null] 2008-01-30 13:38:51,443 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 22 2008-01-30 13:38:51,443 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : authenticate 2008-01-30 13:38:51,443 TRACE [org.jboss.mq.security.ServerSecurityInterceptor] Authenticating user null 2008-01-30 13:38:51,444 TRACE [org.jboss.mq.security.SecurityManager] Username: null is authenticated 2008-01-30 13:38:51,444 TRACE [org.jboss.mq.security.SecurityManager] Adding group : class org.jboss.security.SimpleGroup Roles(members:j2ee,guest,john) 2008-01-30 13:38:51,444 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : authenticate 2008-01-30 13:38:51,444 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.CheckUserMsg3116185[msgType: m_authenticate, msgID: 1, error: null] 2008-01-30 13:38:51,444 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.CheckUserMsg3116185[msgType: m_authenticate, msgID: 1, error: null] 2008-01-30 13:38:51,444 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.CheckUserMsg3116185[msgType: m_authenticate, msgID: 1, error: null] 2008-01-30 13:38:51,444 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 22 2008-01-30 13:38:51,454 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_setSpyDistributedConnection, msgID: 2 2008-01-30 13:38:51,455 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg14492623[msgType: m_setSpyDistributedConnection, msgID: 2, error: null] 2008-01-30 13:38:51,456 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 15 2008-01-30 13:38:51,456 DEBUG [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Setting up the UILClientIL Connection 2008-01-30 13:38:51,456 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg14492623[msgType: m_setSpyDistributedConnection, msgID: 2, error: null] 2008-01-30 13:38:51,456 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg14492623[msgType: m_setSpyDistributedConnection, msgID: 2, error: null] 2008-01-30 13:38:51,456 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg14492623[msgType: m_setSpyDistributedConnection, msgID: 2, error: null] 2008-01-30 13:38:51,456 DEBUG [org.jboss.mq.il.uil2.ServerSocketManagerHandler] The UILClientIL Connection is set up 2008-01-30 13:38:51,456 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 15 2008-01-30 13:38:51,464 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_getID, msgID: 3 2008-01-30 13:38:51,464 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.GetIDMsg5907955[msgType: m_getID, msgID: 3, error: null] 2008-01-30 13:38:51,464 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 9 2008-01-30 13:38:51,464 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : getID 2008-01-30 13:38:51,465 TRACE [org.jboss.mq.sm.jdbc.JDBCStateManager] Client id 'ID:3' is logged in. 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : getID 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.GetIDMsg5907955[msgType: m_getID, msgID: 3, error: null] 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.GetIDMsg5907955[msgType: m_getID, msgID: 3, error: null] 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.GetIDMsg5907955[msgType: m_getID, msgID: 3, error: null] 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 9 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_ping, msgID: 4 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.PingMsg15033128[msgType: m_ping, msgID: 4, error: null] 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 21 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : ping 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : 1201721931464 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.PingMsg30468875[msgType: m_pong, msgID: -2147483643, error: null] 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.PingMsg30468875[msgType: m_pong, msgID: -2147483643, error: null] 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.PingMsg30468875[msgType: m_pong, msgID: -2147483643, error: null] 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : ping 2008-01-30 13:38:51,466 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 21 2008-01-30 13:38:51,500 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_transact, msgID: 5 2008-01-30 13:38:51,500 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.TransactMsg16199287[msgType: m_transact, msgID: 5, error: null] 2008-01-30 13:38:51,500 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 17 2008-01-30 13:38:51,500 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : transact 2008-01-30 13:38:51,500 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : org.jboss.mq.TransactionRequest@bc7c0 2008-01-30 13:38:51,500 TRACE [org.jboss.mq.server.JMSDestinationManager] ConnectionToken:ID:3/93cc4c88601c60075aa0dbc4d702f250 1PC null txId=3 2008-01-30 13:38:51,500 TRACE [org.jboss.mq.pm.TxManager] Commit branch=3 2008-01-30 13:38:51,500 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : transact 2008-01-30 13:38:51,500 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.TransactMsg16199287[msgType: m_transact, msgID: 5, error: null] 2008-01-30 13:38:51,500 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.TransactMsg16199287[msgType: m_transact, msgID: 5, error: null] 2008-01-30 13:38:51,500 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.TransactMsg16199287[msgType: m_transact, msgID: 5, error: null] 2008-01-30 13:38:51,500 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 17 2008-01-30 13:38:51,502 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_connectionClosing, msgID: 6 2008-01-30 13:38:51,502 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.CloseMsg23533966[msgType: m_connectionClosing, msgID: 6, error: null] 2008-01-30 13:38:51,502 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 5 2008-01-30 13:38:51,503 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing 2008-01-30 13:38:51,503 TRACE [org.jboss.mq.sm.jdbc.JDBCStateManager] Client id 'ID:3' is logged out. 2008-01-30 13:38:51,503 TRACE [org.jboss.mq.il.uil2.SocketManager] stop() Thread[UIL2.SocketManager.ReadTask#5 client=127.0.1.1:52621,5,JBossMQ Server Threads] Thread[UIL2.SocketManager.WriteTask#6 client=127.0.1.1:52621,5,JBossMQ Server Threads] 2008-01-30 13:38:51,503 TRACE [org.jboss.mq.il.uil2.SocketManager] WriteTask was interrupted java.lang.InterruptedException at java.lang.Object.wait(Native Method) at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.poll(LinkedQueue.java:170) at org.jboss.mq.il.uil2.SocketManager$WriteTask.run(SocketManager.java:551) at java.lang.Thread.run(Thread.java:595) 2008-01-30 13:38:51,503 TRACE [org.jboss.mq.il.uil2.SocketManager] Exiting on IOE java.net.SocketException: Socket closed at java.net.SocketInputStream.read(SocketInputStream.java:162) at java.io.BufferedInputStream.fill(BufferedInputStream.java:218) at java.io.BufferedInputStream.read(BufferedInputStream.java:235) at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:79) at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2196) at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2376) at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2443) at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2515) at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2664) at java.io.ObjectInputStream.readByte(ObjectInputStream.java:875) at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:340) at java.lang.Thread.run(Thread.java:595) 2008-01-30 13:38:51,503 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing 2008-01-30 13:38:51,503 DEBUG [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Exiting on IOE java.net.SocketException: Socket closed at java.net.SocketInputStream.read(SocketInputStream.java:162) at java.io.BufferedInputStream.fill(BufferedInputStream.java:218) at java.io.BufferedInputStream.read(BufferedInputStream.java:235) at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:79) at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2196) at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2376) at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2443) at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2515) at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2664) at java.io.ObjectInputStream.readByte(ObjectInputStream.java:875) at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:340) at java.lang.Thread.run(Thread.java:595) 2008-01-30 13:38:51,503 TRACE [org.jboss.mq.il.uil2.SocketManager] Failed to handle: org.jboss.mq.il.uil2.msgs.CloseMsg23533966[msgType: m_connectionClosing, msgID: 6, error: null] java.io.IOException: Client is not connected at org.jboss.mq.il.uil2.SocketManager.internalSendMessage(SocketManager.java:288) at org.jboss.mq.il.uil2.SocketManager.sendReply(SocketManager.java:262) at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:134) at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:419) at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:398) at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:761) at java.lang.Thread.run(Thread.java:595) 2008-01-30 13:38:51,503 DEBUG [org.jboss.mq.il.uil2.SocketManager] End ReadTask.run Thread[UIL2.SocketManager.ReadTask#5 client=127.0.1.1:52621,5,JBossMQ Server Threads] 2008-01-30 13:38:51,503 TRACE [org.jboss.mq.il.uil2.SocketManager] Failed to send error reply java.io.IOException: Client is not connected at org.jboss.mq.il.uil2.SocketManager.internalSendMessage(SocketManager.java:288) at org.jboss.mq.il.uil2.SocketManager.access$900(SocketManager.java:53) at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:432) at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:398) at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:761) at java.lang.Thread.run(Thread.java:595) 2008-01-30 13:38:51,503 DEBUG [org.jboss.mq.il.uil2.SocketManager] End WriteTask.run Thread[UIL2.SocketManager.WriteTask#6 client=127.0.1.1:52621,5,JBossMQ Server Threads]