1 Reply Latest reply on Apr 12, 2008 11:08 AM by jaikiran pai

    JBoss AS 4.2.2 Exception in thread "ajp-127.0.0.1-8009-1" Ou

    Larry Liu Newbie

      I deployed several applications to JBoss AS 4.2.2, the applications can run ok for several days until sometime the applications will not respond and I have to restart JBoss. My machine environments are: windows 2003, JBoss AS 4.2.2, struts, hibernate, Sun JDK1.6.0 and run.bat with parameter -XX:MaxPermSize=640m

      It seems the problem happens sometime when serveral internet exploers access the several deployed applications on JBoss at the same time. Would somebody shed a light or refer to JBoss/Redhat tech support? Thanks.

      Following are the sever.log messages:

      2008-03-20 15:43:00,971 ERROR [STDERR] Exception in thread "ajp-127.0.0.1-8009-2"
      2008-03-20 15:43:00,971 ERROR [STDERR] java.lang.reflect.UndeclaredThrowableException
      2008-03-20 15:43:00,971 ERROR [STDERR] at org.apache.commons.logging.impl.Log4jProxy.log(Log4jProxy.java:309)
      2008-03-20 15:43:00,971 ERROR [STDERR] at org.apache.commons.logging.impl.Log4jProxy.error(Log4jProxy.java:283)
      2008-03-20 15:43:00,971 ERROR [STDERR] at org.apache.commons.logging.impl.Log4JLogger.error(Log4JLogger.java:208)
      2008-03-20 15:43:00,971 ERROR [STDERR] at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:401)
      2008-03-20 15:43:00,971 ERROR [STDERR] at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
      2008-03-20 15:43:00,971 ERROR [STDERR] at java.lang.Thread.run(Thread.java:619)
      2008-03-20 15:43:02,206 ERROR [STDERR] Caused by: java.lang.OutOfMemoryError: PermGen space
      2008-03-20 15:43:03,705 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Thu, 20 Mar 2008 15:43:03>
      2008-03-20 15:43:03,705 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
      2008-03-20 15:43:03,705 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
      2008-03-20 15:43:03,705 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
      2008-03-20 15:43:10,627 INFO [STDOUT] Hibernate: select this_.config_id as config1_0_, this_.top_banner_graphic as top2_18_0_, this_.copyright as copyright18_0_, this_.welcome as welcome18_0_, this_.company_name as company5_18_0_, this_.product_name as product6_18_0_, this_.admin_email as admin7_18_0_, this_.billing_system_name as billing8_18_0_, this_.medicare_provider_number as medicare9_18_0_, this_.medicaid_provider_number as medicaid10_18_0_, this_.branch_state as branch11_18_0_, this_.branch_id as branch12_18_0_, this_.companyAddress as company13_18_0_, this_.companyCity as company14_18_0_, this_.companyZipCode as company15_18_0_, this_.companyPhone as company16_18_0_, this_.auto_populate_moo as auto17_18_0_, this_.ipAddress as ipAddress18_0_, this_.importDir as importDir18_0_ from config this_
      2008-03-20 15:43:12,877 INFO [STDOUT] Hibernate: select this_.config_id as config1_0_, this_.top_banner_graphic as top2_18_0_, this_.copyright as copyright18_0_, this_.welcome as welcome18_0_, this_.company_name as company5_18_0_, this_.product_name as product6_18_0_, this_.admin_email as admin7_18_0_, this_.billing_system_name as billing8_18_0_, this_.medicare_provider_number as medicare9_18_0_, this_.medicaid_provider_number as medicaid10_18_0_, this_.branch_state as branch11_18_0_, this_.branch_id as branch12_18_0_, this_.companyAddress as company13_18_0_, this_.companyCity as company14_18_0_, this_.companyZipCode as company15_18_0_, this_.companyPhone as company16_18_0_, this_.auto_populate_moo as auto17_18_0_, this_.ipAddress as ipAddress18_0_, this_.importDir as importDir18_0_ from config this_
      2008-03-20 15:43:13,986 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Thu, 20 Mar 2008 15:43:13>
      2008-03-20 15:43:13,986 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
      2008-03-20 15:43:13,986 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
      2008-03-20 15:43:13,986 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
      2008-03-20 15:43:15,111 INFO [STDOUT] Hibernate: select this_.config_id as config1_0_, this_.top_banner_graphic as top2_18_0_, this_.copyright as copyright18_0_, this_.welcome as welcome18_0_, this_.company_name as company5_18_0_, this_.product_name as product6_18_0_, this_.admin_email as admin7_18_0_, this_.billing_system_name as billing8_18_0_, this_.medicare_provider_number as medicare9_18_0_, this_.medicaid_provider_number as medicaid10_18_0_, this_.branch_state as branch11_18_0_, this_.branch_id as branch12_18_0_, this_.companyAddress as company13_18_0_, this_.companyCity as company14_18_0_, this_.companyZipCode as company15_18_0_, this_.companyPhone as company16_18_0_, this_.auto_populate_moo as auto17_18_0_, this_.ipAddress as ipAddress18_0_, this_.importDir as importDir18_0_ from config this_
      2008-03-20 15:43:40,187 ERROR [org.apache.catalina.connector.CoyoteAdapter] An exception or error occurred in the container during the request processing
      java.lang.reflect.UndeclaredThrowableException
      at org.apache.commons.logging.impl.Log4jProxy.log(Log4jProxy.java:309)
      at org.apache.commons.logging.impl.Log4jProxy.error(Log4jProxy.java:283)
      at org.apache.commons.logging.impl.Log4JLogger.error(Log4JLogger.java:208)
      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:271)
      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
      at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:179)
      at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
      at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:241)
      at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:437)
      at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:381)
      at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
      at java.lang.Thread.run(Thread.java:619)
      Caused by: java.lang.OutOfMemoryError: PermGen space
      2008-03-20 15:44:13,200 INFO [STDOUT] Hibernate: select this_.config_id as config1_0_, this_.top_banner_graphic as top2_18_0_, this_.copyright as copyright18_0_, this_.welcome as welcome18_0_, this_.company_name as company5_18_0_, this_.product_name as product6_18_0_, this_.admin_email as admin7_18_0_, this_.billing_system_name as billing8_18_0_, this_.medicare_provider_number as medicare9_18_0_, this_.medicaid_provider_number as medicaid10_18_0_, this_.branch_state as branch11_18_0_, this_.branch_id as branch12_18_0_, this_.companyAddress as company13_18_0_, this_.companyCity as company14_18_0_, this_.companyZipCode as company15_18_0_, this_.companyPhone as company16_18_0_, this_.auto_populate_moo as auto17_18_0_, this_.ipAddress as ipAddress18_0_, this_.importDir as importDir18_0_ from config this_
      2008-03-20 15:44:15,434 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 150000
      2008-03-20 15:44:16,544 INFO [STDOUT] Hibernate: select this_.config_id as config1_0_, this_.top_banner_graphic as top2_18_0_, this_.copyright as copyright18_0_, this_.welcome as welcome18_0_, this_.company_name as company5_18_0_, this_.product_name as product6_18_0_, this_.admin_email as admin7_18_0_, this_.billing_system_name as billing8_18_0_, this_.medicare_provider_number as medicare9_18_0_, this_.medicaid_provider_number as medicaid10_18_0_, this_.branch_state as branch11_18_0_, this_.branch_id as branch12_18_0_, this_.companyAddress as company13_18_0_, this_.companyCity as company14_18_0_, this_.companyZipCode as company15_18_0_, this_.companyPhone as company16_18_0_, this_.auto_populate_moo as auto17_18_0_, this_.ipAddress as ipAddress18_0_, this_.importDir as importDir18_0_ from config this_
      2008-03-20 15:44:18,778 INFO [STDOUT] Hibernate: select this_.config_id as config1_0_, this_.top_banner_graphic as top2_18_0_, this_.copyright as copyright18_0_, this_.welcome as welcome18_0_, this_.company_name as company5_18_0_, this_.product_name as product6_18_0_, this_.admin_email as admin7_18_0_, this_.billing_system_name as billing8_18_0_, this_.medicare_provider_number as medicare9_18_0_, this_.medicaid_provider_number as medicaid10_18_0_, this_.branch_state as branch11_18_0_, this_.branch_id as branch12_18_0_, this_.companyAddress as company13_18_0_, this_.companyCity as company14_18_0_, this_.companyZipCode as company15_18_0_, this_.companyPhone as company16_18_0_, this_.auto_populate_moo as auto17_18_0_, this_.ipAddress as ipAddress18_0_, this_.importDir as importDir18_0_ from config this_
      2008-03-20 15:45:13,977 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Thu, 20 Mar 2008 15:45:13>
      2008-03-20 15:45:13,977 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
      2008-03-20 15:45:13,977 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
      2008-03-20 15:45:13,977 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
      2008-03-20 15:45:23,976 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Thu, 20 Mar 2008 15:45:23>
      2008-03-20 15:45:23,976 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
      2008-03-20 15:45:23,976 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
      2008-03-20 15:45:23,976 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass






      2008-04-11 13:14:19,171 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 150000
      2008-04-11 13:14:44,186 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Fri, 11 Apr 2008 13:14:44>
      2008-04-11 13:14:44,186 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
      2008-04-11 13:14:44,186 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
      2008-04-11 13:14:44,186 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
      2008-04-11 13:14:54,186 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Fri, 11 Apr 2008 13:14:54>
      2008-04-11 13:14:54,186 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
      2008-04-11 13:14:54,186 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
      2008-04-11 13:14:54,186 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
      2008-04-11 13:15:51,764 INFO [org.apache.struts.tiles.TilesRequestProcessor] Tiles definition factory found for request processor ''.
      2008-04-11 13:15:51,889 INFO [org.hibernate.cfg.Environment] Hibernate 3.0.2
      2008-04-11 13:15:51,889 INFO [org.hibernate.cfg.Environment] hibernate.properties not found
      2008-04-11 13:15:51,889 INFO [org.hibernate.cfg.Environment] using CGLIB reflection optimizer
      2008-04-11 13:15:51,889 INFO [org.hibernate.cfg.Environment] using JDK 1.4 java.sql.Timestamp handling
      2008-04-11 13:16:00,624 INFO [STDOUT] Hibernate: select this_.user_id as user1_0_, this_.username as username10_0_, this_.password as password10_0_, this_.first_name as first4_10_0_, this_.last_name as last5_10_0_, this_.email as email10_0_, this_.usertype_id as usertype7_10_0_ from user this_ where lower(this_.username)=?
      2008-04-11 13:16:11,968 ERROR [STDERR] Exception in thread "ajp-127.0.0.1-8009-3"
      2008-04-11 13:16:11,968 ERROR [STDERR] java.lang.reflect.UndeclaredThrowableException
      2008-04-11 13:16:29,764 ERROR [STDERR] Exception in thread "ajp-127.0.0.1-8009-4"
      2008-04-11 13:16:29,764 ERROR [STDERR] java.lang.reflect.UndeclaredThrowableException
      2008-04-11 13:16:49,171 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 150000
      2008-04-11 13:16:54,186 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Fri, 11 Apr 2008 13:16:54>
      2008-04-11 13:16:54,186 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
      2008-04-11 13:16:54,186 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
      2008-04-11 13:16:54,186 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
      2008-04-11 13:17:06,139 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Fri, 11 Apr 2008 13:17:04>
      2008-04-11 13:17:06,139 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
      2008-04-11 13:17:06,139 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
      2008-04-11 13:17:07,577 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
      2008-04-11 13:17:18,577 ERROR [STDERR] Exception in thread "ajp-127.0.0.1-8009-2"
      2008-04-11 13:17:18,577 ERROR [STDERR] java.lang.reflect.UndeclaredThrowableException
      2008-04-11 13:17:24,155 ERROR [STDERR] Exception in thread "ajp-127.0.0.1-8009-1"
      2008-04-11 13:17:24,155 ERROR [STDERR] java.lang.reflect.UndeclaredThrowableException
      2008-04-11 13:18:10,514 ERROR [STDERR] Exception in thread "ajp-127.0.0.1-8009-6"
      2008-04-11 13:18:10,514 ERROR [STDERR] java.lang.reflect.UndeclaredThrowableException
      2008-04-11 13:18:18,764 ERROR [STDERR] Exception in thread "ajp-127.0.0.1-8009-7"
      2008-04-11 13:18:18,764 ERROR [STDERR] java.lang.reflect.UndeclaredThrowableException
      2008-04-11 13:18:24,202 ERROR [STDERR] Exception in thread "ajp-127.0.0.1-8009-5"
      2008-04-11 13:18:24,202 ERROR [STDERR] java.lang.reflect.UndeclaredThrowableException
      2008-04-11 13:18:28,280 ERROR [STDERR] Exception in thread "ajp-127.0.0.1-8009-9"
      2008-04-11 13:18:28,280 ERROR [STDERR] java.lang.NullPointerException
      2008-04-11 13:18:33,686 ERROR [STDERR] Exception in thread "ajp-127.0.0.1-8009-8"
      2008-04-11 13:18:33,686 ERROR [STDERR] java.lang.reflect.UndeclaredThrowableException
      2008-04-11 13:19:08,014 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Fri, 11 Apr 2008 13:19:08>
      2008-04-11 13:19:08,014 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
      2008-04-11 13:19:08,014 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
      2008-04-11 13:19:08,014 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
      2008-04-11 13:19:12,093 ERROR [STDERR] Exception in thread "ajp-127.0.0.1-8009-10"
      2008-04-11 13:19:12,093 ERROR [STDERR] java.lang.reflect.UndeclaredThrowableException
      2008-04-11 13:19:18,014 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Fri, 11 Apr 2008 13:19:18>
      2008-04-11 13:19:18,014 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
      2008-04-11 13:19:18,014 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
      2008-04-11 13:19:18,014 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
      2008-04-11 13:19:19,171 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 150000
      2008-04-11 13:20:47,561 ERROR [STDERR] Exception in thread "ajp-127.0.0.1-8009-11"
      2008-04-11 13:20:47,561 ERROR [STDERR] java.lang.reflect.UndeclaredThrowableException
      2008-04-11 13:21:18,014 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Fri, 11 Apr 2008 13:21:18>
      2008-04-11 13:21:18,014 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
      2008-04-11 13:21:18,014 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
      2008-04-11 13:21:18,014 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
      2008-04-11 13:21:28,014 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Fri, 11 Apr 2008 13:21:28>
      2008-04-11 13:21:28,014 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
      2008-04-11 13:21:28,014 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
      2008-04-11 13:21:28,014 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
      2008-04-11 13:21:49,171 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 150000
      2008-04-11 13:23:28,014 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Fri, 11 Apr 2008 13:23:28>
      2008-04-11 13:23:28,014 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
      2008-04-11 13:23:28,014 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
      2008-04-11 13:23:28,014 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
      2008-04-11 13:23:38,014 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Fri, 11 Apr 2008 13:23:38>
      2008-04-11 13:23:38,014 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
      2008-04-11 13:23:38,014 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
      2008-04-11 13:23:38,014 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
      2008-04-11 13:24:19,171 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 150000