P4Java一生之敌：CopyOnWrite

发表于 分类于 阅读次数： 本文字数： 4.8k 阅读时长 ≈ 9 分钟

What -> Why -> How -> Never

总有一个发现问题的过程让你对一个知识印象深刻，永远不要沉入固有的认知。

一、问题的描述

  • Gmerge服务端上到JNCE后的某天（3.24）Gmerge用户群，merge平台爆炸啦

  • 同时我收到JNCE小助手的消息

  • 查看日志：重启前没有错误日志，就以为是JNCE平台是不是抽风了，把我的服务搞挂了，CALL @铁匠

  • 老铁也不服，各种找日志，几天后，发现是服务探针探活失败，导致的重启，和JNCE没关系。并且给出线索：Gmerge服务重启之前都是有搜索changelist的日志。

1
2
3
4
5
2023-03-27 10:42:40
INFO http-nio-8000-exec-7 com.bytedance.jiangnan.gmerge.service.P4Service 开始查询Changelists  searchDays: 120 issueSize: 20[384668, 384666, 380956, 372546, 372485, 365200, 364317, 362868, 357317, 352326, 351686, 349775, 349762, 348849, 348768, 348202, 345980, 345872, 345535, 308146]
2023-03-27 10:42:39
INFO http-nio-8000-exec-8 com.bytedance.jiangnan.gmerge.service.P4Service 开始查询Changelists  searchDays: 120 issueSize: 20[384668, 384666, 380956, 372546, 372485, 365200, 364317, 362868, 357317, 352326, 351686, 349775, 349762, 348849, 348768, 348202, 345980, 345872, 345535, 308146]

  • 于是我立马尝试在正式环境搜索120天的changelist，不出所料，挂了一个实例，，，我不敢再试了。
  • 总结就是搜索120天的changelist会导致服务探针探活失败，导致重启。

二、问题产生的原因分析与解决办法

复现1：本地复现失败

第一时间我尝试在本地的Gmerge中复现该问题，连接正式环境的P4，奇怪的是，本地搜索120天changelist很丝滑，，，同时尝试执行P4命令，经过我的-e优化，执行p4 command 的p4 changes只需要数秒。看起来不像是P4的问题呀。

复现2：测试环境复现成功

第二时间尝试JNCE测试环境连接正式环境的P4，拉取120天changelist，挂！

在上述分析过程中，我首先注意到的是内存吃满，分析是不是拉这么多changelist内存不够？内存不够呢就可能是疯狂GC啥的，负载也就高了。本地有64G内存所以不容易吃满。

我决定先给服务加上内存上限，发现：12G内存就够了，不会挂，但是速度还是比较慢。

解决方案1：调整内存

根据上面的分析，发现可能是服务给的内存不够，同时参考了下Gbranch：发现内存上限是14G，很多时候也是12核 + 内存吃满。再加上老铁曾经在群里发过这个问题的解决方案。

是不是事情就是这样呢？他就是要吃这么多内存和CPU？我给出临时方案：

  1. 调整内存，最大14G
  2. 调整探针，超时时间10s，连续失败5次重启

在使用了临时方案之后我心里还是有点疑惑：

  1. db.changes 表不大，几百兆，咋要这么多内存？
  2. 在jnce中使用p4 command 跑速度很快且CPU负载极低，咋要这么多CPU？

问题再来：我要搜索1200天

打脸来的很快，我刚说问题已解决，几天后大家又开始喊，Gmerge挂了！

我首先就去查看日志，发现有一个家伙搜索1200天的changelist。好家伙，这个多少内存都不够吧，不加限制也是我的错，第一时间改成最长搜索时间为240天，同时尝试与项目组沟通。

这个限制240天好像能解决问题？？？

BUT 我可以不搜1200天，但是你不能没有这个能力！

解决方案2：尝试使用execStringMapCmd

我回忆起一个月前阅读P4Search的反编译代码，发现由于P4Search有比较复杂的查询较多changelist的方案中，使用了execStreamingMapCommand，区别于我们使用的包装好的server.getChangelist，这个方法可以一条一条的接收P4D的返回并进行处理，虽然我们的代码中没人用过，没有经验，但是可能的解决方案我还是要尝试一下。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
server.execStreamingMapCommand(CmdSpec.CHANGES.toString(), new String[]{"p4 command"},
 null, callback, 0);

//这里是获取到其中一个changelist
public boolean handleResult(Map<String, Object> resultMaps, int key) throws P4JavaException {
    try {
        ChangelistSummary changelistSummary;
        changelistSummary = new ChangelistSummary(resultMaps, true);
        Integer jnpmId = Utils.getIssueIdFromDescription(changelistSummary.getDescription());
        if (issueIds.contains(jnpmId)) {
            this.changes.add(changelistSummary.getId());
        }
        return true;
    } catch (Exception var5) {
        balabala
    }
}

开搞，改造之后，果然完美解决，速度很快，内存CPU占用很低，1200天不在话下：16s。

我自信满满的再次发新版本：这次是真的解决了

BUT WHY：为什么P4JAVA性能这么差

虽然使用execStreamingMapCommand，内存和CPU占用低了，但是并没有解决我前面的问题：为什么正常的server.getChangelist 性能这么差。

我们经常发现自己处于代码无法正常工作的情况，我们甚至不知道从哪里开始调查。

在最终找到解决方案之前，我们不能只盯着代码看吗？当然可以，但是如果没有对项目的深入了解和大量的脑力劳动，这种方法可能行不通。更聪明的方法是使用手头的工具。他们可以为您指明正确的方向。

我想尝试通过内存和CPU占用分析来解决这个问题。

Tutorial: Get started with CPU profiling | IntelliJ IDEA

Tutorial: Find a memory leak | IntelliJ IDEA

现在IDEA中分析CPU和内存很简单，有需要的同学可以自行学习上述教程。

先看这张图，这个是整体的按时间线的占用情况，明显看出CPU内存不太正常。GC有点快，别的不太能看出来。

再将图中内存7633MB这一时刻的数据给拉下来：

内存是谁吃的？哪来的这么多HashMap？

再看看这段时间的CPU内存火焰图：

很明显啊，这里有一个关键点，就是CopyOnWriteArrayList.add。

CopyOnWriteArrayList：这是一个并发集合类，它是线程安全的，并且在读操作时不会加锁，适合多读少写的场景。在写操作时，会创建一份新的副本，并把新的数据写入新的副本中，然后将新的副本替换原始数据，这样保证写操作的线程安全性。

众所周知：CopyOnWriteArrayList 适合多读少写，那么P4JAVA是怎么使用的？

1
2
3
4
5
6
7
8
9
10
11
public class RpcPacketDispatcher {

    public List<Map<String, Object>> dispatch(CommandEnv cmdEnv) {
        List<Map<String, Object>> resultMaps = new CopyOnWriteArrayList<>(new LinkedList<Map<String, Object>>());
        while( rpc 消息来了) {
            resultMaps.add(消息);
        }
        return resultMaps
    }
}

P4JAVA 将CopyOnWriteArrayList 使用在写非常多的场合，这里changelist的数量最大可能上百万，所以最后表现出来的是内存吃满，CPU吃满。

而且，这是写在哪？几乎所有P4JAVA(包含execMapCmdList这个接口)的返回都是通过他来处理。

Top-level dispatcher method.

Dispatch (i.e. process) commands sent from the Perforce server in response to the original user command. This is an arbitrarily complex process, and may or may not involve traffic management, etc., so the implementation here may be less than transparent…

This method only returns when the entire original command was finished; basically, if it returns at all, things went well; otherwise it throws a suitable exception. Extensive work is actually passed off to the various sub dispatchers, which may do their own client / server messaging.

解决方案3：移除

  1. 同样是线程安全的List可以改用 Collections.synchronizedList(List list)
  2. 这里压根就用不到线程安全的List，，，直接用ArrayList就行

测试证明上述两种解决方案内存和CPU动都不动，事实证明是CopyOnWriteArrayList 导致CPU和内存吃满。

四、问题的修复

我受到影响了吗

范围：所有使用P4JAVA命令(包含execMapCmdList)的同学都可能受此影响，包含P4Jenkins插件(底层是P4JAVA)。

程度：如果你获取的P4JAVA返回数量少影响不大，P4JAVA返回数量大影响很大很大。(例如p4 changes120天快10倍以上)

特别注意到的是GBranch内存和CPU特点和上述问题相似，可能深受此问题影响，可能影响拉分支速度。

此外由于较多P4JAVA服务与P4D交互，可能会从整体上影响P4速度。

我怎么处理呢？

需要各位同学评估对服务的影响和对P4D的影响

  1. 如果你受到影响不大，可以暂时不处理?（如果影响P4D还是要处理）
  2. 如果有少量命令较大影响，建议暂时使用execStreamingMapCommand
  3. 如果有大量命令较大影响，可以重新打包P4JAVA

TODO

  1. 与P4官方反映该问题，推进修复

PS 以上分析基于的P4JAVA版本小于等于最新2023.3.30发布的<version>2022.1.2423241</version>