isInfoEnabled究竟多有用?
前段时间,公司里组织了一次代码检查,其中有一条检查项让我有些费解:
理由是大量的不输出的日志对性能会有影响(日志中存在字符串拼接)。如果说只是DEBUG的加上,我也就认了,可是在系统中写成INFO的日志如果不输出,那还写它干嘛,我就是想看到关键路径的日志。而且在大多数日志上加上这么一个判断真的很难看。。。
所谓上有政策,下有对策,于是有人开始写一些包装了判断的辅助类,当中用这样的代码(截取):
![](http://digitalsonic.iteye.com/images/icon_star.png)
- public class LogUtil {
- public static void info(Logger logger, String message) {
- if (logger.isInfoEnabled()) {
- logger.info(message);
- }
- }
- public static void debug(Logger logger, String message) {
- if (logger.isDebugEnabled()) {
- logger.debug(message);
- }
- }
- public static void debug(Logger logger, String message, Throwable throwable) {
- if (logger.isDebugEnabled()) {
- logger.debug(message, throwable);
- }
- }
- }
但这样的代码真的就能解决问题了吗?答案是“不能”!字符串拼接还存在。
那让我们分两个部分来看一下这个问题:
- 日志中的字符串拼接真的对性能影响很大吗
- 加不加isInfoEnabled的性能差距究竟有多少
关于第一个问题,String的拼接是不修改原来的字符串的,而是创建一个新的String对象,道理上是这么说的,我们也该这么理解。但Java编译器并不傻,实际情况是怎么样的呢,它会做些优化。请看如下代码:
![](http://digitalsonic.iteye.com/images/icon_star.png)
- public class StringAddDemo {
- public static void main(String[] args) {
- String a = "abc";
- String b = a + "def";
- System.out.println(b + "ghi");
- }
- }
在编译后,通过javap -c StringAddDemo看看结果:
public class StringAddDemo extends java.lang.Object{
public StringAddDemo();
Code:
0: aload_0
1: invokespecial #1; //Method java/lang/Object."<init>":()V
4: return
public static void main(java.lang.String[]);
Code:
0: ldc #2; //String abc
2: astore_1
3: new #3; //class java/lang/StringBuilder
6: dup
7: invokespecial #4; //Method java/lang/StringBuilder."<init>":()V
10: aload_1
11: invokevirtual #5; //Method java/lang/StringBuilder.append:(Ljava/lang/
String;)Ljava/lang/StringBuilder;
14: ldc #6; //String def
16: invokevirtual #5; //Method java/lang/StringBuilder.append:(Ljava/lang/
String;)Ljava/lang/StringBuilder;
19: invokevirtual #7; //Method java/lang/StringBuilder.toString:()Ljava/la
ng/String;
22: astore_2
23: getstatic #8; //Field java/lang/System.out:Ljava/io/PrintStream;
26: new #3; //class java/lang/StringBuilder
29: dup
30: invokespecial #4; //Method java/lang/StringBuilder."<init>":()V
33: aload_2
34: invokevirtual #5; //Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
37: ldc #9; //String ghi
39: invokevirtual #5; //Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
42: invokevirtual #7; //Method java/lang/StringBuilder.toString:()Ljava/lang/String;
45: invokevirtual #10; //Method java/io/PrintStream.println:(Ljava/lang/String;)V
48: return
}
实际这里的拼接用的是StringBuilder.append。情况没想的这么糟糕,而且1000次字符串拼接的开销都比不上一次远程调用的开销大,与其想着从这里挤性能,还不如去优化远程调用和数据库访问。
第二点,同样用实验来做说明,这里对比了使用辅助类,使用isInfoEnabled判断和不使用判断的情况,日志级别为INFO,另外再加了使用辅助类,使用isDebugEnabled判断和不使用判断的情况,都是循环输出20万次,每次的拼接在最后都加了些运算:
![](http://digitalsonic.iteye.com/images/icon_star.png)
- public class LogDemo {
- private static final Logger logger = LoggerFactory.getLogger(LogDemo.class);
- public static void main(String[] args) {
- Profiler.start();
- Profiler.enter("Ignore");
- for (int i = 0; i < 200000; i++) {
- LogUtil.info(logger, "test" + "test" + i + i*2);
- }
- Profiler.release();
- Profiler.enter("InfoUtil");
- for (int i = 0; i < 200000; i++) {
- LogUtil.info(logger, "test1" + "test2" + i + i*2);
- }
- Profiler.release();
- Profiler.enter("isInfoEnabled");
- for (int i = 0; i < 200000; i++) {
- if (logger.isInfoEnabled()) {
- logger.info("test3" + "test4" + i + i*2);
- }
- }
- Profiler.release();
- Profiler.enter("info");
- for (int i = 0; i < 200000; i++) {
- logger.info("test5" + "test6" + i + i*2);
- }
- Profiler.release();
- Profiler.enter("DebugUtil");
- for (int i = 0; i < 200000; i++) {
- LogUtil.debug(logger, "test7" + "test8" + i + i*2);
- }
- Profiler.release();
- Profiler.enter("isDebugEnabled");
- for (int i = 0; i < 200000; i++) {
- if (logger.isDebugEnabled()) {
- logger.debug("test9" + "test0" + i + i*2);
- }
- }
- Profiler.release();
- Profiler.enter("debug");
- for (int i = 0; i < 200000; i++) {
- logger.debug("tes1" + "tes2" + i + i*2);
- }
- Profiler.release();
- Profiler.release();
- System.out.println(Profiler.dump());
- }
- }
( 说明:这里的Profiler类是个工具类,作用是记录调用的时间;代码有截取;第一个循环主要是预热一下,不在统计范围内)
经过了几次测试,结果如下:
+---29,937 [14,187ms, 24%, 24%] - isInfoEnabled
+---44,124 [13,938ms, 24%, 24%] - info
+---58,062 [31ms, 0%, 0%] - DebugUtil
+---58,093 [16ms, 0%, 0%] - isDebugEnabled
`---58,109 [46ms, 0%, 0%] - debug
+---14,968 [14,656ms, 25%, 25%] - InfoUtil
+---29,624 [14,141ms, 24%, 24%] - isInfoEnabled
+---43,765 [14,265ms, 25%, 25%] - info
+---58,030 [47ms, 0%, 0%] - DebugUtil
+---58,077 [0ms] - isDebugEnabled
`---58,077 [47ms, 0%, 0%] - debug
+---14,999 [14,922ms, 26%, 26%] - InfoUtil
+---29,921 [14,093ms, 24%, 24%] - isInfoEnabled
+---44,014 [14,219ms, 24%, 24%] - info
+---58,233 [47ms, 0%, 0%] - DebugUtil
+---58,280 [0ms] - isDebugEnabled
`---58,280 [47ms, 0%, 0%] - debug
+---14,656 [14,812ms, 26%, 26%] - InfoUtil
+---29,468 [14,344ms, 25%, 25%] - isInfoEnabled
+---43,812 [13,890ms, 24%, 24%] - info
+---57,702 [31ms, 0%, 0%] - DebugUtil
+---57,733 [16ms, 0%, 0%] - isDebugEnabled
`---57,749 [47ms, 0%, 0%] - debug
+---16,219 [16,719ms, 25%, 25%] - InfoUtil
+---32,938 [17,703ms, 27%, 27%] - isInfoEnabled
+---50,641 [15,157ms, 23%, 23%] - info
+---65,798 [47ms, 0%, 0%] - DebugUtil
+---65,845 [0ms] - isDebugEnabled
`---65,845 [47ms, 0%, 0%] - debug
(数据说明:第一列为开始计时的时间点,[]内为时间及统计,15,171ms为该阶段的具体耗时,后面的百分比是该阶段耗时在这个统计内所占的百分比)
对上述数据分析后,可以得到这样的结论:
- 日志输出前的判断确实有效,但效果甚微
- 在日志级别较低,不会输出的情况下,日志的耗时基本可以忽略 ,20万次的调用耗时在50ms内
- 在日志级别满足输出要求时,3种方法差别不大
针对第3条再做些补充说明,日志输出大的开销应该在IO上,计算应该不会很多,也不该很多,如果存在大量的运算请自己考虑下是不是有问题;既然是确认要输出的日志,那增加判断其实是种浪费,虽然这种判断的开销可以忽略。
综上所述,个人建议在日常系统中无需对日志增加isInfoEnabled判断,想通过这种处理来优化效果的作用不会很明显,还是把精力从日志移到数据库和远程调用上效果更好些。 (特殊情况下,如果在日志中有复杂的操作,可以酌情考虑,但个人不倾向于复杂的日志)
from: http://digitalsonic.iteye.com/blog/700891
isInfoEnabled究竟多有用?相关推荐
- windows下看端口占用
谁在占用本地端口: 上面介绍的netstat -a命令只能查询出当前哪个端口被使用,无法找到究竟是什么程序在使用相应的端口.这样就为我们找出***带来的麻烦,如果发现某个可疑端口被占用的话,究竟是有 ...
- 【深度学习神经网络】--BatchNorm详解
A) 简单了解BN层 (In 30 seconds) Batch-Normalization (BN)是一种让神经网络训练更快.更稳定的方法(faster and more stable).它计算每个 ...
- 那些英语不好的人现在在职场都混得如何?
很多人心中一直埋着一个疑问,我为什么要学英语?如果我进的不是外企,我根本用不到英语,那既然是这样,英语好和英语不好又有什么区别呢? 或者问得再功利性更明显一些,那些英语不好的人到底在职场混得怎么样了? ...
- 关于AI,你最该了解但从没想过的四个问题
文章来源:雷锋网 ID:leiphone-sz 人工智能在当今社会被讨论的如此火热,但是仔细一想,你可能甚至并不知道它的基本运行逻辑. 人工智能和机器学习是一回事吗?人工智能是不是能解决所有的问题?如 ...
- 师从施一公,从造纸工人到清华教授,CNS12篇,柴继杰再发Science
柴继杰,1966年生于辽宁,现任清华大学生命科学学院教授,博导,国家杰出青年基金获得者,全国优秀科技工作者,谈家桢生命科学创新奖获得者,已发表80多篇SCI,13篇CNS,他引12000+次. 主要科 ...
- java位运算究竟有用么?
背景:java位运算除了课本上老师讲过,有时候面试的时候为了凸显高大尚,也会问些皮毛,难道真是一无是处么?本文主要从两方面进行叙述,什么是位运算,以及它的使用场景. 1 位运算简介 说明: & ...
- 数据科学究竟是什么?
数据科学是一门将数据变得有用的学科.它包含三个重要概念: 统计 机器学习 数据挖掘/分析 数据科学的定义 如果你回顾一下数据科学这个术语的[早期历史](),会发现有两个主题密切相连: 大数据意味着计算 ...
- Node.js 究竟是什么?
2019独角兽企业重金招聘Python工程师标准>>> 简介 如果您听说过 Node,或者阅读过一些文章,宣称 Node 是多么多么的棒,那么您可能会想:"Node 究竟是 ...
- 某快手程序员爆料:给小厂随便投投简历,面试表现很差也能过,大厂背书确实有用!...
"背书"有保证.担保的意思,"大厂背书"意即有大厂工作背景做担保,在大厂工作过的人,会给人一种技术好.能力强的感觉,人们往往觉得在大厂待过的人不会太差. 那么在 ...
最新文章
- sqlserver2008未将对象引用设置到对象的实例_面试官:ThreadLocal 的内存泄漏是弱引用导致的,你确定?...
- MySQL各种类型实验
- mysql列别名引用_引用聚合列的MySQL别名
- JAVA知识基础(四):深入理解static关键字
- 给网站加上“新年快乐”灯笼源码
- 计算机 编程 教程 pdf,[计算机软件及应用]PLC编程基础教程.pdf
- java linux 写文件_Java读写文件
- KANO 模型——卡诺模型
- windows系统VS code coderunner 运行shell脚本
- Vuex模块化用法 跨模块调用方法
- 微信html代码怎么换行,微信小程序文本如何换行
- 成功路上并不拥挤 坚持就是胜利
- Excel 中连续生成开始日期和结束日期之间的日期
- NOR flash 坏块处理方法
- google输入法PK搜狗输入法
- ZLG 发布开源 GUI 引擎 AWTK
- 正版方舟建服务器,方块方舟怎么自建服务器 自建服务器方法详解
- 有些事情现在不做,就一辈子也不会做了
- 原型设计大师:Axure RP网站与APP设计从入门到精通(全彩) 中文pdf扫描版
- Elasticsearch搜素引擎入门
热门文章
- sql server数据库导入导出bcp方法
- npm install 时--save-dev和--save的区别
- Android targetSdkVersion详解
- 谷歌提出新型卷积网络EfficientNet: 推理速度升5.1倍参数减少88%,需要我们的验证
- 中兴执行副总裁熊辉回母校谈目标:相信总有路可走
- 谷歌语音转录背后的神经网络
- Android常见XML属性解析
- 简单计算机病毒黑屏,教大家一个黑屏小程序
- groovy定义变量获取当前时间_IDEA不愧为神器,结合Groovy脚本,简直无敌!
- python 链表的基础概念和基础用法