性能分析5~top命令、jps命令、jstack命令:分析多线程下HashMap卡死原因分析
程序员文章站
2022-04-07 12:37:42
...
多线程下,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进程id3、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(当然它也不是线程安全的)。
上一篇: Jmeter分布式环境部署_1
下一篇: 基于easyx的c++贪吃蛇