这是一个开发环境,一个centos上部署了很多tomcat,其中有一个就是本次主角,我发现每次部署持续打印一段错误日志:
10-Apr-2025 17:11:13.106 信息 [pool-2-thread-13] org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading 非法访问:此Web应用程序实例已停止。无法加载[com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException]。为了调试以及终止导致非法访问的线程,将抛出以下堆栈跟踪。
java.lang.IllegalStateException: 非法访问:此Web应用程序实例已停止。无法加载[com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException]。为了调试以及终止导致非法访问的线程,将抛出以下堆栈跟踪。
at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading(WebappClassLoaderBase.java:1435)
at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1423)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1262)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1223)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:264)
at com.mysql.jdbc.Util.getInstance(Util.java:383)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:980)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3847)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3783)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2447)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2594)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2545)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1901)
at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2002)
at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:70)
at org.hibernate.loader.Loader.getResultSet(Loader.java:2116)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1899)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1875)
at org.hibernate.loader.Loader.doQuery(Loader.java:919)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:336)
at org.hibernate.loader.Loader.doList(Loader.java:2611)
at org.hibernate.loader.Loader.doList(Loader.java:2594)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2423)
at org.hibernate.loader.Loader.list(Loader.java:2418)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:501)
at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:371)
at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:226)
at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1268)
at org.hibernate.internal.QueryImpl.list(QueryImpl.java:87)
at org.hibernate.jpa.internal.QueryImpl.list(QueryImpl.java:593)
at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:470)
at com.zjs.nms.dao.common.jpa.BasicJPQLDao.findByJpql(BasicJPQLDao.java:69)
at com.zjs.nms.dao.common.jpa.BasicJPQLDao$$FastClassBySpringCGLIB$$8fc7afab.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655)
at com.zjs.nms.dao.common.jpa.BasicJPQLDao$$EnhancerBySpringCGLIB$$132ebefe.findByJpql(<generated>)
at com.zjs.nms.service.common.impl.BasicService.findAll(BasicService.java:112)
at com.zjs.nms.service.tasks.ServerMonitorTask.doJob(ServerMonitorTask.java:54)
at com.zjs.nms.service.tasks.BaseTask.run(BaseTask.java:56)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2025-04-10 17:11:13,107 [pool-2-thread-13] WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] - SQL Error: 0, SQLState: S1000
2025-04-10 17:11:13,107 [pool-2-thread-13] ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] - Unable to create correct SQLException class instance, error class/codes may be incorrect. Reason:
** BEGIN NESTED EXCEPTION **
java.sql.SQLException
MESSAGE: Can't instantiate required class
STACKTRACE:
java.sql.SQLException: Can't instantiate required class
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:998)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:937)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:926)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:872)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:904)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:894)
at com.mysql.jdbc.Util.getInstance(Util.java:389)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:980)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3847)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3783)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2447)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2594)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2545)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1901)
at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2002)
at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:70)
at org.hibernate.loader.Loader.getResultSet(Loader.java:2116)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1899)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1875)
at org.hibernate.loader.Loader.doQuery(Loader.java:919)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:336)
at org.hibernate.loader.Loader.doList(Loader.java:2611)
at org.hibernate.loader.Loader.doList(Loader.java:2594)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2423)
at org.hibernate.loader.Loader.list(Loader.java:2418)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:501)
at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:371)
at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:226)
at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1268)
at org.hibernate.internal.QueryImpl.list(QueryImpl.java:87)
at org.hibernate.jpa.internal.QueryImpl.list(QueryImpl.java:593)
at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:470)
at com.zjs.nms.dao.common.jpa.BasicJPQLDao.findByJpql(BasicJPQLDao.java:69)
at com.zjs.nms.dao.common.jpa.BasicJPQLDao$$FastClassBySpringCGLIB$$8fc7afab.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655)
at com.zjs.nms.dao.common.jpa.BasicJPQLDao$$EnhancerBySpringCGLIB$$132ebefe.findByJpql(<generated>)
at com.zjs.nms.service.common.impl.BasicService.findAll(BasicService.java:112)
at com.zjs.nms.service.tasks.ServerMonitorTask.doJob(ServerMonitorTask.java:54)
at com.zjs.nms.service.tasks.BaseTask.run(BaseTask.java:56)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.ClassNotFoundException: 非法访问:此Web应用程序实例已停止。无法加载[com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException]。为了调试以及终止导致非法访问的线程,将抛出以下堆栈跟踪。
at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1425)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1262)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1223)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:264)
at com.mysql.jdbc.Util.getInstance(Util.java:383)
... 44 more
Caused by: java.lang.IllegalStateException: 非法访问:此Web应用程序实例已停止。无法加载[com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException]。为了调试以及终止导致非法访问的线程,将抛出以下堆栈跟踪。
at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading(WebappClassLoaderBase.java:1435)
at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1423)
... 49 more
** END NESTED EXCEPTION *
定位到ServerMonitorTask
,这是个任务类,通过 @Scheduled定时执行,任务是交给线程池异步执行的。
刚启动 tomcat怎么会打印这个错误呢?web应用才刚启动啊。于是怀疑是不是之前的停止的有问题,没有关闭相关资源?于是看了下线程池,虽然的确没有主动关闭,但之前都是正常的,虽然没想明白,但还是处理下,于是乎在 @PreDestroy
注解里关了线程池。
重新部署,仍然报错,同样的错误日志,每10秒打印(@Scheduled
的确是每10秒执行)。这时怀疑会不会是别的tomcat把日志打印过来了,于是关停了此tomcat,ps -ef | grep 'java' | grep 'nms_ts3000ggch_8089'
(nms_ts3000ggch_8089是我tomcat路径),的确没有了。但是!观察日志,cataline.out居然仍然在持续打印这个错误日志,每10s稳定打印。这时通过各种AI工具,最后还是grok给了一个可能性:其他tomcat把日志打印到我这里了!于是于通过:
ps -ef | grep 'java'
查询了一下java进程,发现有个进程本不该还活着:nms_ts3000ggch_8089
,这个是啥呢?这是之前我这个tomcat的目录名称,因为多个tomcat命名不太规范,为做区分,要求重新命名,所以当时可能没有正确shutdown,就执行mv改名了,导致java进程在后台一直在执行。
这里有个问题:
按理说mv改名后,路径也变了,为什么之前的java进程还是会将日志打印到新路径下的catalina.out里呢?