背景
系统前期设计不太合理,经常被用户吐槽系统慢,而且预计双十一双十二期间系统的访问量会飙升,所以系统的压测和优化势在必行
本次主要挑选首页的接口来分析
应用配置
2核4G,逻辑CPU40
应用启动2G内存
新生代老年代默认1:2
新生代GC收集器为parNew,老年代为CMS
优化前
压测数据
线程数 | 平均耗时 | 总调用次数 | 异常次数 | 平均吞吐量 |
---|---|---|---|---|
120 | 1022 | 19822 | 8 | 107.2/S |
为什么吞吐量会这么低呢?
通过jvisual发现系统的CPU使用只有3%左右,但是内存在1-2秒的时间内就会达到峰值然后触发GC
为什么GC会如此频繁? 初步猜想应该有大对象占用着,GC一直回收不了
通过 jmap -histo pid 命令查看可知字符类型数组在程序运行的时候占用着几百兆的内存, 为什么会这么大呢?
通过 jstack 查看线程的运行状态发现很多线程都WAITING在打印日志这里了.
通过代码分析, 我们的日志打印的太多了, 我们的日志打印模式是ASYNC异步的.
原来由于异步打印日志,打印的大对象就一直无法被回收掉,打印日志又会写盘,所以才会频繁GC而且吞吐量极低
"http-nio-8000-exec-193" #2041 daemon prio=5 os_prio=0 tid=0x00007fe91c031000 nid=0x120f waiting on condition [0x00007fe9304cc000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000ab7334a8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:210)
at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:235)
at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:100)
at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421)
at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
at ch.qos.logback.classic.Logger.debug(Logger.java:482)
复制代码
另外还发现代码中有一些重复的逻辑以及一些没必要的大对象
所以要着手开始优化
优化
- 调整日志级别
- 去掉没必要的逻辑
- 优化没必要的大对象
- 读取redis时使用pipeline
线程数 | 平均耗时 | 总调用次数 | 异常次数 | 平均吞吐量 |
---|---|---|---|---|
300 | 688 | 109832 | 0 | 413.2/S |