问题现象：CPU 负载过高
我们线上的 jenkins 系统，时不时会发生 CPU 负载过高的现象。
CPU 负载过高后，SRE 同学会收到电话告警。
在我们的监控系统中，可以看到，某些时候，CPU 的负载确实会很高，如下图：
file
问题排查
Jenkins 系统本身是一个 Java 程序，应对 Java 程序导致的 CPU 使用率过高这一问题，GitHub 上有现成的解决方案：show-busy-java-threads。
下载链接如下：
- GitHub：show-busy-java-threads
- Gitee：show-busiest-java-threads
登录上机器，在 CPU 使用率高时候，执行 show-busy-java-threads 脚本：./show-busy-java-threads。
摘选其中的一些输出如下：
The stack of busy(25.0%) thread(20239/0x4f0f) of java process(248927) of user(jenkins):
"Handling GET /job/jenkins-test-job/api/json from 172.168.1.1 : qtp1641808846-3127" #3127 prio=5 os_prio=0 tid=0x00007f7380014000 nid=0x4f0f runnable [0x00007f722c392000]
java.lang.Thread.State: RUNNABLE
at java.util.Arrays.copyOfRange(Arrays.java:3664)
at java.lang.String.<init>(String.java:207)
at java.lang.String.substring(String.java:1933)
at net.sf.json.util.JSONTokener.matches(JSONTokener.java:110)
at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:912)
at net.sf.json.JSONObject.fromObject(JSONObject.java:156)
at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:348)
at net.sf.json.JSONArray._fromJSONTokener(JSONArray.java:1131)
at net.sf.json.JSONArray.fromObject(JSONArray.java:125)
at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:351)
at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:955)
at net.sf.json.JSONObject.fromObject(JSONObject.java:156)
at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:348)
at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:955)
at net.sf.json.JSONObject.fromObject(JSONObject.java:156)
at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:348)
at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:955)
at net.sf.json.JSONObject.fromObject(JSONObject.java:156)
at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:348)
at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:955)
at net.sf.json.JSONObject._fromString(JSONObject.java:1145)
at net.sf.json.JSONObject.fromObject(JSONObject.java:162)
at net.sf.json.JSONObject.fromObject(JSONObject.java:132)
at sam.Sam.sendRequestReturnJson(Sam.java:517)
at sam.Sam.getPermissionByUser(Sam.java:225)
at sam.Sam.checkUserPermissionLocal(Sam.java:243)
at com.michelin.cio.hudson.plugins.rolestrategy.PermissionCache.getPermissionSam(RoleMap.java:155)
at com.michelin.cio.hudson.plugins.rolestrategy.PermissionCache.getPermission(RoleMap.java:106)
at com.michelin.cio.hudson.plugins.rolestrategy.RoleMap.hasPermission(RoleMap.java:220)
at com.michelin.cio.hudson.plugins.rolestrategy.RoleMap.access$000(RoleMap.java:166)
at com.michelin.cio.hudson.plugins.rolestrategy.RoleMap$AclImpl.hasPermission(RoleMap.java:569)
at hudson.security.SidACL._hasPermission(SidACL.java:70)
从上面的输出可以看到，25.0% 的 CPU 资源在处理 Handling GET /job/jenkins-test-job/api/json from 172.168.1.1 这个请求。
运维同学根据这个 ip ，定位到发起请求的是某同学 A。这个同学在跑一些定时任务，定时拉取 job 的执行结果。
问题是当我直接访问这个接口：/job/jenkins-test-job/api/json 时，返回并不慢，几乎很快就可以返回。问题应该不是这个接口的问题。
我们接着从 ./show-busy-java-threads 输出往下看：看到其中有问题的调用栈：
at net.sf.json.JSONObject.fromObject(JSONObject.java:132)
at sam.Sam.sendRequestReturnJson(Sam.java:517)
at sam.Sam.getPermissionByUser(Sam.java:225)
at sam.Sam.checkUserPermissionLocal(Sam.java:243)
看起来是这个 Sam 校验用户权限导致的 CPU 使用率过高，而接着看上面的代码 net.sf.json.JSONObject.fromObject，这个是在做 json 的反序列化。
通常来说，json 的序列化、反序列化都是比较费 CPU 的，更糟糕的是，这里用到的 json 序列化框架是 net.sf.json，而不是 Java 常用的 jackson 和 gson 等。
直觉告诉我，肯定是这个 net.sf.json 反序列化引起的 CPU 使用率过高问题。
备注：
通过跟之前维护 jenkins 的同学了解到，他们基于 role-strategy 插件，重写了 jenkins 权限验证逻辑，用的就是 Sam 权限。翻看 sam 权限插件的代码，确实有用 net.sf.json 做 json 反序列化。
到这里，定位到大概率是 Sam 权限插件的 net.sf.json 反序列化引起的问题。
问题复现
为了验证这个问题，我们拿到 Sam 权限插件的代码。找到出问题的关键代码：
public void getPermissionByUser(String email) {
JSONObject params = new JSONObject();
params.put("user_email", email);
params.put("subsystem_id", SAM_JENKINS_SUM_SYSTEM_ID);
JSONObject res = sendRequestReturnJson(URL, "GET", params);
if (res.get("success").equals(true)) {
cacheUserPermission(params.getString("user_email"), res.getJSONObject("permission").getJSONObject(email).getJSONObject("SERVICE"));
}
}
public static JSONObject sendRequestReturnJson(String endpoint, String method, JSONObject params) {
if (method.equals("POST")) {
return JSONObject.fromObject(sendPostRequest(endpoint, params));
} else if (method.equals("GET")) {
return JSONObject.fromObject(sendGetRequest(endpoint, params));
}
return new JSONObject();
}
可以看到，这段代码会根据用户邮箱，发送 http 请求调用 Sam 系统，获取用户的权限数据，然后将数据反序列化成 JSONObject，即：
JSONObject.fromObject(sendGetRequest(endpoint, params, token))
在本地，通过复现 A 同学的请求，发现这个请求确实比较慢，而且费 CPU。通过 debug 得知，这个用户返回的 json 数据有 1M 左右，json 反序列化 CPU 打满。
而通过其他用户请求，发现处理很快，返回的 json 数据也比较小。
到这里，确认就是 net.sf.json 框架的反序列化性能问题，引起的 CPU 使用率过高。我们需要替换成其他高性能的 json 序列化框架。
备选有：gson、jackson、fastjson等。fastjson 因为经常出安全漏洞，暂不考虑，我们考虑从 gson、jackson 选择一个。
在选定之前，先对 gson、jackson， 的性能做个基准测试，并与 net.sf.json 做对比。
JMH 基准测试 json 框架性能
Json 框架的性能测试，我们选用 JMH 框架。
JMH 框架是 JDK 官方提供的性能基准测试套件，参考：https://github.com/openjdk/jmh
代码如下：
import com.fasterxml.jackson.databind.JsonNode;
import com.fasterxml.jackson.databind.ObjectMapper;
import com.google.gson.Gson;
import com.google.gson.JsonObject;
import net.sf.json.JSONObject;
import org.apache.commons.io.FileUtils;
import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.annotations.BenchmarkMode;
import org.openjdk.jmh.annotations.Mode;
import org.openjdk.jmh.annotations.OutputTimeUnit;
import org.openjdk.jmh.annotations.Param;
import org.openjdk.jmh.annotations.Scope;
import org.openjdk.jmh.annotations.Setup;
import org.openjdk.jmh.annotations.State;
import org.openjdk.jmh.results.format.ResultFormatType;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;
import org.springframework.util.ResourceUtils;
import java.io.File;
import java.io.IOException;
import java.util.concurrent.TimeUnit;
@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.MILLISECONDS)
@State(Scope.Benchmark)
public class JsonBenchmark {
@Param({"10", "100", "500"})
private int length;
private String json;
private String email = "a@123.com";
private String path = "classpath:sam.json";
@Benchmark
public void testGson() throws IOException {
Gson gson = new Gson();
JsonObject root = gson.fromJson(json, JsonObject.class);
if (root.getAsJsonObject("success").getAsBoolean()) {
JsonObject services = root.get("permission").getAsJsonObject()
.get(email).getAsJsonObject()
.get("SERVICE").getAsJsonObject();
System.out.println(services.size());
}
}
@Benchmark
public void testJackson() throws IOException {
ObjectMapper objectMapper = new ObjectMapper();
JsonNode root = objectMapper.readTree(json);
if (root.get("success").asBoolean()) {
JsonNode services = root.get("permission").get(email).get("SERVICE");
System.out.println(services.size());
}
}
@Benchmark
public void testJsonObject() throws IOException {
JSONObject root = JSONObject.fromObject(json);
if (root.get("success").equals(true)) {
JSONObject services = root.getJSONObject("permission").getJSONObject(email).getJSONObject("SERVICE");
System.out.println(services.size());
}
}
@Setup
public void prepare() throws IOException {
File file = ResourceUtils.getFile(path);
json = FileUtils.readFileToString(file);
}
public static void main(String[] args) throws RunnerException {
Options options = new OptionsBuilder()
.include(JsonBenchmark.class.getSimpleName())
.forks(1)
.warmupIterations(5)
.measurementIterations(2)
// .output("/Users/wxweven/Benchmark.log")
.result("result.json")
.resultFormat(ResultFormatType.JSON)
.build();
new Runner(options).run();
}
}
测试的结果如下：
Benchmark (length) Mode Cnt Score Error Units
JsonBenchmark.testGson 10 avgt 2 7.979 ms/op
JsonBenchmark.testGson 100 avgt 2 8.958 ms/op
JsonBenchmark.testGson 500 avgt 2 9.975 ms/op
JsonBenchmark.testJackson 10 avgt 2 10.393 ms/op
JsonBenchmark.testJackson 100 avgt 2 12.214 ms/op
JsonBenchmark.testJackson 500 avgt 2 10.548 ms/op
JsonBenchmark.testJsonObject 10 avgt 2 1350.788 ms/op
JsonBenchmark.testJsonObject 100 avgt 2 1350.583 ms/op
JsonBenchmark.testJsonObject 500 avgt 2 1381.046 ms/op
可以看到，gson 和 jackson 性能接近，但是 jsonlib 性能就很差，比另外两个慢 100 多倍。
综合考虑性能、api 易用性等，选定 gson 作为替代方案。
替换成 gson
将之前的代码替换成 gson，代码如下：
public void getPermissionByUser(String email) {
JSONObject params = new JSONObject();
params.put("user_email", email);
params.put("subsystem_id", SAM_JENKINS_SUM_SYSTEM_ID);
JsonObject res = sendRequestReturnJsonV2(URL, "GET", params);
if (res.get("success").getAsBoolean()) {
cacheUserPermission(params.getString("user_email"), res.getAsJsonObject("permission").getAsJsonObject(email).getAsJsonObject("SERVICE"));
}
}
public static JsonObject sendRequestReturnJsonV2(String endpoint, String method, JSONObject params) throws IOException {
if (method.equals("POST")) {
return GSON.fromJson(sendPostRequest(endpoint, params, token), JsonObject.class);
} else if (method.equals("GET")) {
return GSON.fromJson(sendGetRequest(endpoint, params, token), JsonObject.class);
}
return new JsonObject();
}
重新编译权限插件后上线，再次查看 CPU 负载监控，发现 CPU 负载确实降下来了（05/13晚上 0 点左右上线的）。
file
再次重新编译，问题得到解决。
结束语
这个问题，前前后后花费了不少时间，也困扰了 DevOps 团队比较久，经过大家的齐心协力，总算是把问题给解决了。
这篇文章也是对之前排查、解决问题的一个总结。
同时，也提醒大家，在使用第三方 jar 包的时候，一定要注意该 jar 包有没有性能、安全等问题。如果不确定的话，可以用 JMH 等手段自己测试一下。
本文由博客群发一文多发等运营工具平台 OpenWrite 发布
网友评论