最近新上线了个系统，我们系统【接手的老系统】配合下压测，造点数据，晚上九点戳一下没问题就下班了。
轻轻一戳，尼玛 cpu瞬间飙升 10x台服务器全部打满。。。什么鬼哦
快看看是谁家接口又又又出问题了，就依赖了一个接口，20ms 就返回了，呃哦
快摔给运维，运维紧张的看了看 有个机房的服务器比另一个机房的慢了几毫秒 。。。没问题啊
抗起大锅，老代码代码撸起来， 话说之前也压过
优化过、缓存也加了，不至于啊，之前几次性能也没问题啊
没办法加日志吧（最终发现，通过耗时难定位），看谁耗时，这锅给谁
每个地方都写log显然是不能接受，虽然心里慌，代码不能脏
定义一个注解吧 ExecuteTime，需要打耗时就加一下，顺带重构了一些代码比如 O（m*n）-> O(m+n)...
@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.METHOD)
public @interface ExecuteTime {
int limit() default 500;
}
@Slf4j
@Aspect
@Component
public class XXXAspect {
@Around("@annotation(executeTime)")
public Object monitorLog(JoinPoint joinPoint, ExecuteTime executeTime){
try {
long start =System.currentTimeMillis();
Object result = ((ProceedingJoinPoint)joinPoint).proceed();
String method = joinPoint.getTarget().getClass().getSimpleName() + "#" + joinPoint.getSignature().getName();
long spend = System.currentTimeMillis()-start ;
if(spend > 1*1000){
log.error("monitor-exe-common {} ,spend 1s time {}" ,method,spend);
}else if(spend > executeTime.limit()){
log.error("monitor-exe-limit {} ,spend limit time {}" ,method,spend);
}
return result;
} catch (Throwable throwable) {
log.error("aspect log time ex {} ",throwable);
}
return null;
}
}
加好了，压一下吧 ，这个方法怎么执行3s 4s 5s。。。
【有妖气】，调用接口的方法这么慢， 拆解了 几下，貌似就它了
public static String getCfgKey(String key){
// 单例吧，static中执行啊
String filePath = "/xxx/xxx/app_config.properties";
Properties properties = new Properties();
try{
FileInputStream file = new FileInputStream(new File(filePath));
properties.load(file);
}catch (IOException e) {
log.(xxx);
}
return properties.getProperty(key);
}
部署， 走一个， 性能提升仅0.5s ，不科学啊，继续找原因
邻座小美，一脸懵逼，我说 ，你多加些时间日志吧。。。看看哪里会慢
我发现一个循环调用 xxx方法， 想着用parallel 执行可能会快点
如果是多个接口 可以CompletableFuture.allOf
但是，cpu本身很高，猜测可能不行，但是，试试没准有机会呢
Set<String> classSet = Collections.synchronizedSet(new HashSet<>()) ;//new CopyOnWriteArraySet<>();
Set<String> historySet = new HashSet<>();
historySet.parallelStream().forEach(item-> {
// todo logic
classSet.add("xxx");
});
一点效果也没有，毕竟cpu本身不够用，并发也提升不了性能。。。
顺便看下jstat -gc pid 5000 ，十分钟压测，fgc 120次？
此处必有妖孽，正在寻找问题。。。
小美说，找到了， 我一脸不信啊，这个代码都是通用的啊 不能有问题，也没法优化
int code = conn.getResponseCode();
if(code != 200){
log.error("xxx");
}else {
br = new BufferedReader(new InputStreamReader(conn.getInputStream(),"UTF-8"));
String s = "";
while((s = br.readLine()) != null){
sb = sb + s;
}
}
mock一下吧 直接返回， 部署压测， 一点效果都没有。。。
分析gc
jstat.png
看fgc那项，66，基本5s一次full gc 啊，，EU也是频繁波动啊，呵呵
大对象 ，原来的代码中有还加了redis缓存呢，多么迷惑啊。因为这次压测数据造的特别， 加上代码写的有质量问题。。。
List<XXX> items = redisTemplate.getXXX(xxID);
为什么有问题呢，此处 对象比较大 包含几千数据， 变量声明用完需要回收，访问频繁就需要频繁生命、销毁。
怎么办，本地缓存啊，guava cache
String keyConfig = "xxx_"+xxxId;
List<XXX> items= CacheUtil.STORE.getIfPresent(keyConfig);
if(items== null){
items = redisTemplate.getXXX(xxID);
}
public class CacheUtil {
public static Cache<String, JSONArray> STORE;
static {
CACHEAPP = CacheBuilder.newBuilder().maximumSize(1000L).expireAfterWrite(5L, TimeUnit.MINUTES).build();
}
}
烧香 ，压测100ms 搞定，full gc 一次
至此问题解决，紧急上线一把，后续还要优化，别影响公司收钱啊
附： jstas gc 结果指标
S0C：第一个幸存区的大小
S1C：第二个幸存区的大小
S0U：第一个幸存区的使用大小
S1U：第二个幸存区的使用大小
EC：伊甸园区的大小
EU：伊甸园区的使用大小
OC：老年代大小
OU：老年代使用大小
MC：方法区大小
MU：方法区使用大小
CCSC:压缩类空间大小
CCSU:压缩类空间使用大小
YGC：年轻代垃圾回收次数
YGCT：年轻代垃圾回收消耗时间
FGC：老年代垃圾回收次数
FGCT：老年代垃圾回收消耗时间
GCT：垃圾回收消耗总时间
网友评论