先介绍下java系统的日志
日志框架:是一种日志接口,不负责具体的日志输出形式(有点类似于JDBC),可以灵活的切换日志输出形式。常见的日志框架有slf4j、jcl,只提供Logger、LoggerFactory等接口
日志系统:是应用实际使用的日志工具,主要有log4j,jul,logback等。一般在程序中应该避免直接使用,可以保证程序具有一定的灵活性。
Logger:日志输出实例,包含Appender和Layout
Appender:日志输出目标,如控制台,文件,数据库等。多个Appender可以被关联到任何Logger上,所以可以到多个输出文件上记录相同的信息。
Layout:定义日志输出格式:时间戳、线程名称、日志级别、日志内容、对应输出该日志的类、对应输出该日志的方法、行号及MDC信息
Level :日志级别,通过配置不同的日志界别来打印不同的日志信息。
log4j定义了8个级别的log(除去OFF和ALL,可以说分为6个级别),优先级从高到低依次为:OFF、FATAL、ERROR、WARN、INFO、DEBUG、TRACE、 ALL。
Log4j建议只使用四个级别,优先级 从高到低分别是 ERROR、WARN、INFO、DEBUG。日志记录器(Logger)的行为是分等级的:
日志记录器(Logger)是日志处理的核心组件。log4j具有5种正常级别(Level)。:
1.static Level DEBUG :
DEBUG Level指出细粒度信息事件对调试应用程序是非常有帮助的。
2.static Level INFO
INFO level表明 消息在粗粒度级别上突出强调应用程序的运行过程。
3.static Level WARN
WARN level表明会出现潜在错误的情形。
4.static Level ERROR
ERROR level指出虽然发生错误事件,但仍然不影响系统的继续运行。
5.static Level FATAL
FATAL level指出每个严重的错误事件将会导致应用程序的退出。
另外,还有两个可用的特别的日志记录级别:
1.static Level ALL
ALL Level是最低等级的,用于打开所有日志记录。
2.static Level OFF
OFF Level是最高等级的,用于关闭所有日志记录。
针对于日志级别的问题分析如下:
一、场景描述:
“xx交易”单交易200并发下稳定执行10分钟,TPS为47,两台门户前置平均cpu占用81%,其中sys利用率达到32%。(日志级别为info)
分析过程
1、抓取并分析javacore文件
阻塞进程共92个。其中85个线程被同一个线程阻塞(即WebContainer:2184),此线程抓取javacore文件的瞬间正在调用org/apache/log4j/spi/LocationInfo方法。线程阻塞现象会降低并发处理性能,因此分析客户登录交易性能差可能与log4j写日志有关。如图所示:
2、验证性测试:降低日志级别测试,即由info级别改为error级别
抓取javacore文件并分析
阻塞线程仅有18个,其中仅有2个线程被同一个线程阻塞(即WebContainer:92)。
3、对比
测试结果对比:相同测试场景分别在info和error级别下,TPS、资源利用率等对比
序号
日志级别
并发数
TPS
两台前置服务器cpu平均利用率
1
Info
200
47
81%(其中sys使用34%)
2
Error
200
108
81%(其中sys使用7.5%)
日志输出量对比:分别在info和error级别下,执行1次客户登录操作,产生的日志量对比
日志文件
Info级别(byte)
Error级别(byte)
portalweb_all.log
28242
396
portalweb_business.log
21567
396
portalweb_db.log
263
0
portalweb_sign.log
0
0
总量
50072
792
结论
日志级别即日志的输出量对系统性能具有一定的影响。
四、建议
建议项目组修改info级别下的日志输出量,以提高系统处理能力。