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

【问题标题】：Java ConcurrentHashMap putIfAbsent slow down after running for about a day or moreJava ConcurrentHashMap putIfAbsent 在运行大约一天或更长时间后变慢
【发布时间】：2015-12-26 12:15:49
【问题描述】：

我在 tomcat 下部署了一个 java web 应用程序，突然 API 的响应时间随着快照显示变慢（抱歉，由于缺乏信誉，我无法发布图像。）。重启tomcat后就恢复正常了。

唯一引起我注意的可疑代码是putIfAbsent的使用ConcurrentHashMap，所以我写了一个测试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 会发生去优化？

【问题讨论】：

  • tomcat重启后运行测试JSP怎么样？结果是一样的吗？ size参数是多少？请注意，当争用增加时，CHM 吞吐量可能会降低（例如，更多线程试图集中修改它）。
  • 一天或更长时间后地图中有多少条目？删除和更新了多少？ 24 小时内还有其他内存消耗的可能性吗？ - 当 GC 突然需要更多工作时会发生减速，这并非闻所未闻。
  • 在实际产品使用中，map是一个临时变量，一次是两个线程合并数据，现在只供一个线程使用（是的，遗留代码在单线程情况下使用并发map） ，大小范围为 1000 ~ 10000。在我的测试页面中，大小为 100000，也可以通过单线程访问。不是gc问题，因为gc是正常的，但是putIfAbsent在重启tomcat之前突然变慢后总是很慢。重启tomcat后，测试结果是concurrent put -> 35 concurrent putIfAbsent -> 35
  • 在产品使用或测试页面中没有删除或更新此临时地图的条目，并且都通过单线程访问。重启tomcat后测试正常，put和putIfAbsent的响应时间没有区别，35ms左右。
  • 请注意，System.currentTimeMillis() 并不精确（即，它不一定会返回精确到毫秒精度的正确时间）。它的精确精度是特定于平台的实现细节。在您的基准测试中，.put() 花费了 36 毫秒，.putIfAbsent() 花费了 157 毫秒——这完全在可能的时钟不精确范围内。对 Java 进行基准测试很困难，而对 并发 Java 进行基准测试则更加困难，而且乍一看，这个测试并不可靠。请参阅stackoverflow.com/q/504103/113632 获取一些建议。

标签： java performance jit concurrenthashmap


【解决方案1】：

（我认为 -XX:+PrintCompilation 的可读性会更好，虽然不那么详细。这个 xml 日志真的只在 jitwatch 中有用）

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

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

希望这会有所帮助，尽管这并不是真正的答案。

【讨论】：

    猜你喜欢
    • 1970-01-01
    • 2015-06-27
    • 2017-01-31
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 2012-03-15
    相关资源
    最近更新 更多
    热门标签
    Java Python linux javascript Mysql C# Docker 算法 前端 SpringBoot Redis Vue spring 设计模式 .net core .net kubernetes c++ 数据库 数据结构 大数据 js 机器学习 微服务 Android Go 程序员 面试 JVM ASP.net core 云原生 人工智能 后端 PHP git CSS golang k8s Nginx Django mybatis 深度学习 多线程 React 架构 devops 爬虫 云计算 Spring Boot LeetCode