线上错误日志

[ERROR] 220110 16:27:54.300 - org.springframework.web.util.NestedServletException: Handler dispatch failed; nested exception is java.lang.OutOfMemoryError: GC overhead limit exceeded (com.tplink.tpcw.web.aop.ExceptionAdvice) (http-nio-8443-exec-3) 
org.springframework.web.util.NestedServletException: Handler dispatch failed; nested exception is java.lang.OutOfMemoryError: GC overhead limit exceeded
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1054)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:942)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1005)
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:908)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:660)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:882)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:109)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:92)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:109)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:109)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.session.web.http.SessionRepositoryFilter.doFilterInternal(SessionRepositoryFilter.java:151)
    at org.springframework.session.web.http.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:85)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:109)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:490)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408)
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:853)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1587)
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded
    at org.hibernate.engine.internal.EntityEntryContext.reentrantSafeEntityEntries(EntityEntryContext.java:317)
    at org.hibernate.engine.internal.StatefulPersistenceContext.clear(StatefulPersistenceContext.java:233)
    at org.hibernate.internal.SessionImpl.internalClear(SessionImpl.java:395)
    at org.hibernate.internal.SessionImpl.afterTransactionCompletion(SessionImpl.java:2503)
    at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.afterTransactionCompletion(JdbcCoordinatorImpl.java:479)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.afterCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:198)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$400(JdbcResourceLocalTransactionCoordinatorImpl.java:39)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.rollback(JdbcResourceLocalTransactionCoordinatorImpl.java:295)
    at org.hibernate.engine.transaction.internal.TransactionImpl.rollback(TransactionImpl.java:145)
    at org.springframework.orm.hibernate5.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:654)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:838)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:812)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:552)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:299)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688)
    at com.tplink.tpcw.accounting.service.impl.AccountingClientServiceImpl$$EnhancerBySpringCGLIB$$f4e2c078.exportClientInvoiceData(<generated>)
    at com.tplink.tpcw.web.controller.accounting.AccountingClientController.exportClientInvoiceData(AccountingClientController.java:40)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:892)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797)
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1039)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:942)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1005)

jinfo查看线上应用JVM配置

[tpcw@tpcw1 ~]$ jps -l | grep tpcw.jar | awk '{print $1}' | xargs jinfo -flags
Attaching to process ID 79031, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.111-b14
Non-default VM flags: -XX:CICompilerCount=3 -XX:InitialHeapSize=127926272 -XX:MaxHeapSize=2021654528 -XX:MaxNewSize=673710080 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=42467328 -XX:OldSize=85458944 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseParallelGC
Command line:  -Dapp.key=/u1/home/tpcw/app.key -Duser.timezone=GMT+08

从jinfo输出看出,应用启动没有自定义JVM参数,使用的是JVM默认配置参数,堆设置MaxHeapSize=2021654528(约等于1.88GB), -XX:+UseParallelGC 即 Parallel Scavenge + Parallel Old组合(JDK 8默认垃圾回收器类型组合)

应用启动脚本如下

ps -ef | grep tpcw.jar | grep -v grep | awk '{print $2}' | xargs kill -9
nohup java -jar -Dapp.key=/u1/home/tpcw/app.key -Duser.timezone=GMT+08 tpcw.jar  --spring.profiles.active=prod --server.port=8080  > log  2>&1 &

jinfo

实时查看和调整JVM配置参数,其中,Non-default VM flags 是虚拟机默认设置的参数,Command line 是用户指定的参数,比如命令行启动 jar时加上的参数

jinfo [option] pid

-flags 输出全部的参数
-sysprops 输出系统属性
-flag name 输出对应名称的参数

-flag [+|-]name 开启或者关闭对应名称的参数(布尔类型参数)
-flag name=value 设定对应名称的参数(数字类型参数)

jstack

查看进程内当前时刻的线程快照,用于定位线程停顿、死锁等长时间等待的问题

top查java线程资源消耗情况

top -H -p pid

jstack定位线程执行点

jstack pid | grep 线程pid -A 50

jmap

查看给定进程、核心文件、远程调试服务器的共享对象内存映射和堆内存细节的工具,可查看堆使用情况、堆内对象直方图、加载类、生成堆快照等

//打印 JVM 堆概要信息,包括堆配置、新生代、老生代信息
[tpqms@server 10:57:13 ~]$ jmap -heap 26632 
Attaching to process ID 26632, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.60-b23

using thread-local object allocation.
Garbage-First (G1) GC with 6 thread(s)

Heap Configuration:
   MinHeapFreeRatio         = 40
   MaxHeapFreeRatio         = 70
   MaxHeapSize              = 2147483648 (2048.0MB)
   NewSize                  = 1363144 (1.2999954223632812MB)
   MaxNewSize               = 1287651328 (1228.0MB)
   OldSize                  = 5452592 (5.1999969482421875MB)
   NewRatio                 = 2
   SurvivorRatio            = 8
   MetaspaceSize            = 21807104 (20.796875MB)
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 1048576 (1.0MB)

Heap Usage:
G1 Heap:
   regions  = 2048
   capacity = 2147483648 (2048.0MB)
   used     = 640679920 (610.9999847412109MB)
   free     = 1506803728 (1437.000015258789MB)
   29.83398362994194% used
G1 Young Generation:
Eden Space:
   regions  = 470
   capacity = 649068544 (619.0MB)
   used     = 492830720 (470.0MB)
   free     = 156237824 (149.0MB)
   75.92891760904685% used
Survivor Space:
   regions  = 26
   capacity = 27262976 (26.0MB)
   used     = 27262976 (26.0MB)
   free     = 0 (0.0MB)
   100.0% used
G1 Old Generation:
   regions  = 115
   capacity = 397410304 (379.0MB)
   used     = 120586224 (114.99998474121094MB)
   free     = 276824080 (264.00001525878906MB)
   30.343003889501567% used

54718 interned Strings occupying 6144440 bytes.

jstat

虚拟机统计信息监视工具

jstat -gcutil pid 1000 20 ---每隔1s输出统计信息(共20次)

S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
4.18   0.00  71.29   9.27  96.22  94.70     24    0.512     5    0.856    1.369

粥于于
9 声望1 粉丝

代码搬运工