Administrator
Administrator
发布于 2025-04-11 / 15 阅读
0
0

记一次服务器tomcat持续打印诡异错误日志

这是一个开发环境,一个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里呢?


评论