zoukankan      html  css  js  c++  java
  • jvm gc 调优 实战

    非常不错的文章们 转自:

    中文:http://blog.csdn.net/dragonassassin/article/details/51010947

    http://josh-persistence.iteye.com/blog/2161848?utm_source=tuicool&utm_medium=referral

    英文:超级超级超级无敌棒的Gc问题调优五部曲

    https://www.cubrid.org/blog/understanding-java-garbage-collection

    https://www.cubrid.org/blog/how-to-monitor-java-garbage-collection/

    https://www.cubrid.org/blog/how-to-tune-java-garbage-collection

    https://www.cubrid.org/blog/maxclients-in-apache-and-its-effect-on-tomcat-during-full-gc

    https://www.cubrid.org/blog/the-principles-of-java-application-performance-tuning

    前提概要: 

           JDK本身提供了很多方便的JVM性能调优监控工具,除了集成式的VisualVM和jConsole外,还有jps、jstack、jmap、jhat、jstat、hprof等小巧的工具,每一种工具都有其自身的特点,用户可以根据你需要检测的应用或者程序片段的状况,适当的选择相应的工具进行检测。接下来的两个专题分别会讲VisualVM的具体应用。

     

    现实企业级Java开发中,有时候我们会碰到下面这些问题:

    • OutOfMemoryError,内存不足

    • 内存泄露

    • 线程死锁

    • 锁争用(Lock Contention)

    • Java进程消耗CPU过高

    • ......

    这些问题在日常开发中可能被很多人忽视(比如有的人遇到上面的问题只是重启服务器或者调大内存,而不会深究问题根源),但能够理解并解决这些问题是Java程序员进阶的必备要求。

    一、 jps(Java Virtual Machine Process Status Tool)      : 基础工具

           实际中这是最常用的命令,下面要介绍的小工具更多的都是先要使用jps查看出当前有哪些Java进程,获取该Java进程的id后再对该进程进行处理。

        jps主要用来输出JVM中运行的进程状态信息。语法格式如下:

    Java代码  收藏代码
    1. jps [options] [hostid]  

     如果不指定hostid就默认为当前主机或服务器。

      命令行参数选项说明如下:

    Java代码  收藏代码
    1. -q 不输出类名、Jar名和传入main方法的参数  
    2. -m 输出传入main方法的参数  
    3. -l 输出main类或Jar的全限名  
    4. -v 输出传入JVM的参数  

      

    比如

    1、我现在有一个WordCountTopo的Strom程序正在本机运行。

    2、使用java -jar deadlock.jar & 启动一个线程死锁的程序 

    Java代码  收藏代码
    1. wangsheng@WANGSHENG-PC /E  
    2. $ jps -ml  
    3. 14200 deadlock.jar  
    4. 13952 com.wsheng.storm.topology.WordCountTopo D://input/ 3  
    5. 13248 sun.tools.jps.Jps -ml  
    6. 9728  

      

    二、 jstack    jstack主要用来查看某个Java进程内的线程堆栈信息。语法格式如下:

    Java代码  收藏代码
    1. jstack [option] pid  
    2. jstack [option] executable core  
    3. jstack [option] [server-id@]remote-hostname-or-ip  
    Java代码  收藏代码
    1. 命令行参数选项说明如下:  
    Java代码  收藏代码
    1. -l long listings,会打印出额外的锁信息,在发生死锁时可以用<strong>jstack -l pid</strong>来观察锁持有情况  
    2. -m mixed mode,不仅会输出Java堆栈信息,还会输出C/C++堆栈信息(比如Native方法)  

        jstack可以定位到线程堆栈,根据堆栈信息我们可以定位到具体代码,所以它在JVM性能调优中使用得非常多。

        下面我们来一个实例:

         找出某个Java进程中最耗费CPU的Java线程并定位堆栈信息,用到的命令有ps、top、printf、jstack、grep。

       

        第一步: 先找出Java进程ID,服务器上的Java应用名称为wordcount.jar:

      

    Java代码  收藏代码
    1. [root@storm-master home]# ps -ef | grep wordcount | grep -v grep  
    2. root       2860   2547 13 02:09 pts/0    00:02:03 java -jar wordcount.jar /home/input 3  

        得到进程ID为2860,

        第二步:找出该进程内最耗费CPU的线程,可以使用如下3个命令,这里我们使用第3个命令得出如下结果:

    Java代码  收藏代码
    1. 1)ps -Lfp pid : 即 ps -Lfp 2860  
    2. 2)ps -mp pid -o THREAD, tid, time :即 ps -mp 2860 -o THREAD,tid,time  
    3. 3)top -Hp pid: 即 <strong>top -Hp 2860</strong>  
    4. 用第三个,输出如下:   

     

     

      TIME列就是各个Java线程耗费的CPU时间,显然CPU时间最长的是ID为2968的线程,用

    Java代码  收藏代码
    1. printf "%x " 2968  

        得到2968的十六进制值为b98,下面会用到。     

        第三步:终于轮到jstack上场了,它用来输出进程2860的堆栈信息,然后根据线程ID的十六进制值grep,如下:

    Java代码  收藏代码
    1. [root@storm-master home]# jstack 2860 | grep b98  
    2. "SessionTracker" prio=10 tid=0x00007f55a44e4800 nid=0xb53 in Object.wait() [0x00007f558e06c000  

     可以看到CPU消耗在SessionTracker这个类的Object.wait(),于是就能很容易的定位到相关的代码了。

      

    三、 jmap(Memory Map)和 jhat(Java Heap Analysis Tool):

    jmap导出堆内存,然后使用jhat来进行分析

        jmap用来查看堆内存使用状况,一般结合jhat使用。

        jmap语法格式如下:

    Java代码  收藏代码
    1. jmap [option] pid  
    2. jmap [option] executable core  
    3. jmap [option] [server-id@]remote-hostname-or-ip  

     如果运行在64位JVM上,由于linux操作系统的不同,可能需要指定-J-d64命令选项参数。

     1、打印进程的类加载器和类加载器加载的持久代对象信息: jmap -permstat pid

    个人感觉这个不是太有用蠢话

    输出:类加载器名称、对象是否存活(不可靠)、对象地址、父类加载器、已加载的类大小等信息,如图:


     

    2、查看进程堆内存使用情况:包括使用的GC算法、堆配置参数和各代中堆内存使用jmap -heap pid

    比如下面的例子

    Java代码  收藏代码
    1. [root@storm-master home]# jmap -heap 2860  
    2. Attaching to process ID 2860, please wait...  
    3. Debugger attached successfully.  
    4. Server compiler detected.  
    5. JVM version is 20.45-b01  
    6.   
    7. using thread-local object allocation.  
    8. Mark Sweep Compact GC  
    9.   
    10. Heap Configuration:  
    11.    MinHeapFreeRatio = 40  
    12.    MaxHeapFreeRatio = 70  
    13.    MaxHeapSize      = 257949696 (246.0MB)  
    14.    NewSize          = 1310720 (1.25MB)  
    15.    MaxNewSize       = 17592186044415 MB  
    16.    OldSize          = 5439488 (5.1875MB)  
    17.    NewRatio         = 2  
    18.    SurvivorRatio    = 8  
    19.    PermSize         = 21757952 (20.75MB)  
    20.    MaxPermSize      = 85983232 (82.0MB)  
    21.   
    22. Heap Usage:  
    23. New Generation (Eden + 1 Survivor Space):  
    24.    capacity = 12189696 (11.625MB)  
    25.    used     = 6769392 (6.4557952880859375MB)  
    26.    free     = 5420304 (5.1692047119140625MB)  
    27.    55.53372290826613% used  
    28. Eden Space:  
    29.    capacity = 10878976 (10.375MB)  
    30.    used     = 6585608 (6.280525207519531MB)  
    31.    free     = 4293368 (4.094474792480469MB)  
    32.    60.53518272307982% used  
    33. From Space:  
    34.    capacity = 1310720 (1.25MB)  
    35.    used     = 183784 (0.17527008056640625MB)  
    36.    free     = 1126936 (1.0747299194335938MB)  
    37.    14.0216064453125% used  
    38. To Space:  
    39.    capacity = 1310720 (1.25MB)  
    40.    used     = 0 (0.0MB)  
    41.    free     = 1310720 (1.25MB)  
    42.    0.0% used  
    43. tenured generation:  
    44.    capacity = 26619904 (25.38671875MB)  
    45.    used     = 15785896 (15.054603576660156MB)  
    46.    free     = 10834008 (10.332115173339844MB)  
    47.    59.30110040967841% used  
    48. Perm Generation:  
    49.    capacity = 33554432 (32.0MB)  
    50.    used     = 33323352 (31.779624938964844MB)  
    51.    free     = 231080 (0.22037506103515625MB)  
    52.    99.31132793426514% used  

     3、查看堆内存中的对象数目、大小统计直方图,如果带上live则只统计活对象:jmap -histo[:live] pid

    Java代码  收藏代码
    1. [root@storm-master Desktop]# jmap -histo 2860  
    2.   
    3.  num     #instances         #bytes  class name  
    4. ----------------------------------------------  
    5.    1:         13917       11432488  [B  
    6.    2:          6117        6181448  <instanceKlassKlass>  
    7.    3:         39520        6004504  <constMethodKlass>  
    8.    4:          6117        5517072  <constantPoolKlass>  
    9.    5:         39520        5383280  <methodKlass>  
    10.    6:          5148        3150944  <constantPoolCacheKlass>  
    11.    7:         29954        2810640  [C  
    12.    8:         50179        2469272  <symbolKlass>  
    13.    9:         42122        1791704  [Ljava.lang.Object;  
    14.   10:          1804         961464  <methodDataKlass>  
    15.   11:         11747         941200  [Ljava.util.HashMap$Entry;  
    16.   12:         28786         921152  java.lang.String  
    17.   13:          6347         660088  java.lang.Class  
    18.   14:          7374         625616  [S  
    19.   15:         11740         563520  java.util.HashMap  
    20.   16:         23447         562728  clojure.lang.PersistentHashMap$BitmapIndexedNode  
    21.   17:         10980         351360  clojure.lang.Symbol  
    22.   18:          8544         341760  java.lang.ref.SoftReference  
    23.   19:          8028         336632  [[I  
    24.   20:          3944         283968  java.lang.reflect.Constructor  
    25.   21:          4744         227712  java.nio.HeapByteBuffer  
    26.   22:          6854         219328  java.util.AbstractList$Itr  
    27.   23:          2185         195192  [I  
    28.   24:          3854         184992  java.nio.HeapCharBuffer  
    29.   25:          5500         176000  java.util.concurrent.ConcurrentHashMap$HashEntry  

     class name是对象类型,说明如下: 

    Java代码  收藏代码
    1. B  byte  
    2. C  char  
    3. D  double  
    4. F  float  
    5. I  int  
    6. J  long  
    7. Z  boolean  
    8. [  数组,如[I表示int[]  
    9. [L+类名 其他对象  

        4、还有一个很常用的情况是:用jmap把进程内存使用情况dump到文件中,再用jhat分析查看。需要注意的是 dump出来的文件还可以用MAT、VisualVM等工具查看。

    jmap进行dump命令格式如下:

    Java代码  收藏代码
    1. <strong>jmap -dump:format=b,file=dumpFileName pid</strong>  

     

        我一样地对上面进程ID为2860进行Dump:

      

    Java代码  收藏代码
    1. [root@storm-master Desktop]# jmap -dump:format=b,file=/home/dump.dat 2860  
    2. Dumping heap to /home/dump.dat ...  
    3. Heap dump file created  

      然后使用jhat来对上面dump出来的内容进行分析 

    Java代码  收藏代码
    1. [root@storm-master Desktop]# jhat -port 8888 /home/dump.dat   
    2. Reading from /home/dump.dat...  
    3. Dump file created Sat Aug 01 04:21:12 PDT 2015  
    4. Snapshot read, resolving...  
    5. Resolving 411123 objects...  
    6. Chasing references, expect 82 dots..................................................................................  
    7. Eliminating duplicate references..................................................................................  
    8. Snapshot resolved.  
    9. Started HTTP server on port 8888  
    10. Server is ready.  

        注意如果Dump文件太大,可能需要加上-J-Xmx512m参数以指定最大堆内存,即jhat -J-Xmx512m -port 8888 /home/dump.dat。然后就可以在浏览器中输入主机地址:8888查看了:

     

     

    点击每一个蓝色的超链接,你都会看到其相关更具体的信息,而最后一项更是支持OQL(对象查询语言)。

    四、jstat(JVM统计监测工具): 看看各个区内存和GC的情况

        语法格式如下:

    Java代码  收藏代码
    1. jstat [ generalOption | outputOptions vmid [interval[s|ms] [count]] ]  

     vmid是Java虚拟机ID,在Linux/Unix系统上一般就是进程ID。interval是采样时间间隔。count是采样数目。比如下面输出的是GC信息,采样时间间隔为250ms,采样数为6:

    Java代码  收藏代码
    1. [root@storm-master Desktop]# jstat -gc 2860 250 6  

     

     

    要明白上面各列的意义,先看JVM堆内存布局:

    可以看出:

    Java代码  收藏代码
    1. 堆内存 = 年轻代 + 年老代 + 永久代  
    2. 年轻代 = Eden区 + 两个Survivor区(From和To)  

     现在来解释各列含义:

    Java代码  收藏代码
    1. S0C、S1C、S0U、S1U:Survivor 0/1区容量(Capacity)和使用量(Used)  
    2. EC、EU:Eden区容量和使用量  
    3. OC、OU:年老代容量和使用量  
    4. PC、PU:永久代容量和使用量  
    5. YGC、YGT:年轻代GC次数和GC耗时  
    6. FGC、FGCT:Full GC次数和Full GC耗时  
    7. GCT:GC总耗时  

    五、hprof(Heap/CPU Profiling Tool):    hprof能够展现CPU使用率,统计堆内存使用情况。

          HPROF: 一个Heap/CPU Profiling工具:J2SE中提供了一个简单的命令行工具来对java程序的cpu和heap进行 profiling,叫做HPROF。HPROF实际上是JVM中的一个native的库,它会在JVM启动的时候通过命令行参数来动态加载,并成为 JVM进程的一部分。若要在java进程启动的时候使用HPROF,用户可以通过各种命令行参数类型来使用HPROF对java进程的heap或者 (和)cpu进行profiling的功能。HPROF产生的profiling数据可以是二进制的,也可以是文本格式的。这些日志可以用来跟踪和分析 java进程的性能问题和瓶颈,解决内存使用上不优的地方或者程序实现上的不优之处。二进制格式的日志还可以被JVM中的HAT工具来进行浏览和分析,用 以观察java进程的heap中各种类型和数据的情况。在J2SE 5.0以后的版本中,HPROF已经被并入到一个叫做Java Virtual Machine Tool Interface(JVM TI)中。

       

    语法格式如下:

    Java代码  收藏代码
    1. java -agentlib:hprof[=options] ToBeProfiledClass  
    2. java -Xrunprof[:options] ToBeProfiledClass  
    3. javac -J-agentlib:hprof[=options] ToBeProfiledClass  

     完整的命令选项如下:

    Java代码  收藏代码
    1. Option Name and Value  Description                    Default  
    2. ---------------------  -----------                    -------  
    3. heap=dump|sites|all    heap profiling                 all  
    4. cpu=samples|times|old  CPU usage                      off  
    5. monitor=y|n            monitor contention             n  
    6. format=a|b             text(txt) or binary output     a  
    7. file=<file>            write data to file             java.hprof[.txt]  
    8. net=<host>:<port>      send data over a socket        off  
    9. depth=<size>           stack trace depth              4  
    10. interval=<ms>          sample interval in ms          10  
    11. cutoff=<value>         output cutoff point            0.0001  
    12. lineno=y|n             line number in traces?         y  
    13. thread=y|n             thread in traces?              n  
    14. doe=y|n                dump on exit?                  y  
    15. msa=y|n                Solaris micro state accounting n  
    16. force=y|n              force output to <file>         y  
    17. verbose=y|n            print messages about dumps     y  

    - Get sample cpu information every 20 millisec, with a stack depth of 3: 

             java -agentlib:hprof=cpu=samples,interval=20,depth=3 classname 
         - Get heap usage information based on the allocation sites: 
             java -agentlib:hprof=heap=sites classname 

          上面每隔20毫秒采样CPU消耗信息,堆栈深度为3,生成的profile文件名称是java.hprof.txt,在当前目录。 

          默认情况下,java进程profiling的信息(sites和dump)都会被 写入到一个叫做java.hprof.txt的文件中。大多数情况下,该文件中都会对每个trace,threads,objects包含一个ID,每一 个ID代表一个不同的观察对象。通常,traces会从300000开始。 默认,force=y,会将所有的信息全部输出到output文件中,所以如果含有 多个JVMs都采用的HRPOF enable的方式运行,最好将force=n,这样能够将单独的JVM的profiling信息输出到不同的指定文件。 interval选项只在 cpu=samples的情况下生效,表示每隔多少毫秒对java进程的cpu使用情况进行一次采集。 msa选项仅仅在Solaris系统下才有效, 表示会使用Solaris下的Micro State Accounting功能 

      

    第二部分: 实例部分:

    该部分将使用相关的实例和前面提到的JVM性能调优工具来进行性能诊断。

    1、使用jstack来分析死锁问题:

           上面说明中提到 jstack主要用来查看某个Java进程内的线程堆栈信息,您可以使用它查明问题。jstack [-l] <pid>,pid可以通过使用jps命令来查看当前Java程序的pid值,-l是可选参数,它可以显示线程阻塞/死锁情况

    Java代码  收藏代码
    1. package com.wsheng.aggregator.thread.performance;  
    2.   
    3. import org.springframework.stereotype.Component;  
    4.   
    5. /** 
    6.  * Dead lock example 
    7.  *  
    8.  * @author Josh Wang(Sheng) 
    9.  * 
    10.  * @email  josh_wang23@hotmail.com 
    11.  */  
    12. @Component  
    13. public class DeadLock {    
    14.     
    15.     public static void main(String[] args) {    
    16.         System.out.println(" start the example ----- ");  
    17.         final Object obj_1 = new Object(), obj_2 = new Object();    
    18.             
    19.         Thread t1 = new Thread("t1") {    
    20.             @Override    
    21.             public void run() {    
    22.                 synchronized (obj_1) {    
    23.                     try {    
    24.                         System.out.println("thread t1 start...");  
    25.                         Thread.sleep(3000);    
    26.                     } catch (InterruptedException e) {e.printStackTrace();}    
    27.                         
    28.                     synchronized (obj_2) {    
    29.                         System.out.println("thread t1 done....");    
    30.                     }    
    31.                 }    
    32.             }    
    33.         };    
    34.             
    35.         Thread t2 = new Thread("t2") {    
    36.             @Override    
    37.             public void run() {    
    38.                 synchronized (obj_2) {    
    39.                     try {    
    40.                         System.out.println("thread t2 start...");  
    41.                         Thread.sleep(3000);    
    42.                     } catch (InterruptedException e) {e.printStackTrace();}    
    43.                         
    44.                     synchronized (obj_1) {    
    45.                         System.out.println("thread t2 done...");    
    46.                     }    
    47.                 }    
    48.             }    
    49.         };    
    50.             
    51.         t1.start();    
    52.         t2.start();    
    53.     }    
    54.         
    55. }    

        以上DeadLock类是一个死锁的例子,假使在我们不知情的情况下,运行DeadLock后,发现等了N久都没有在屏幕打印线程完成信息。这个时候我们就可以使用jps查看该程序的pid值和使用jstack来生产堆栈结果问题。

    Java代码  收藏代码
    1. java -jar deadlock.jar <span style="font-size: 1em; line-height: 1.5;">com.wsheng.aggregator.thread.performance.</span><span style="font-size: 1em; line-height: 1.5;">DeadLock & </span>  
    Java代码  收藏代码
    1. $ jps    
    2.   3076 Jps    
    3.   448 DeadLock    
    4. $ <strong>jstack -l 448 > deadlock.jstack</strong>  

     结果文件deadlock.jstack内容如下:

    Java代码  收藏代码
    1. 2014-11-29 13:31:06  
    2. Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.65-b04 mixed mode):  
    3.   
    4. "Attach Listener" daemon prio=5 tid=0x00007fd9d4002800 nid=0x440b waiting on condition [0x0000000000000000]  
    5.    java.lang.Thread.State: RUNNABLE  
    6.   
    7.    Locked ownable synchronizers:  
    8.     - None  
    9.   
    10. "DestroyJavaVM" prio=5 tid=0x00007fd9d4802000 nid=0x1903 waiting on condition [0x0000000000000000]  
    11.    java.lang.Thread.State: RUNNABLE  
    12.   
    13.    Locked ownable synchronizers:  
    14.     - None  
    15.   
    16. "t2" prio=5 tid=0x00007fd9d30ac000 nid=0x5903 waiting for monitor entry [0x000000011da46000]  
    17.    java.lang.Thread.State: BLOCKED (on object monitor)  
    18.     at DeadLock$2.run(DeadLock.java:38)  
    19.     - waiting to lock <0x00000007aaba7e58> (a java.lang.Object)  
    20.     - locked <0x00000007aaba7e68> (a java.lang.Object)  
    21.   
    22.    Locked ownable synchronizers:  
    23.     - None  
    24.   
    25. "t1" prio=5 tid=0x00007fd9d30ab800 nid=0x5703 waiting for monitor entry [0x000000011d943000]  
    26.    java.lang.Thread.State: BLOCKED (on object monitor)  
    27.     at DeadLock$1.run(DeadLock.java:23)  
    28.     - waiting to lock <0x00000007aaba7e68> (a java.lang.Object)  
    29.     - locked <0x00000007aaba7e58> (a java.lang.Object)  
    30.   
    31.    Locked ownable synchronizers:  
    32.     - None  
    33.   
    34. "Service Thread" daemon prio=5 tid=0x00007fd9d2809000 nid=0x5303 runnable [0x0000000000000000]  
    35.    java.lang.Thread.State: RUNNABLE  
    36.   
    37.    Locked ownable synchronizers:  
    38.     - None  
    39.   
    40. "C2 CompilerThread1" daemon prio=5 tid=0x00007fd9d304e000 nid=0x5103 waiting on condition [0x0000000000000000]  
    41.    java.lang.Thread.State: RUNNABLE  
    42.   
    43.    Locked ownable synchronizers:  
    44.     - None  
    45.   
    46. "C2 CompilerThread0" daemon prio=5 tid=0x00007fd9d2800800 nid=0x4f03 waiting on condition [0x0000000000000000]  
    47.    java.lang.Thread.State: RUNNABLE  
    48.   
    49.    Locked ownable synchronizers:  
    50.     - None  
    51.   
    52. "Signal Dispatcher" daemon prio=5 tid=0x00007fd9d3035000 nid=0x4d03 runnable [0x0000000000000000]  
    53.    java.lang.Thread.State: RUNNABLE  
    54.   
    55.    Locked ownable synchronizers:  
    56.     - None  
    57.   
    58. "Finalizer" daemon prio=5 tid=0x00007fd9d2013000 nid=0x3903 in Object.wait() [0x000000011d18d000]  
    59.    java.lang.Thread.State: WAITING (on object monitor)  
    60.     at java.lang.Object.wait(Native Method)  
    61.     - waiting on <0x00000007aaa85608> (a java.lang.ref.ReferenceQueue$Lock)  
    62.     at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)  
    63.     - locked <0x00000007aaa85608> (a java.lang.ref.ReferenceQueue$Lock)  
    64.     at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)  
    65.     at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)  
    66.   
    67.    Locked ownable synchronizers:  
    68.     - None  
    69.   
    70. "Reference Handler" daemon prio=5 tid=0x00007fd9d2012000 nid=0x3703 in Object.wait() [0x000000011d08a000]  
    71.    java.lang.Thread.State: WAITING (on object monitor)  
    72.     at java.lang.Object.wait(Native Method)  
    73.     - waiting on <0x00000007aaa85190> (a java.lang.ref.Reference$Lock)  
    74.     at java.lang.Object.wait(Object.java:503)  
    75.     at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)  
    76.     - locked <0x00000007aaa85190> (a java.lang.ref.Reference$Lock)  
    77.   
    78.    Locked ownable synchronizers:  
    79.     - None  
    80.   
    81. "VM Thread" prio=5 tid=0x00007fd9d5011000 nid=0x3503 runnable   
    82.   
    83. "GC task thread#0 (ParallelGC)" prio=5 tid=0x00007fd9d200b000 nid=0x2503 runnable   
    84.   
    85. "GC task thread#1 (ParallelGC)" prio=5 tid=0x00007fd9d200b800 nid=0x2703 runnable   
    86.   
    87. "GC task thread#2 (ParallelGC)" prio=5 tid=0x00007fd9d200c800 nid=0x2903 runnable   
    88.   
    89. "GC task thread#3 (ParallelGC)" prio=5 tid=0x00007fd9d200d000 nid=0x2b03 runnable   
    90.   
    91. "GC task thread#4 (ParallelGC)" prio=5 tid=0x00007fd9d200d800 nid=0x2d03 runnable   
    92.   
    93. "GC task thread#5 (ParallelGC)" prio=5 tid=0x00007fd9d200e000 nid=0x2f03 runnable   
    94.   
    95. "GC task thread#6 (ParallelGC)" prio=5 tid=0x00007fd9d200f000 nid=0x3103 runnable   
    96.   
    97. "GC task thread#7 (ParallelGC)" prio=5 tid=0x00007fd9d200f800 nid=0x3303 runnable   
    98.   
    99. "VM Periodic Task Thread" prio=5 tid=0x00007fd9d3033800 nid=0x5503 waiting on condition   
    100.   
    101. JNI global references: 114  
    102.   
    103.   
    104. <strong>Found one Java-level deadlock:</strong>  
    105. =============================  
    106. <strong>"t2":  
    107.   waiting to lock monitor 0x00007fd9d30aebb8 (object 0x00000007aaba7e58, a java.lang.Object),  
    108.   which is held by "t1"  
    109. "t1":  
    110.   waiting to lock monitor 0x00007fd9d28128b8 (object 0x00000007aaba7e68, a java.lang.Object),  
    111.   which is held by "t2"  
    112.   
    113. Java stack information for the threads listed above:</strong>  
    114. ===================================================  
    115. "t2":  
    116.     at DeadLock$2.run(DeadLock.java:38)  
    117.     - waiting to lock <0x00000007aaba7e58> (a java.lang.Object)  
    118.     - locked <0x00000007aaba7e68> (a java.lang.Object)  
    119. "t1":  
    120.     at DeadLock$1.run(DeadLock.java:23)  
    121.     - waiting to lock <0x00000007aaba7e68> (a java.lang.Object)  
    122.     - locked <0x00000007aaba7e58> (a java.lang.Object)  
    123.   
    124. Found 1 deadlock.  

     从这个结果文件我们一看到发现了一个死锁,具体是线程t2在等待线程t1,而线程t1在等待线程t2造成的,同时也记录了线程的堆栈和代码行数,通过这个堆栈和行数我们就可以去检查对应的代码块,从而发现问题和解决问题。

    可通过下面的代码解决死锁问题:

    Java代码  收藏代码
    1. import java.util.concurrent.locks.Lock;  
    2. import java.util.concurrent.locks.ReentrantLock;  
    3.   
    4. /** 
    5.  * Dead lock example 
    6.  *  
    7.  * @author Josh Wang(Sheng) 
    8.  * 
    9.  * @email  josh_wang23@hotmail.com 
    10.  */  
    11. public class DeadLock2Live {    
    12.     
    13.     public static void main(String[] args) {    
    14.         System.out.println(" start the example ----- ");  
    15.         final Lock lock = new ReentrantLock();   
    16.             
    17.         Thread t1 = new Thread("t1") {    
    18.             @Override    
    19.             public void run() {    
    20.                 try {    
    21.                 lock.lock();  
    22.                     Thread.sleep(3000);   
    23.                     System.out.println("thread t1 done.");  
    24.                 } catch (InterruptedException e) {  
    25.                     e.printStackTrace();  
    26.                 } finally {  
    27.                     lock.unlock();  
    28.                 }  
    29.             }  
    30.             };    
    31.             
    32.         Thread t2 = new Thread("t2") {    
    33.             @Override    
    34.             public void run() {    
    35.                 try {    
    36.                     lock.lock();  
    37.                     Thread.sleep(3000);  
    38.                     System.out.println("thread t2 done.");  
    39.                      
    40.   
    41.                 }  catch (InterruptedException e) {  
    42.                     e.printStackTrace();  
    43.                 } finally {  
    44.                     lock.unlock();  
    45.                 }  
    46.             }    
    47.         };    
    48.             
    49.         t1.start();    
    50.         t2.start();    
    51.       
    52. }  
    53.           
    54. }    

     2、继续使用jstack来分析HashMap在多线程情况下的死锁问题:

           对于如下代码,使用10个线程来处理提交的2000个任务,每个任务会分别循环往hashmap中分别存入和取出1000个数,通过测试发现,程序并不能完整执行完成。[PS:该程序能不能成功执行完,有时也取决于所使用的服务器的运行状况,我在笔记本上测试的时候,大多时候该程序不能成功执行完成,有时会出现CPU转速加快,发热等情况]

    Java代码  收藏代码
    1. import java.util.HashMap;  
    2. import java.util.Map;  
    3. import java.util.concurrent.Callable;  
    4. import java.util.concurrent.ExecutionException;  
    5. import java.util.concurrent.ExecutorService;  
    6. import java.util.concurrent.Executors;  
    7. /** 
    8.  * @author Josh Wang(Sheng) 
    9.  * 
    10.  * @email  josh_wang23@hotmail.com 
    11.  */  
    12. public class HashMapDeadLock implements Callable<Integer> {  
    13.       
    14.     private static ExecutorService threadPool = Executors.newFixedThreadPool(10);  
    15.       
    16.     private static Map<Integer, Integer> results = new HashMap<>();  
    17.   
    18.     @Override  
    19.     public Integer call() throws Exception {  
    20.         results.put(1, 1);  
    21.         results.put(2, 2);  
    22.         results.put(3, 3);  
    23.           
    24.         for (int i = 0; i < 1000; i++) {  
    25.             results.put(i, i);  
    26.         }  
    27.           
    28.         Thread.sleep(1000);  
    29.           
    30.         for (int i= 0; i < 1000; i++) {  
    31.             results.remove(i);  
    32.         }  
    33.           
    34.         System.out.println(" ---- " + Thread.currentThread().getName()  + "     " + results.get(0));  
    35.           
    36.         return results.get(1);  
    37.     }  
    38.       
    39.       
    40. public static void main(String[] args) throws InterruptedException, ExecutionException {  
    41.     try {  
    42.         for (int i = 0; i < 2000; i++) {  
    43.              HashMapDeadLock hashMapDeadLock  = new HashMapDeadLock();  
    44. //           Future<Integer> future = threadPool.submit(hashMapDeadLock);  
    45. //           future.get();  
    46.              threadPool.submit(hashMapDeadLock);  
    47.         }  
    48.      } catch (Exception e) {  
    49.         e.printStackTrace();  
    50.      } finally {  
    51.         threadPool.shutdown();  
    52.      }  
    53.     }  
    54. }  

    1) 使用jps查看线程可得:

    Java代码  收藏代码
    1. 43221 Jps  
    2. 30056   
    3. 43125 HashMapDeadLock  

    2)使用jstack导出多线程栈区信息:

    Java代码  收藏代码
    1. jstack -l 43125 > hash.jstack   

    3) hash.jstack的内容如下:

    Java代码  收藏代码
    1. 2014-11-29 18:14:22  
    2. Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.65-b04 mixed mode):  
    3.   
    4. "Attach Listener" daemon prio=5 tid=0x00007f83ee08a000 nid=0x5d07 waiting on condition [0x0000000000000000]  
    5.    java.lang.Thread.State: RUNNABLE  
    6.   
    7.    Locked ownable synchronizers:  
    8.     - None  
    9.   
    10. "DestroyJavaVM" prio=5 tid=0x00007f83eb016800 nid=0x1903 waiting on condition [0x0000000000000000]  
    11.    java.lang.Thread.State: RUNNABLE  
    12.   
    13.    Locked ownable synchronizers:  
    14.     - None  
    15.   
    16. "pool-1-thread-10" prio=5 tid=0x00007f83ec80a000 nid=0x6903 runnable [0x000000011cd19000]  
    17.    java.lang.Thread.State: RUNNABLE  
    18.     at java.util.HashMap.transfer(HashMap.java:601)  
    19.     at java.util.HashMap.resize(HashMap.java:581)  
    20.     at java.util.HashMap.addEntry(HashMap.java:879)  
    21.     at java.util.HashMap.put(HashMap.java:505)  
    22.     <span style="color: #ff0000;"><strong>at HashMapDeadLock.call(HashMapDeadLock.java:30)  
    23.     at HashMapDeadLock.call(HashMapDeadLock.java:1)</strong></span>  
    24.     at java.util.concurrent.FutureTask.run(FutureTask.java:262)  
    25.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)  
    26.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)  
    27.     at java.lang.Thread.run(Thread.java:745)  
    28.   
    29.    Locked ownable synchronizers:  
    30.     - <0x00000007aaba84c8> (a java.util.concurrent.ThreadPoolExecutor$Worker)  
    31.   
    32. "Service Thread" daemon prio=5 tid=0x00007f83eb839800 nid=0x5303 runnable [0x0000000000000000]  
    33.    java.lang.Thread.State: RUNNABLE  
    34.   
    35.    Locked ownable synchronizers:  
    36.     - None  
    37.   
    38. "C2 CompilerThread1" daemon prio=5 tid=0x00007f83ee002000 nid=0x5103 waiting on condition [0x0000000000000000]  
    39.    java.lang.Thread.State: RUNNABLE  
    40.   
    41.    Locked ownable synchronizers:  
    42.     - None  
    43.   
    44. "C2 CompilerThread0" daemon prio=5 tid=0x00007f83ee000000 nid=0x4f03 waiting on condition [0x0000000000000000]  
    45.    java.lang.Thread.State: RUNNABLE  
    46.   
    47.    Locked ownable synchronizers:  
    48.     - None  
    49.   
    50. "Signal Dispatcher" daemon prio=5 tid=0x00007f83ec04c800 nid=0x4d03 runnable [0x0000000000000000]  
    51.    java.lang.Thread.State: RUNNABLE  
    52.   
    53.    Locked ownable synchronizers:  
    54.     - None  
    55.   
    56. "Finalizer" daemon prio=5 tid=0x00007f83eb836800 nid=0x3903 in Object.wait() [0x000000011bc58000]  
    57.    java.lang.Thread.State: WAITING (on object monitor)  
    58.     at java.lang.Object.wait(Native Method)  
    59.     - waiting on <0x00000007aaa85608> (a java.lang.ref.ReferenceQueue$Lock)  
    60.     at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)  
    61.     - locked <0x00000007aaa85608> (a java.lang.ref.ReferenceQueue$Lock)  
    62.     at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)  
    63.     at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)  
    64.   
    65.    Locked ownable synchronizers:  
    66.     - None  
    67.   
    68. "Reference Handler" daemon prio=5 tid=0x00007f83eb01a800 nid=0x3703 in Object.wait() [0x000000011bb55000]  
    69.    java.lang.Thread.State: WAITING (on object monitor)  
    70.     at java.lang.Object.wait(Native Method)  
    71.     - waiting on <0x00000007aaa85190> (a java.lang.ref.Reference$Lock)  
    72.     at java.lang.Object.wait(Object.java:503)  
    73.     at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)  
    74.     - locked <0x00000007aaa85190> (a java.lang.ref.Reference$Lock)  
    75.   
    76.    Locked ownable synchronizers:  
    77.     - None  
    78.   
    79. "VM Thread" prio=5 tid=0x00007f83ed808800 nid=0x3503 runnable   
    80.   
    81. "GC task thread#0 (ParallelGC)" prio=5 tid=0x00007f83ec80d800 nid=0x2503 runnable   
    82.   
    83. "GC task thread#1 (ParallelGC)" prio=5 tid=0x00007f83ec80e000 nid=0x2703 runnable   
    84.   
    85. "GC task thread#2 (ParallelGC)" prio=5 tid=0x00007f83ec001000 nid=0x2903 runnable   
    86.   
    87. "GC task thread#3 (ParallelGC)" prio=5 tid=0x00007f83ec002000 nid=0x2b03 runnable   
    88.   
    89. "GC task thread#4 (ParallelGC)" prio=5 tid=0x00007f83ec002800 nid=0x2d03 runnable   
    90.   
    91. "GC task thread#5 (ParallelGC)" prio=5 tid=0x00007f83ec003000 nid=0x2f03 runnable   
    92.   
    93. "GC task thread#6 (ParallelGC)" prio=5 tid=0x00007f83ec003800 nid=0x3103 runnable   
    94.   
    95. "GC task thread#7 (ParallelGC)" prio=5 tid=0x00007f83ec004800 nid=0x3303 runnable   
    96.   
    97. "VM Periodic Task Thread" prio=5 tid=0x00007f83ec814800 nid=0x5503 waiting on condition   
    98.   
    99. JNI global references: 134  

     4)从红色高亮部分可看出,代码中的30行出问题了,即往hashmap中写入数据出问题了:

    Java代码  收藏代码
    1. results.put(i, i);  

    很快就明白因为Hashmap不是线程安全的,所以问题就出在这个地方,我们可以使用线程安全的map即

    ConcurrentHashMap后者HashTable来解决该问题:

    Java代码  收藏代码
    1. import java.util.Map;  
    2. import java.util.concurrent.Callable;  
    3. import java.util.concurrent.ConcurrentHashMap;  
    4. import java.util.concurrent.ExecutionException;  
    5. import java.util.concurrent.ExecutorService;  
    6. import java.util.concurrent.Executors;  
    7.   
    8. /** 
    9.  *  
    10.  */  
    11.   
    12. /** 
    13.  * @author Josh Wang(Sheng) 
    14.  * 
    15.  * @email  josh_wang23@hotmail.com 
    16.  */  
    17. public class HashMapDead2LiveLock implements Callable<Integer> {  
    18.       
    19.     private static ExecutorService threadPool = Executors.newFixedThreadPool(10);  
    20.       
    21.     private static Map<Integer, Integer> results = new ConcurrentHashMap<>();  
    22.   
    23.     @Override  
    24.     public Integer call() throws Exception {  
    25.         results.put(1, 1);  
    26.         results.put(2, 2);  
    27.         results.put(3, 3);  
    28.           
    29.         for (int i = 0; i < 1000; i++) {  
    30.             results.put(i, i);  
    31.         }  
    32.           
    33.         Thread.sleep(1000);  
    34.           
    35.         for (int i= 0; i < 1000; i++) {  
    36.             results.remove(i);  
    37.         }  
    38.           
    39.         System.out.println(" ---- " + Thread.currentThread().getName()  + "     " + results.get(0));  
    40.           
    41.         return results.get(1);  
    42.     }  
    43.       
    44.       
    45.     public static void main(String[] args) throws InterruptedException, ExecutionException {  
    46.         try {  
    47.             for (int i = 0; i < 2000; i++) {  
    48.                     HashMapDead2LiveLock hashMapDeadLock  = new HashMapDead2LiveLock();  
    49. //                  Future<Integer> future = threadPool.submit(hashMapDeadLock);  
    50. //                  future.get();  
    51.                     threadPool.submit(hashMapDeadLock);  
    52.                 }  
    53.         } catch (Exception e) {  
    54.             e.printStackTrace();  
    55.         } finally {  
    56.             threadPool.shutdown();  
    57.         }  
    58.       
    59.           
    60.           
    61.           
    62.     }  
    63.   
    64.       
    65. }  

    改成ConcurrentHashMap后,重新执行该程序,你会发现很快该程序就执行完了。

  • 相关阅读:
    JavaSE-集合的遍历
    JavaSE-Collection常用方法
    JavaSE-异常
    JavaSE-匿名类_匿名内部类的使用
    JavaSE-内部类
    JavaSE-接口应用举例
    java线程的使用(Runnable)
    list根据所存对象属性排序
    Unable to locate appropriate constructor on class异常
    redis在java项目中的使用
  • 原文地址:https://www.cnblogs.com/sunshisonghit/p/8028484.html
Copyright © 2011-2022 走看看