Java 进阶:异常影响性能吗?
曾经在给一个业务系统增加限流功能,使用的限流组件在流量超过阈值时,会直接抛异常,异常导致 CPU 占用率飙升。第一次遇到这样的情况,让我们不得不思考,异常怎么会对性能造成这么大的影响?
下面我们写几个测试程序观察一下。
catch 中不做任何事情
public class ExceptionTest {
public static void main(String[] args) {
doExTest();
doExTest();
}
private static void doExTest() {
long start = System.nanoTime();
for (int i=0; i<100000; ++i) {
try {
throw new RuntimeException("" + Math.random());
} catch (Exception e) {
}
}
System.out.println("time: " + (System.nanoTime() - start));
}
}
- 1
- 2
- 3
- 4
- 5
- 6
- 7
- 8
- 9
- 10
- 11
- 12
- 13
- 14
- 15
- 16
- 17
测试结果如下:
time: 365218274
time: 224583244
第一次 doExTest 只是起到预热的作用,我们以第二次 doExTest 的时间为准。10 万次请求,平均每次请求耗时 2245 纳秒,也就是 0.002 毫秒,速度还是很快的。
catch 中输出异常到日志
public class ExceptionTest {
private static final Logger logger = LoggerFactory.getLogger(ExceptionTest.class);
public static void main(String[] args) {
doExTest();
doExTest();
}
private static void doExTest() {
long start = System.nanoTime();
for (int i=0; i<100000; ++i) {
try {
throw new RuntimeException("" + Math.random());
} catch (Exception e) {
logger.error("fuck", e);
}
}
System.out.println("time: " + (System.nanoTime() - start));
}
}
- 1
- 2
- 3
- 4
- 5
- 6
- 7
- 8
- 9
- 10
- 11
- 12
- 13
- 14
- 15
- 16
- 17
- 18
- 19
- 20
测试结果如下:
time: 13454674590
time: 9891780450
10 万次请求,平均每次请求耗时 98917 纳秒,大约 0.1 毫秒,比“不输出异常”的时候,慢了 50 倍。输出日志如此耗费性能,那么 logger.error 这一句做了什么事儿呢?
1. 根据过滤规则,判断是否要输出日志
2. 获取异常堆栈
3. 拼接日志字符串,输出日志到文件
获取异常堆栈主要调用的如下方法,下面我们写程序,不输出日志到文件,测试只读取异常栈的性能:
public class Throwable implements Serializable {
public StackTraceElement[] getStackTrace() {
return getOurStackTrace().clone();
}
private synchronized StackTraceElement[] getOurStackTrace() {
// Initialize stack trace field with information from
// backtrace if this is the first call to this method
if (stackTrace == UNASSIGNED_STACK ||
(stackTrace == null && backtrace != null) /* Out of protocol state */) {
int depth = getStackTraceDepth();
stackTrace = new StackTraceElement[depth];
for (int i=0; i < depth; i++)
stackTrace[i] = getStackTraceElement(i);
} else if (stackTrace == null) {
return UNASSIGNED_STACK;
}
return stackTrace;
}
}
- 1
- 2
- 3
- 4
- 5
- 6
- 7
- 8
- 9
- 10
- 11
- 12
- 13
- 14
- 15
- 16
- 17
- 18
- 19
catch 中获取异常栈
public class ExceptionTest {
public static void main(String[] args) {
doExTest();
doExTest();
}
private static void doExTest() {
long start = System.nanoTime();
for (int i=0; i<100000; ++i) {
try {
throw new RuntimeException("" + Math.random());
} catch (Exception e) {
StackTraceElement[] stackTrace = e.getStackTrace();
}
}
System.out.println("time: " + (System.nanoTime() - start));
}
}
- 1
- 2
- 3
- 4
- 5
- 6
- 7
- 8
- 9
- 10
- 11
- 12
- 13
- 14
- 15
- 16
- 17
- 18
- 19
- 20
测试结果如下:
time: 1559107012
time: 795376775
10 万次请求,平均每次请求耗时 7953 纳秒,大约 0.008 毫秒,比“不输出异常”的时候,慢了 4 倍。这么看获取堆栈耗时并不多,耗时主要在输出日志到文件中。
总结
处理异常的几个步骤里,对性能的耗费从大到小依次为:输出到日志、获取异常堆栈、创建并 catch 异常。