运行大约一天或更长时间后，Java ConcurrentHashMap putIfAbsent 变慢

Question

我在 tomcat 下部署了一个 java web 应用程序，突然 API 的响应时间变慢，如快照所示(抱歉，由于缺乏声誉，我无法发布图像。)。重启tomcat后即可恢复正常。

唯一引起我注意的可疑代码是 ConcurrentHashMap 的 putIfAbsent 的用法，所以我编写了一个测试 JSP 页面如下:

ConcurrentHashMap<Integer, Integer> testMap2 = new ConcurrentHashMap<Integer, Integer>();
long putStart2 = System.currentTimeMillis();
for (int i = 0; i < size; i++) {
    testMap2.put(i, data[i]);
}
out.println("concurrent put -> " + (System.currentTimeMillis() - putStart2));
out.println("</br>");

ConcurrentHashMap<Integer, Integer> testMap = new ConcurrentHashMap<Integer, Integer>();
long putStart = System.currentTimeMillis();
for (int i = 0; i < size; i++) {
    testMap.putIfAbsent(i, data[i]);
}
out.println("concurrent putIfAbsent -> " + (System.currentTimeMillis() - putStart));
out.println("</br>");

得到的结果是:

concurrent put -> 36 
concurrent putIfAbsent -> 157

JDK版本是1.7.0_45，查看了ConcurrentHashMap的源码，putIfAbsent应该比put快，至少和put一样。

我认为差异可能是JIT造成的，所以我在日志编译中添加了JVM选项:

ConcurrentHashMap.putIfAbsent 的日志

<task_queued compile_id='211' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='256' iicount='256' level='3' stamp='0.604' comment='tiered' hot_count='256'/>
<nmethod compile_id='211' compiler='C1' level='3' entry='0x00007feaf12d1480' size='2208' address='0x00007feaf12d12d0' relocation_offset='288' insts_offset='432' stub_offset='1552' scopes_data_offset='1792' scopes_pcs_offset='2008' dependencies_offset='2184' nul_chk_table_offset='2192' oops_offset='1768' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='262' iicount='262' stamp='0.606'/>
<task_queued compile_id='2449' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='3458' iicount='3458' level='3' stamp='8.227' comment='tiered' hot_count='3458'/>
<nmethod compile_id='2449' compiler='C1' level='3' entry='0x00007feaf19cfe00' size='2200' address='0x00007feaf19cfc50' relocation_offset='288' insts_offset='432' stub_offset='1552' scopes_data_offset='1784' scopes_pcs_offset='2000' dependencies_offset='2176' nul_chk_table_offset='2184' oops_offset='1768' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='3458' iicount='3458' stamp='8.241'/>
<task_queued compile_id='3842' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='5378' iicount='5378' stamp='15.601' comment='tiered' hot_count='5378'/>
<nmethod compile_id='3842' compiler='C2' level='4' entry='0x00007feaf1db8400' size='13248' address='0x00007feaf1db81d0' relocation_offset='288' insts_offset='560' stub_offset='7760' scopes_data_offset='8072' scopes_pcs_offset='12136' dependencies_offset='12920' handler_table_offset='12992' nul_chk_table_offset='13232' oops_offset='7816' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='38053' iicount='38053' stamp='15.650'/>
<jvms bci='75' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='38063' iicount='38063'/>
<task_queued compile_id='5282' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='38146' iicount='38146' decompiles='1' level='3' stamp='23.188' comment='tiered' hot_count='38146'/>
<nmethod compile_id='5282' compiler='C1' level='3' entry='0x00007feaf2032880' size='2200' address='0x00007feaf20326d0' relocation_offset='288' insts_offset='432' stub_offset='1552' scopes_data_offset='1784' scopes_pcs_offset='2000' dependencies_offset='2176' nul_chk_table_offset='2184' oops_offset='1768' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='38173' iicount='38173' decompiles='1' stamp='23.200'/>
<task_queued compile_id='5448' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='46339' iicount='46339' decompiles='1' stamp='24.862' comment='tiered' hot_count='46338'/>
<nmethod compile_id='5448' compiler='C2' level='4' entry='0x00007feaf2041a00' size='4232' address='0x00007feaf2041850' relocation_offset='288' insts_offset='432' stub_offset='2416' scopes_data_offset='2568' scopes_pcs_offset='3736' dependencies_offset='4088' handler_table_offset='4112' oops_offset='2456' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='46350' iicount='46350' decompiles='1' stamp='24.878'/>
<jvms bci='65' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='46350' iicount='46350' decompiles='1'/>
<jvms bci='65' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='46350' iicount='46350' decompiles='1'/>
<jvms bci='65' method='java/util/concurrent/ConcurrentHashMap putIfAbsent (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='46350' iicount='46350' decompiles='1'/>

ConcurrentHashMap.put 的日志

<task_queued compile_id='2937' method='java/util/concurrent/ConcurrentHashMap put (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='512' iicount='512' level='3' stamp='9.732' comment='tiered' hot_count='512'/>
<nmethod compile_id='2937' compiler='C1' level='3' entry='0x00007feaf18010c0' size='2200' address='0x00007feaf1800f10' relocation_offset='288' insts_offset='432' stub_offset='1552' scopes_data_offset='1784' scopes_pcs_offset='2000' dependencies_offset='2176' nul_chk_table_offset='2184' oops_offset='1768' method='java/util/concurrent/ConcurrentHashMap put (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='514' iicount='514' stamp='9.735'/>
<task_queued compile_id='5235' method='java/util/concurrent/ConcurrentHashMap put (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='10752' iicount='10752' stamp='22.558' comment='tiered' hot_count='10752'/>
<nmethod compile_id='5235' compiler='C2' level='4' entry='0x00007feaf20a4b40' size='4208' address='0x00007feaf20a4990' relocation_offset='288' insts_offset='432' stub_offset='2384' scopes_data_offset='2536' scopes_pcs_offset='3712' dependencies_offset='4064' handler_table_offset='4088' oops_offset='2424' method='java/util/concurrent/ConcurrentHashMap put (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;' bytes='79' count='10766' iicount='10766' stamp='22.570'/>

我无法完全理解日志，这是否意味着 putIfAbsent 已取消优化？但我补充说

-XX:-UseCodeCacheFlushing -XX:ReservedCodeCacheSize=80m

为什么去优化发生在 putIfAbsent 上？

Answer 1

(我认为 -XX:+PrintCompilation 会更具可读性，虽然不够详细。这个 xml 日志实际上只在 jitwatch 中有用)

我猜 c2 已经取消优化，因为出现了一些新的东西，比如以前没有采用过的新代码路径。下面的 ConcurrentHashMap.putVal() 中的 for 循环很复杂，因此由于路径数量多而暴露在更多的反编译中。 jit 在分支中不太频繁地安装一个不常见的陷阱。所以一会儿代码又回到了解释状态。

Jitwatch 应该在建议选项卡中指出一些原因。 youtube 上有很多来自 Douglas Hawkins 的优秀 JIT 视频，解释了 jit 的内部结构。他们在各种 session 上开会，恕我直言，值得您关注每一分钟。我记不起所有的规则，而且它们也没有全部记录下来。

希望这会有所帮助，即使它不是真正的答案。