问题描述

最近生产系统，某一台业务服务器偶发出现CPU执行90%以上。更严重者导致系统hang掉，事先未找到代码原因，拉取java core里堆栈信息后，发现

发现有几个线程的状态都是Runnable，程序定位在InventoryReportServiceImpl 服务类上，其他的线程都处于Waiting状态

代码定位：

找到该代码位置之后，发现此处代码的业务逻辑为：根据商品SKU去查询对应的商品主数据信息，由于要查询的商品sku数量比较多，所以开发者采取的思想是：通过多线程来进行这批商品的信息查询

实现方式：

通过创建线程池，然后for循环里每一个sku启动线程去查询对应的商品信息，等所有的线程都执行完毕之后，执行后续业务逻辑；这里采用的多线程的计数器来进行控制

初步分析：

每次通过页面点击查询，然后创建线程池，线程池里最大可执行8个子线程，如果sku待查询的商品数量过大的话，那么此过程执行完成耗时较长，此时如果该服务器业务量大的话，那么该报表在执行过程中，由于待处理的sku查询信息数较多，线程池一直处于runnalbe状态；其次：如果用户发现该报表一直未得到相应，就会进行多次点击查询，最后程序会根据多次请求，多次新建线程池，而线程池的多次创建，势必会增加系统消耗，导致CPU过高

进一步分析：

在java core里我们疏忽了一个点：

这句话HashMap.put,根据这条信息，在网上搜索后，发现别人遇到的现象和我们类似

后来根据资料上的例子，进行了本地机器的模拟，通过启动10个异步线程，其中有5个线程都在HashMap里进行put 10000次操作，其余5个进行get操作，然后启动这10个线程，偶现CPU执行到100%

进行本地分析

我们查到消耗CPU最高的进程PID 6024

然后去控制台导出该pid下所有的tid(子线程)

Jstack -l 6024 > c:/6024.txt

对pid 进行16进制转换

1 2018-07-19 11:48:412 Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.65-b04 mixed mode):3

4 "DestroyJavaVM" prio=6 tid=0x000000001d2fb800 nid=0x3428 waiting on condition [0x0000000000000000]5 java.lang.Thread.State: RUNNABLE6

7 Locked ownable synchronizers:8 - None9

10 "Thread-421" prio=6 tid=0x000000001d177000 nid=0x3828 runnable [0x000000002f4ce000]11 java.lang.Thread.State: RUNNABLE12 at java.util.HashMap.transfer(Unknown Source)13 at java.util.HashMap.resize(Unknown Source)14 at java.util.HashMap.addEntry(Unknown Source)15 at java.util.HashMap.put(Unknown Source)16 at TestLock$2.run(TestLock.java:23)17

18 Locked ownable synchronizers:19 - None20

21 "Thread-246" prio=6 tid=0x000000001cfe5000 nid=0xcd4 runnable [0x0000000021f0e000]22 java.lang.Thread.State: RUNNABLE23 at java.util.HashMap.transfer(Unknown Source)24 at java.util.HashMap.resize(Unknown Source)25 at java.util.HashMap.addEntry(Unknown Source)26 at java.util.HashMap.put(Unknown Source)27 at TestLock$7.run(TestLock.java:73)28

29 Locked ownable synchronizers:30 - None31

32 "Thread-244" prio=6 tid=0x000000001cfe3800 nid=0x4e54 runnable [0x0000000021baf000]33 java.lang.Thread.State: RUNNABLE34 at java.util.HashMap.transfer(Unknown Source)35 at java.util.HashMap.resize(Unknown Source)36 at java.util.HashMap.addEntry(Unknown Source)37 at java.util.HashMap.put(Unknown Source)38 at TestLock$5.run(TestLock.java:53)39

40 Locked ownable synchronizers:41 - None42

43 "Service Thread" daemon prio=6 tid=0x000000000c940800 nid=0x4c98 runnable [0x0000000000000000]44 java.lang.Thread.State: RUNNABLE45

46 Locked ownable synchronizers:47 - None48

49 "C2 CompilerThread1" daemon prio=10 tid=0x000000000af44800 nid=0x3fa8 waiting on condition [0x0000000000000000]50 java.lang.Thread.State: RUNNABLE51

52 Locked ownable synchronizers:53 - None54

55 "C2 CompilerThread0" daemon prio=10 tid=0x000000000af42000 nid=0xfec waiting on condition [0x0000000000000000]56 java.lang.Thread.State: RUNNABLE57

58 Locked ownable synchronizers:59 - None60

61 "Attach Listener" daemon prio=10 tid=0x000000000af40800 nid=0x2aa4 waiting on condition [0x0000000000000000]62 java.lang.Thread.State: RUNNABLE63

64 Locked ownable synchronizers:65 - None66

67 "Signal Dispatcher" daemon prio=10 tid=0x000000000af3f800 nid=0x4118 runnable [0x0000000000000000]68 java.lang.Thread.State: RUNNABLE69

70 Locked ownable synchronizers:71 - None72

73 "Finalizer" daemon prio=8 tid=0x000000000aed4800 nid=0x1ea0 in Object.wait() [0x000000000c3ae000]74 java.lang.Thread.State: WAITING (on object monitor)75 at java.lang.Object.wait(Native Method)76 - waiting on <0x0000000783afd560>(a java.lang.ref.ReferenceQueue$Lock)77 at java.lang.ref.ReferenceQueue.remove(Unknown Source)78 - locked <0x0000000783afd560>(a java.lang.ref.ReferenceQueue$Lock)79 at java.lang.ref.ReferenceQueue.remove(Unknown Source)80 at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source)81

82 Locked ownable synchronizers:83 - None84

85 "Reference Handler" daemon prio=10 tid=0x000000000aecd000 nid=0x2824 in Object.wait() [0x000000000c21f000]86 java.lang.Thread.State: WAITING (on object monitor)87 at java.lang.Object.wait(Native Method)88 - waiting on <0x0000000783afd210>(a java.lang.ref.Reference$Lock)89 at java.lang.Object.wait(Object.java:503)90 at java.lang.ref.Reference$ReferenceHandler.run(Unknown Source)91 - locked <0x0000000783afd210>(a java.lang.ref.Reference$Lock)92

93 Locked ownable synchronizers:94 - None95

96 "VM Thread" prio=10 tid=0x000000000aec7800 nid=0x4a14 runnable97

98 "GC task thread#0 (ParallelGC)" prio=6 tid=0x000000000280d000 nid=0x2684 runnable99

100 "GC task thread#1 (ParallelGC)" prio=6 tid=0x000000000280e800 nid=0x4370 runnable101

102 "GC task thread#2 (ParallelGC)" prio=6 tid=0x0000000002810000 nid=0x2d44 runnable103

104 "GC task thread#3 (ParallelGC)" prio=6 tid=0x0000000002812000 nid=0x4898 runnable105

106 "VM Periodic Task Thread" prio=10 tid=0x000000000af4f800 nid=0x4b88 waiting on condition107

108 JNI global references: 144