Linux排查JVM问题

背景

通常来说当我们的Java服务出现问题时,首先需要考虑的是这个进程是不是还在运行,然后再关注这个进程所占用的资源多少,CPU、内存的使用情况,从而定位到具体问题。因此,有必要对Linux服务器中的JVM异常排查进行下记录。

方法

1、查找Java进程id

ps -ef|grep java

当然,如果服务器上有多个Java进程,我们可以考虑使用top命令,然后查看cpu和内存使用率最高的进程情况

top -c  #参数c表示列出命令的详细信息

此命令展示出的信息,各项含义可以参考:这篇文章

假设拿到的进程id 为 3907

2、jmap查看堆使用信息

jmap -heap 3907

拿到结果如下:

using thread-local object allocation.
Mark Sweep Compact GC

Heap Configuration:
   MinHeapFreeRatio         = 40
   MaxHeapFreeRatio         = 70
   MaxHeapSize              = 1258291200 (1200.0MB)
   NewSize                  = 26542080 (25.3125MB)
   MaxNewSize               = 419430400 (400.0MB)
   OldSize                  = 53149696 (50.6875MB)
   NewRatio                 = 2
   SurvivorRatio            = 8
   MetaspaceSize            = 21807104 (20.796875MB)
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 0 (0.0MB)

Heap Usage:
New Generation (Eden + 1 Survivor Space):
   capacity = 23986176 (22.875MB)
   used     = 13869504 (13.22698974609375MB)
   free     = 10116672 (9.64801025390625MB)
   57.82290599385246% used
Eden Space:
   capacity = 21364736 (20.375MB)
   used     = 11248072 (10.726997375488281MB)
   free     = 10116664 (9.648002624511719MB)
   52.64783987969709% used
From Space:
   capacity = 2621440 (2.5MB)
   used     = 2621432 (2.4999923706054688MB)
   free     = 8 (7.62939453125E-6MB)
   99.99969482421875% used
To Space:
   capacity = 2621440 (2.5MB)
   used     = 0 (0.0MB)
   free     = 2621440 (2.5MB)
   0.0% used
tenured generation:
   capacity = 53149696 (50.6875MB)
   used     = 28450632 (27.13263702392578MB)
   free     = 24699064 (23.55486297607422MB)
   53.52924690293619% used

21354 interned Strings occupying 1919928 bytes.

 3、通过查看gc统计信息来分析问题,如果gc次数比较多,那么发生内存泄漏的可能性就比较大了

jstat -gcutil 3907

 得到信息如下:

  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
100.00   0.00  97.85  53.53  94.62  92.74     76    0.857     2    0.227    1.083

其中各个参数的含义如下:

s0: 新生代survivor0的使用率
s1:s1的使用率
E: 新生代eden空间的使用率
O:老年代的使用率
M:元数据的空间使用率
YGC:新生代gc次数
YGCT:新生代GC总时长
FGC:full gc的次数
FGCT: full gc 的总时长
GCT: 总的gc时长

 4、查看各个类所对应的实例对象所占用的内存:(分析内存使用飙高原因

[root@localhost s]# jmap -histo 3907

 num     #instances         #bytes  class name
----------------------------------------------
   1:         67987        6238344  [C
   2:        337475        5399600  com.boc.eureka.service.TestHeap$OOMExample
   3:         12917        3820336  [I
   4:        111712        3574784  java.util.concurrent.locks.AbstractQueuedSynchronizer$Node
   5:         14247        3379280  [Ljava.lang.Object;
   6:         19022        1673936  java.lang.reflect.Method
   7:         67576        1621824  java.lang.String
   8:         46815        1498080  java.util.concurrent.ConcurrentHashMap$Node
   9:         11140        1225912  java.lang.Class
  10:          9775        1174376  [B
  11:         18018         720720  java.util.LinkedHashMap$Entry
  12:          8591         690872  [Ljava.util.HashMap$Node;
  13:           214         519680  [Ljava.util.concurrent.ConcurrentHashMap$Node;
  14:          8725         488600  java.util.LinkedHashMap
  15:         13800         441600  java.util.HashMap$Node
  16:         26304         420864  java.lang.Object
  17:         17791         392920  [Ljava.lang.Class;
  18:          5130         369360  java.lang.reflect.Field
... ...

   5010: 1 16 sun.util.locale.provider.SPILocaleProviderAdapter
   5011: 1 16 sun.util.locale.provider.TimeZoneNameUtility$TimeZoneNameGetter
   5012: 1 16 sun.util.resources.LocaleData
   5013: 1 16 sun.util.resources.LocaleData$LocaleDataResourceBundleControl

 从上面的结果可以看出:

num:表示编号, #instances表示实例数量,#bytes表示占用的内存字节数量,class name是对应的类名

一个类,一般也就16字节大小,而我们的基础数据类型,它的大小char: 2bytes,short:2bytes, int:4 bytes.long:8bytes

 

 5、查看进程中线程使用情况(分析CPU的使用飙高原因

top -Hp 3907 #其中参数H表示使用线程分析模式,p表示指定相关的进程id为3907

上述命令将列出进程下的各个线程的使用情况,我们根据结果,得到使用CPU多的线程id

top - 21:03:44 up 54 min,  3 users,  load average: 0.17, 0.22, 0.39
Threads:  61 total,   2 running,  59 sleeping,   0 stopped,   0 zombie
%Cpu(s):  1.0 us,  0.0 sy,  0.0 ni, 99.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  4912604 total,  2212304 free,  1247976 used,  1452324 buff/cache
KiB Swap:  3354620 total,  3354620 free,        0 used.  3371908 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND                                                                            
 3662 root      20   0 3350296 224996  13676 R  0.7  4.6   0:37.39 TaskAcceptor-ta                                                                    
 3684 root      20   0 3350296 224996  13676 R  0.7  4.6   0:37.34 TaskAcceptor-12                                                                    
 3640 root      20   0 3350296 224996  13676 S  0.3  4.6   0:01.19 Catalina-utilit                                                                    
 3563 root      20   0 3350296 224996  13676 S  0.0  4.6   0:00.06 java                                                                               
 3564 root      20   0 3350296 224996  13676 S  0.0  4.6   0:38.20 java                                                                               
 3565 root      20   0 3350296 224996  13676 S  0.0  4.6   0:02.71 VM Thread                                                                          
 3566 root      20   0 3350296 224996  13676 S  0.0  4.6   0:00.05 Reference Handl                                                                    
 3567 root      20   0 3350296 224996  13676 S  0.0  4.6   0:00.06 Finalizer      
    .... ....
 3657 root      20   0 3350296 224996  13676 S  0.0  4.6   0:00.09 Eureka-Eviction                                                                    
 3658 root      20   0 3350296 224996  13676 S  0.0  4.6   0:00.01 Eureka-MeasureR                                                                    
 3659 root      20   0 3350296 224996  13676 S  0.0  4.6   0:00.00 ReplicaAwareIns                                                                    
 3660 root      20   0 3350296 224996  13676 S  0.0  4.6   0:00.01 Eureka-MeasureR                                                                    
 3661 root      20   0 3350296 224996  13676 S  0.0  4.6   0:00.05 Apache-HttpClie 

我们选择id为3662的线程,查看是哪个类里面在运行任务

先将3662转为16进制,因为后面查看jstack输出的信息,线程id是16进制的

printf "%x\n" 3662
e4e

得到结果e4e

然后通过jstack查看e4e相关的信息

jstack -l
再查找e4e相关的信息

得到结果:

"TaskAcceptor-target_127.0.0.1" #21 daemon prio=5 os_prio=0 tid=0x00007f5d111de000 nid=0xe4e runnable [0x00007f5ce8597000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000cf9b82d8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    at com.netflix.eureka.util.batcher.AcceptorExecutor$AcceptorRunner.drainInputQueues(AcceptorExecutor.java:228)
    at com.netflix.eureka.util.batcher.AcceptorExecutor$AcceptorRunner.run(AcceptorExecutor.java:189)
    at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
    - None

这样就能分析出是哪个类里面的哪个方法,在不断的占用CPU了。

其中:


tid, Java memory address of its internal Thread control structure.

nid, native thread id. 每一个nid对应于linux下的一个tid, 即lwp  (light weight process, or thread)

 

posted @ 2020-07-19 21:19  sliec  阅读(647)  评论(0编辑  收藏  举报