小小的日志,大大的坑 | 京东云技术团队

京东云开发者
• 阅读 195

1. 背景

压测过程中优化线程池以后单机qps存在性能瓶颈,优化过程中发现默认线程池及日志对性能存在严重的影响所以引发了一系列对日志优化的整理

2.哪些场景可能导致性能问题

在任何系统中,日志都是非常重要的组成部分,它是反映系统运行情况的重要依据,也是排查问题时的必要线索。绝大多数人都认可日志的重要性,但是又有哪些场景可能导致性能问题?今天就让我们来聊聊Java日志性能那些事。

2.1 不合理的书写方法

小小的日志,大大的坑 | 京东云技术团队

如上3种写法,我相信大家或多或少都在项目代码中看到过,那么他们之前有区别呢,会对性能造成什么影响? 如果此时关闭 DEBUG 日志级别,差异就出现了

格式1 依然还是要执行字符串拼接,即使它不输出日志,属于浪费。

格式2 的缺点就是参数会提前做JSON序列化也产生性能损耗。

所以推荐格式3,新增日志开关,只有在执行时才会动态的拼接,关闭相应日志级别后,不会有性能损耗。

2.2 不合理的日志

尽量多的日志,能够把用户的请求串起来,更容易断定出问题的代码位置。由于当前分布式系统,且业务庞杂,任何日志的缺失对于程序员定位问题都是极大的障碍。所以要合理的打印日志,设置合理的日志级别

小小的日志,大大的坑 | 京东云技术团队

2.3 日志输出格式

位置信息 官网称作 Location Information,含义是当前这行日志是哪个类的哪个方法哪一行打印的。

可配置的模式有很多,具体见官网
https://logging.apache.org/log4j/2.x/manual/layouts.html#Patterns

这里只说和位置相关的 %C or %class, %F or %file, %l or %location, %L or %line, %M or %method。

官网这几个模式的说明中也都反复强调了会影响性能。同时也给出了具体的性能数据,比常用的同步 logger 慢 1.3 ~ 5 倍。如果在异步 logger 中使用位置信息,将会慢 30 ~ 100 倍。

3. 如何尽量避免日志对性能产生影响

3.1 日志级别动态调整

用好DEBUG级别!项目代码需要打印大量 INFO级别日志,以支持问题定位及测试排查等。但这些大量的 INFO日志对生产环境是无效的,大量的日志会吃掉 CPU 性能,此时需要能动态调整日志级别,既满足可随时查看 INFO日志,又能满足不需要时可动态关闭,不影响服务性能需要。

3.2 不打无用日志

日志内容,能少就少,不在循环中打,大 list 简化,不打无用内容。

明显知道的异常栈不要打印(比如自定义异常捕获后直接打印异常信息即可)

3.3 避免字符串拼接

避免使用字符串连接:在日志记录中,字符串连接是一项较为昂贵的操作,特别是在循环中使用。每次进行字符串连接都会产生一个新的字符串对象,浪费了内存和时间。应优先考虑使用占位符的形式,如使用slf4j库中的"{}",然后传入参数,并避免使用字符串连接。

3.4 新增日志开关

按需新增日志开关减少不必要的性能损耗,例如JSON序列化及字符串拼接等等。(若无相关操作则不需要新增日志开关,反而存在一堆废代码)

3.5 调整日志输出格式

影响性能的位置信息按需选择减少性能损耗

3.6 日志异步打印(谨慎选择)

同步打印日志磁盘 I/O 成为瓶颈,导致大量线程 Block,异步缺可能产生日志丢失。

4. 优化成果

4.1优化前(单机80qps..性能已经不可用 耗时高达1500+ms):

小小的日志,大大的坑 | 京东云技术团队

4.2优化后(单机200qps tp999稳定在575ms):

小小的日志,大大的坑 | 京东云技术团队

作者:京东零售 王军

来源:京东云开发者社区 转载请注明来源

点赞
收藏
评论区
推荐文章
Stella981 Stella981
3年前
Dubbo日志链路追踪TraceId选型
!mark(https://oscimg.oschina.net/oscnet/updd1ad9729fb807ee6dc473bdc283b1a4481.png)一、目的开发排查系统问题用得最多的手段就是查看系统日志,但是在分布式环境下使用日志定位问题还是比较麻烦,需要借助全链路追踪ID把上下文串联起来,本文主要分享基于
Wesley13 Wesley13
3年前
FLV文件格式
1.        FLV文件对齐方式FLV文件以大端对齐方式存放多字节整型。如存放数字无符号16位的数字300(0x012C),那么在FLV文件中存放的顺序是:|0x01|0x2C|。如果是无符号32位数字300(0x0000012C),那么在FLV文件中的存放顺序是:|0x00|0x00|0x00|0x01|0x2C。2.  
Stella981 Stella981
3年前
SpringBoot整合Redis乱码原因及解决方案
问题描述:springboot使用springdataredis存储数据时乱码rediskey/value出现\\xAC\\xED\\x00\\x05t\\x00\\x05问题分析:查看RedisTemplate类!(https://oscimg.oschina.net/oscnet/0a85565fa
Wesley13 Wesley13
3年前
mysql设置时区
mysql设置时区mysql\_query("SETtime\_zone'8:00'")ordie('时区设置失败,请联系管理员!');中国在东8区所以加8方法二:selectcount(user\_id)asdevice,CONVERT\_TZ(FROM\_UNIXTIME(reg\_time),'08:00','0
Easter79 Easter79
3年前
SpringBoot整合Redis乱码原因及解决方案
问题描述:springboot使用springdataredis存储数据时乱码rediskey/value出现\\xAC\\xED\\x00\\x05t\\x00\\x05问题分析:查看RedisTemplate类!(https://oscimg.oschina.net/oscnet/0a85565fa
Stella981 Stella981
3年前
Linux日志安全分析技巧
0x00前言我正在整理一个项目,收集和汇总了一些应急响应案例(不断更新中)。GitHub地址:https://github.com/Bypass007/EmergencyResponseNotes本文主要介绍Linux日志分析的技巧,更多详细信息请访问Github地址,欢迎Star。0x01日志简介Lin
Stella981 Stella981
3年前
Python日志库logging总结
在部署项目时,不可能直接将所有的信息都输出到控制台中,我们可以将这些信息记录到日志文件中,这样不仅方便我们查看程序运行时的情况,也可以在项目出现故障时根据运行时产生的日志快速定位问题出现的位置。1、日志级别Python标准库logging用作记录日志,默认分为六种日志级别(括号为级别对应的数值),NOTSET(0)、DEBUG(10)
Wesley13 Wesley13
3年前
MySQL部分从库上面因为大量的临时表tmp_table造成慢查询
背景描述Time:20190124T00:08:14.70572408:00User@Host:@Id:Schema:sentrymetaLast_errno:0Killed:0Query_time:0.315758Lock_
京东云开发者 京东云开发者
10个月前
分布式日志追踪ID实战 | 京东物流技术团队
本文通过介绍分布式应用下各个场景的全局日志ID透传思路,以及介绍分布式日志追踪ID简单实现原理和实战效果,从而达到通过提高日志查询排查问题的效率。背景开发排查系统问题用得最多的手段就是查看系统日志,相信不少人都值过班当过小秘吧:给下接口和出入参吧,麻烦看看
京东云开发者 京东云开发者
9个月前
关于「日志采样」的一些思考及实践
一、背景:系统日志可用于追踪用户操作轨迹,异常情况下,合理的日志有助于快速排查、定位问题,毫无疑问,打印日志对于系统是很重要的。当业务规模较小时,大家都倾向于享受日志带来的便利,从而忽略日志带来的潜在的负面影响,缺乏对日志的管控。在JD当前用户量、业务规模