知識回顧 上一篇介紹了Spring中三級緩存的singletonObjects、earlySingletonObjects、singletonFactories,Spring在處理迴圈依賴時在實例化後屬性填充前將一個lambda表達式放在了三級緩存中,後續在獲取時進行了判斷,如果不需要進行對象代理, ...
問題現象:CPU 負載過高
我們線上的 jenkins 系統,時不時會發生 CPU 負載過高的現象。
CPU 負載過高後,SRE 同學會收到電話告警。
在我們的監控系統中,可以看到,某些時候,CPU 的負載確實會很高,如下圖:
問題排查
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 = "[email protected]";
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 點左右上線的)。
再次重新編譯,問題得到解決。
結束語
這個問題,前前後後花費了不少時間,也困擾了 DevOps 團隊比較久,經過大家的齊心協力,總算是把問題給解決了。
這篇文章也是對之前排查、解決問題的一個總結。
同時,也提醒大家,在使用第三方 jar 包的時候,一定要註意該 jar 包有沒有性能、安全等問題。如果不確定的話,可以用 JMH 等手段自己測試以下。
我是梅小西,最近在某東南亞電商公司做 DevOps 的相關事情。從本期開始,將陸續分享基於 Jenkins 的 CI/CD 工作流,包括 Jenkins On k8s 等。
如果你對 Java 或者 Jenkins 等感興趣,歡迎與我聯繫,微信:wxweven(備註 DevOps)
本文由博客群發一文多發等運營工具平臺 OpenWrite 發佈