性能分析5～top命令、jps命令、jstack命令：分析多线程下HashMap卡死原因分析

多线程下，HashMap使用很容易出bug，直接被卡死，原因分析我们先看一段代码：

import java.util.HashMap;
import java.util.Map;

/**
 * 多线程下HashMap卡死原因分析
 */
public class Test4_HashMap_bug {
    
    static Map<String, String> map = new HashMap<String, String>();
    
    public static class AddThread implements Runnable {
        
        int start = 0;
        
        public AddThread(int start){
            this.start = start;
        }

        @Override
        public void run() {
            for(int i=start;i<10000;i+=2){
                map.put(Integer.toString(i), Integer.toBinaryString(i));
            }
        }
    }
    
    public static void main(String[] args) throws InterruptedException{
        Thread t1 = new Thread(new AddThread(0));
        Thread t2 = new Thread(new AddThread(1));
        t1.start();
        t2.start();
        t1.join();
        t2.join();
        System.out.println(map.size());
    }
}

我们期待的结果是输出20000，或者因为线程不安全输出一个比20000小的数字也行，但实际情况是运行一直无法结束，直接被卡死了，而且cpu的使用率在不断的飙升，我们一步步分析原因：

1、top命令查看cpu的使用情况

PID    COMMAND      %CPU  TIME     #TH   #WQ  #PORT MEM    PURG   CMPRS  PGRP  PPID  STATE    BOOSTS           %CPU_ME
10889  top          1.9   00:00.83 1/1   0    20    2968K  0B     0B     10889 10869 running  *0[1]            0.00000
10886  java         197.8 00:57.72 22/2  1    82    12M    0B     0B     8892  8892  running  *0[1]            0.00000
10878  mdworker     0.0   00:00.07 4     1    48    10M    0B     0B     10878 1     sleeping *0[1]            0.00000
10876  ocspd        0.0   00:00.02 2     1    32    1968K  0B     0B     10876 1     sleeping *0[1]            0.00000
10869  bash         0.0   00:00.04 1     0    16    916K   0B     0B     10869 10868 sleeping *0[1]            0.00000
10868  login        0.0   00:00.02 2     1    28    1180K  0B     0B     10868 259   sleeping *0[9]            0.00000
10745  quicklookd   0.0   00:00.09 4     1    86    4572K  32K    0B     10745 1     sleeping  0[0]            0.00000

我们发现pid为10886的进程cpu使用率很高

2、jps查询有问题的进程id

zhengchao1991deMacBook-Pro:~ zhengchao1991$ top
zhengchao1991deMacBook-Pro:~ zhengchao1991$ jps
8892 
10895 Jps
10886 Test4_HashMap_bug

此命令更容易定位java进程id

3、jstack查询有问题进程的内部线程运行情况

zhengchao1991deMacBook-Pro:~ zhengchao1991$ jstack 10886
2017-09-13 14:04:12
Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.79-b02 mixed mode):

"Attach Listener" daemon prio=5 tid=0x00007fbb8486e800 nid=0x1407 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Thread-1" prio=5 tid=0x00007fbb84865800 nid=0x5503 runnable [0x000070000877c000]
   java.lang.Thread.State: RUNNABLE
    at java.util.HashMap.put(HashMap.java:494)
    at Test4_HashMap_bug$AddThread.run(Test4_HashMap_bug.java:21)
    at java.lang.Thread.run(Thread.java:745)

"Thread-0" prio=5 tid=0x00007fbb84865000 nid=0x5303 runnable [0x0000700008679000]
   java.lang.Thread.State: RUNNABLE
    at java.util.HashMap.put(HashMap.java:494)
    at Test4_HashMap_bug$AddThread.run(Test4_HashMap_bug.java:21)
    at java.lang.Thread.run(Thread.java:745)

"Service Thread" daemon prio=5 tid=0x00007fbb8701b000 nid=0x4f03 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=5 tid=0x00007fbb8701a000 nid=0x4d03 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=5 tid=0x00007fbb87018800 nid=0x4b03 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=5 tid=0x00007fbb87009800 nid=0x4903 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=5 tid=0x00007fbb87003800 nid=0x3903 in Object.wait() [0x0000700008067000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000007aaa84858> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000007aaa84858> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" daemon prio=5 tid=0x00007fbb87003000 nid=0x3703 in Object.wait() [0x0000700007f64000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000007aaa84470> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:503)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
    - locked <0x00000007aaa84470> (a java.lang.ref.Reference$Lock)

"main" prio=5 tid=0x00007fbb85805800 nid=0x1c03 in Object.wait() [0x0000700007546000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000007aaadd9a0> (a java.lang.Thread)
    at java.lang.Thread.join(Thread.java:1281)
    - locked <0x00000007aaadd9a0> (a java.lang.Thread)
    at java.lang.Thread.join(Thread.java:1355)
    at Test4_HashMap_bug.main(Test4_HashMap_bug.java:31)

我们看到main方法一直在等待线程的执行完成，join方法，说明我们的线程一直没有执行完成，而且造成了cpu的使用率飙升，之前的文章中，我们也说过导致cpu飙升的原因之一就是代码中有死循环这个因素。

4、分析hashmap的put方法的源码

public V put(K key, V value) {
    if (table == EMPTY_TABLE) {
        inflateTable(threshold);
    }
    if (key == null)
        return putForNullKey(value);
    int hash = hash(key);
    int i = indexFor(hash, table.length);
    for (Entry<K,V> e = table[i]; e != null; e = e.next) {
        Object k;
        if (e.hash == hash && ((k = e.key) == key || key.equals(k))) {
            V oldValue = e.value;
            e.value = value;
            e.recordAccess(this);
            return oldValue;
        }
    }

    modCount++;
    addEntry(hash, key, value, i);
    return null;
}

 for (Entry<K,V> e = table[i]; e != null; e = e.next) {

5、原因分析

根据这段代码可以看到，当前这两个线程正在遍历HashMap的内部数据；
当前所处循环乍看之下是一个迭代遍历，就如同遍历一个链表一样；
但在此时此刻，由于多线程的冲突，这个链表的结构已经遭到了破坏，链表成环了，

上述的迭代就等同于一个死循环，

由此造成main方法一直无法执行完成，也造成了cpu的飙升；

此问题已经在jdk8中修复，如果你用的不是jdk8，可以使用ConcurrentHashMap来代替HashMap(当然它也不是线程安全的)。