Java应用GC阶段sync耗时过长（183ms）问题排查求助

问题背景 #

你的Java应用在2022-10-26 16:08:37左右的G1年轻代回收（Evacuation Pause）中，整体停顿接近190ms，但GC日志显示STW（Stop-The-World）仅30+ms。通过VM日志排查发现，sync阶段耗时高达183ms，这是导致整体停顿过长的核心原因。

关键日志信息 #

GC日志片段（对应问题GC）

2022-10-26T16:08:37.248+0800: 7082.727: [GC pause (G1 Evacuation Pause) (young) ..., 0.0355926 secs]
...
[Times: user=0.32 sys=0.01, real=0.04 secs] 
2022-10-26T16:08:37.283+0800: 7082.763: Total time for which application threads were stopped: 0.0368899 seconds, Stopping threads took: 0.0001211 seconds

VM日志片段（对应问题GC）

7082.543: G1IncCollectionPause             [     290          0              0    ]      [     0     0   183     0    35    ]  0   
         vmop                    [threads: total initially_running wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count

VM日志中，sync字段代表等待所有应用线程到达安全点后，VM操作正式开始前的同步等待时间，此处183ms的耗时直接拉长了整体停顿。

可能的原因 #

1. 线程卡在非安全点执行路径
   安全点是VM可以暂停线程执行的位置（如方法返回、循环边界、异常抛出等）。如果线程长时间执行没有安全点的代码：

   • 比如执行无限循环或超大循环，且循环内没有触发安全点检查；
   • 调用了长时间阻塞的Native方法（JNI），Native方法执行期间不会响应安全点请求。

2. CPU资源严重竞争
   如果GC发生时，服务器CPU被其他进程或线程（包括GC并发线程）占满，应用线程无法及时响应安全点请求，导致sync阶段等待时间延长。

3. G1并发阶段与年轻代回收冲突
   问题GC发生时，应用正处于G1并发标记阶段（GC日志显示GC concurrent-mark-start在7081.759启动），并发标记线程占用CPU资源，可能影响应用线程到达安全点的速度。

解决方案 #

1. 排查并修复非安全点阻塞问题

   • 使用jstack或性能分析工具（如async-profiler）在GC高发时段抓取线程栈，定位长时间运行且无安全点的线程；
   • 优化大循环代码：拆分循环、在循环中插入Thread.yield()（触发安全点检查），或升级到Java 8u191+版本并启用-XX:+UseCountedLoopSafepoints，让循环内自动插入安全点；
   • 缩短Native方法的执行时间，避免在Native方法中长时间阻塞。

2. 优化CPU资源分配

   • 清理服务器上的冗余进程，确保应用有足够CPU资源；
   • 调整GC线程数：通过-XX:ParallelGCThreads设置合适的并行GC线程数（建议值为CPU核心数的50%-75%），避免GC线程抢占过多CPU；
   • 调整并发标记线程数：通过-XX:ConcGCThreads设置并发线程数（建议值为CPU核心数的1/4），减少并发阶段对CPU的占用。

3. 优化G1 GC配置

   • 调整年轻代大小：通过-XX:G1NewSizePercent（默认5%）和-XX:G1MaxNewSizePercent（默认60%）扩大年轻代，减少年轻代GC的触发频率；
   • 放宽目标停顿时间：如果业务允许，适当调大-XX:MaxGCPauseMillis（当前为35ms），避免G1为了追求严格的停顿目标而频繁触发GC，加剧资源竞争；
   • 评估并发阶段时机：如果应用对延迟敏感，可调整G1并发标记的触发时机，避免在业务高峰时段启动并发操作。

内容的提问来源于stack exchange，提问作者胡骏飞