6 Replies Latest reply on Aug 21, 2006 11:00 AM by hsoldier

    SocketTimeoutException:Read timed out after client connect t

    catherinelo

      I have a JMS client that connect to server. When I started the JMS client, the client managed to connect to server. And once connection was established, the client instantly send a message to server to record down the client startup time.

      Server log shows that client startup time was recorded(in the server log : 2005-08-19 23:04:51,453 INFO [ErrorLogControllerBean] error log created successfully).

      But after 2 mins, I got this java.net.socketTimeoutException:Read timed out in the server side.

      Client log shows socket timeout exception. JMS client has to reconnect to server.

      Why does this happen? How can I solve this problem?
      Please help, thanks.

      JMS client connection code

      public void createConnection() throws NamingException, JMSException {
       InitialContext iniCtx = new InitialContext(properties);
       Object tmp = iniCtx.lookup("ConnectionFactory");
      
       cf = (ConnectionFactory)tmp;
       errorQueue = (Queue) iniCtx.lookup("queue/ErrorQueue");
      
       connection = cf.createConnection();
       connection.setExceptionListener(exListener);
       connection.start();
      }



      JMS client sendMessage code
      public void sendMessage(Serializable serializable, short queueType) {
      try {
       if (connection != null) {
       if (serializable != null) {
       Session session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
       MessageProducer producer = = session.createProducer(errorQueue);
       ObjectMessage objMsg = session.createObjectMessage(serializable);
       producer.send(objMsg);
       session.close();
       } else {
       logger.warn("SessionDetails is null");
       }
       } else {
       logger.error("connection is null");
       }
      } catch (Exception ex) {
       logger.error(ex.getMessage(), ex);
      }
      }



      Here is the server log

      2005-08-19 23:04:50,906 DEBUG [org.jboss.mq.il.uil2.SocketManager] Begin ReadTask.run
      2005-08-19 23:04:50,906 DEBUG [org.jboss.mq.il.uil2.SocketManager] Begin WriteTask.run
      2005-08-19 23:04:50,906 DEBUG [org.jboss.mq.il.uil2.SocketManager] Created ObjectOutputStream
      2005-08-19 23:04:51,046 DEBUG [org.jboss.mq.il.uil2.SocketManager] Created ObjectInputStream
      2005-08-19 23:04:51,062 WARN [org.jboss.resource.security.ConfiguredIdentityLoginModule] Creating LoginModule with no configured password!
      2005-08-19 23:04:51,093 DEBUG [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Setting up the UILClientIL Connection
      2005-08-19 23:04:51,093 DEBUG [org.jboss.mq.il.uil2.ServerSocketManagerHandler] The UILClientIL Connection is set up
      2005-08-19 23:04:51,421 INFO [ErrorLogControllerBean] Create error log for stationId = 5
      2005-08-19 23:04:51,437 DEBUG [org.jboss.ejb.plugins.cmp.jdbc.JDBCFindByPrimaryKeyQuery.Station#findByPrimaryKey] Executing SQL: SELECT t0_Station.StationId FROM Station t0_Station WHERE t0_Station.StationId=?
      2005-08-19 23:04:51,437 DEBUG [org.jboss.resource.adapter.jdbc.local.LocalManagedConnectionFactory] Using properties: {user=jboss, password=--hidden--}
      2005-08-19 23:04:51,453 DEBUG [org.jboss.ejb.plugins.cmp.jdbc.keygen.JDBCMySQLCreateCommand.ErrorLog] Executing SQL: INSERT INTO ErrorLog (ClassName, Level, Message, Exception, ErrorDate, StationId) VALUES (?, ?, ?, ?, ?, ?)
      2005-08-19 23:04:51,453 DEBUG [org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.Station] Executing SQL: SELECT Name, Description, Status, DeployDate, LastStartupDate, Rate, Currency, LastUsedDate, LocationId, AdContentId FROM Station WHERE (StationId=?)
      2005-08-19 23:04:51,453 INFO [ErrorLogControllerBean] error log created successfully
      2005-08-19 23:04:51,453 DEBUG [org.jboss.ejb.StatelessSessionContainer] Useless invocation of remove() for stateless session bean
      2005-08-19 23:04:51,453 DEBUG [org.jboss.ejb.plugins.cmp.jdbc.JDBCStoreEntityCommand.ErrorLog] Executing SQL: UPDATE ErrorLog SET StationId=? WHERE ErrorId=?
      2005-08-19 23:06:51,953 DEBUG [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Exiting on IOE
      java.net.SocketTimeoutException: Read timed out

      at java.net.SocketInputStream.socketRead0(Native Method)
      at java.net.SocketInputStream.read(SocketInputStream.java:129)
      at java.io.BufferedInputStream.fill(BufferedInputStream.java:183)
      at java.io.BufferedInputStream.read(BufferedInputStream.java:201)
      at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:67)
      at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2133)
      at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2313)
      at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2380)
      at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2452)
      at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2601)
      at java.io.ObjectInputStream.readByte(ObjectInputStream.java:845)
      at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:285)
      at java.lang.Thread.run(Thread.java:534)
      2005-08-19 23:06:51,953 DEBUG [org.jboss.mq.il.uil2.SocketManager] End ReadTask.run
      2005-08-19 23:06:51,953 DEBUG [org.jboss.mq.il.uil2.SocketManager] End WriteTask.run
      2005-08-19 23:06:55,421 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
      2005-08-19 23:07:01,843 DEBUG [org.jboss.mq.il.uil2.SocketManager] Begin ReadTask.run
      2005-08-19 23:07:01,843 DEBUG [org.jboss.mq.il.uil2.SocketManager] Begin WriteTask.run
      2005-08-19 23:07:01,843 DEBUG [org.jboss.mq.il.uil2.SocketManager] Created ObjectOutputStream
      2005-08-19 23:07:01,843 DEBUG [org.jboss.mq.il.uil2.SocketManager] Created ObjectInputStream
      2005-08-19 23:07:01,859 DEBUG [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Setting up the UILClientIL Connection
      2005-08-19 23:07:01,859 DEBUG [org.jboss.mq.il.uil2.ServerSocketManagerHandler] The UILClientIL Connection is set up



        • 1. Re: SocketTimeoutException:Read timed out after client conne
          catherinelo

          Here is the client log

          DEBUG: 2005-08-22 09:36:25,437 [JMSManager] establish the connection...
          DEBUG: 2005-08-22 09:36:28,421 [SpyConnectionFactoryObjectFactory] Extracting SpyConnectionFactory from reference
          DEBUG: 2005-08-22 09:36:29,031 [SpyConnectionFactoryObjectFactory] The GenericConnectionFactory is: GenericConnectionFactory[server=org.jboss.mq.il.uil2.UILServerIL@c9131c connectionProperties={UIL_ADDRESS_KEY=192.168.7.38, UIL_CHUNKSIZE_KEY=1000000, UIL_TCPNODELAY_KEY=yes, ClientILService=org.jboss.mq.il.uil2.UILClientILService, UIL_PORT_KEY=8093, UIL_BUFFERSIZE_KEY=2048, PingPeriod=60000}]
          DEBUG: 2005-08-22 09:36:29,234 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
          DEBUG: 2005-08-22 09:36:29,250 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
          DEBUG: 2005-08-22 09:36:29,265 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
          DEBUG: 2005-08-22 09:36:29,265 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
          DEBUG: 2005-08-22 09:36:29,281 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
          DEBUG: 2005-08-22 09:36:29,593 [Connection] Setting the clockDaemon's thread factory
          DEBUG: 2005-08-22 09:36:29,812 [SocketManager$ReadTask] Begin ReadTask.run
          DEBUG: 2005-08-22 09:36:29,828 [SocketManager$WriteTask] Begin WriteTask.run
          DEBUG: 2005-08-22 09:36:29,828 [SocketManager$WriteTask] Created ObjectOutputStream
          DEBUG: 2005-08-22 09:36:29,843 [SocketManager$ReadTask] Created ObjectInputStream
          DEBUG: 2005-08-22 09:36:29,843 [UILClientILService] Starting
          DEBUG: 2005-08-22 09:36:30,093 [JMSManager] topic subscriber clientID = 6
          INFO : 2005-08-22 09:36:30,109 [Log4jManager] Startup Notification from stationId = 6
          DEBUG: 2005-08-22 09:38:20,390 [NestedThrowable$Util] org.jboss.util.NestedThrowable.parentTraceEnabled=true
          DEBUG: 2005-08-22 09:38:20,390 [NestedThrowable$Util] org.jboss.util.NestedThrowable.nestedTraceEnabled=false
          DEBUG: 2005-08-22 09:38:20,390 [NestedThrowable$Util] org.jboss.util.NestedThrowable.detectDuplicateNesting=true
          INFO : 2005-08-22 09:38:20,390 [JMSManager$ExceptionListenerImpl] JMS provider failure detected: Exiting on IOE; - nested throwable: (java.net.SocketException: Connection reset)
          DEBUG: 2005-08-22 09:38:20,406 [JMSManager$ExceptionListenerImpl] Trying to reconnect to JMS provider
          DEBUG: 2005-08-22 09:38:30,406 [JMSManager] try to stop the connection
          DEBUG: 2005-08-22 09:38:30,406 [SocketManager$WriteTask] End WriteTask.run
          DEBUG: 2005-08-22 09:38:40,406 [UILClientILService] Stopping
          ERROR: 2005-08-22 09:38:40,406 [JMSManager] Error when try to stop Connection = Cannot disable the connection with the JMS server; - nested throwable: (java.io.IOException: Client is not connected)
          ERROR: 2005-08-22 09:38:40,421 [JMSManager] Cannot disable the connection with the JMS server; - nested throwable: (java.io.IOException: Client is not connected)
          org.jboss.mq.SpyJMSException: Cannot disable the connection with the JMS server; - nested throwable: (java.io.IOException: Client is not connected)
          at org.jboss.mq.Connection.doStop(Connection.java:1289)
          at org.jboss.mq.Connection.close(Connection.java:598)
          at com.streetspace.webstation.client.JMSManager.stopConnection(JMSManager.java:122)
          at com.streetspace.webstation.client.JMSManager$ExceptionListenerImpl.connectThread(JMSManager.java:227)
          at com.streetspace.webstation.client.JMSManager$ExceptionListenerImpl.onException(JMSManager.java:203)
          at org.jboss.mq.Connection.asynchFailure(Connection.java:446)
          at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:145)
          at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:406)
          at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:338)
          at java.lang.Thread.run(Unknown Source)
          Caused by: java.io.IOException: Client is not connected
          at org.jboss.mq.il.uil2.SocketManager.internalSendMessage(SocketManager.java:233)
          at org.jboss.mq.il.uil2.SocketManager.sendMessage(SocketManager.java:201)
          at org.jboss.mq.il.uil2.UILServerIL.setEnabled(UILServerIL.java:189)
          at org.jboss.mq.Connection.doStop(Connection.java:1285)
          ... 9 more
          DEBUG: 2005-08-22 09:38:40,421 [JMSManager] establish the connection...
          DEBUG: 2005-08-22 09:38:40,671 [SpyConnectionFactoryObjectFactory] Extracting SpyConnectionFactory from reference
          DEBUG: 2005-08-22 09:38:40,703 [SpyConnectionFactoryObjectFactory] The GenericConnectionFactory is: GenericConnectionFactory[server=org.jboss.mq.il.uil2.UILServerIL@8a548b connectionProperties={UIL_ADDRESS_KEY=192.168.7.38, UIL_CHUNKSIZE_KEY=1000000, UIL_TCPNODELAY_KEY=yes, ClientILService=org.jboss.mq.il.uil2.UILClientILService, UIL_PORT_KEY=8093, UIL_BUFFERSIZE_KEY=2048, PingPeriod=60000}]
          DEBUG: 2005-08-22 09:38:40,703 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
          DEBUG: 2005-08-22 09:38:40,718 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
          DEBUG: 2005-08-22 09:38:40,734 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
          DEBUG: 2005-08-22 09:38:40,734 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
          DEBUG: 2005-08-22 09:38:40,750 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
          DEBUG: 2005-08-22 09:38:40,750 [SocketManager$ReadTask] Begin ReadTask.run
          DEBUG: 2005-08-22 09:38:40,750 [SocketManager$WriteTask] Begin WriteTask.run
          DEBUG: 2005-08-22 09:38:40,750 [SocketManager$WriteTask] Created ObjectOutputStream
          DEBUG: 2005-08-22 09:38:40,765 [SocketManager$ReadTask] Created ObjectInputStream
          DEBUG: 2005-08-22 09:38:40,781 [UILClientILService] Starting
          DEBUG: 2005-08-22 09:38:40,812 [JMSManager$ExceptionListenerImpl] Successfully reconnect to JMS
          DEBUG: 2005-08-22 09:38:40,828 [SocketManager$ReadTask] End ReadTask.run


          In the server, I have enabled "InterruptThreads" and increased the socket timeout to 2 minutes. But it doesn't help.

          < attribute name="InterruptThreads" >true< /attribute >


          < attribute name="SocketTimeout" >120000< /attribute >


          Please help. Thanks.

          • 2. Re: SocketTimeoutException:Read timed out after client conne
            r100476

            Hi,

            I'm having the same problem. Did you solve it ?

            Ricardo

            • 3. Re: SocketTimeoutException:Read timed out after client conne
              wxxg

              Hi there,

              I've encountered the same problem with 4.0.3sp1 and 4.0.4.GA on Solaris 8/JDK 1.4.2 and have painstakingly working on it for couple of days, without any clue.

              Anyone out there with similar problem and solutions/clues? Pls help, thanks in advance!

              • 4. Re: SocketTimeoutException:Read timed out after client conne
                wargun02

                Hi All,

                I have a the same problem as well (on JBoss 4.0.4 GA).

                No solutions yet. This issue requires quite some attention.

                • 5. Re: SocketTimeoutException:Read timed out after client conne
                  wargun02

                  Hi Gozen,

                  My guess is that you have called the createConnection(); somewhere in the constructor or other places and did some processing which took a long time before calling the method sendMessage(); (mark me if I'm wrong).

                  Why not try calling createConnection() and sendMessage() only when you need to send the message or better, combine both content of createConnection and sendMessage together.

                  • 6. Re: SocketTimeoutException:Read timed out after client conne
                    hsoldier


                    Hi All,

                    the client timeout that you are observing is "by design" and can be configured in the uil2-service.xml file for the "jboss.mq:service=InvocationLayer,type=UIL2" managed bean:

                    - ReadTimeout attribute (in milliseconds, default is 120000 - two minutes): it is used to disconnect the client on the server-side if there is no activity

                    - ClientReadTimeout attribute (in milliseconds, default is 120000 - two minutes): it is used to disconnect the client on the client-side if there is no activity

                    Hope this helps,
                    Peter