日志框架,Pick Logback Or Log4j2?

写在前面

前段时间写了一篇文章(文章链接:Logback配置文件这么写,TPS提高10倍),反响还不错,有很多网友也发表了自己的意见:

意见1

意见2

意见三

总结一下就是:

  • logback性能测试同步和异步TPS相差不大
  • 都9102年了还在用logback

看到网友的意见后又继续去做了一波测试和调研

服务器硬件

  • CPU 六核
  • 内存 8G

测试工具

  • JMeter
  • JProfile

logback日志框架同步和异步测试

之前的测试结果存在以下几点问题:

  • 测试样本数过少(即线程数和循环执行次数过少,之前线程数为100,循环1次,样本总数为100)
  • 测试次数过少,只进行了一次测试,结果存在偶然性
  • 两次测试结果存在污染,样本数量不一样

针对以上问题,重新测试中将线程数修改为200,每次测试中循环100次,样本总数为2w,和原来测试的样本数相比扩大200倍,并且重复测试5次。
新的测试结果如下:


logback同步和异步测试性能报告

新的测试结果表明,使用logback日志框架同步和异步输出日志方式的TPS相差不大。把数据制作成柱形图更直观


logback同步和异步测试结果

但是总觉得异步去写日志了,访问api的线程将更快响应客户端,TPS就应该有明显的变化才对。想不通又去网上查阅了一些资料,有反应说通过APM进行性能监控,同步和异步的TPS将会有较大的差别,TPS一定是会有明显变化的(呐喊),于是用APM去监控JMeter发送的请求(JMeter参数设置为线程数100Ramp-up Period0,循环100次):
APM测试结果如下:

APM-异步输出日志

APM监控下,在执行的五分钟内异步输出日志TPS平均为378rpm

APM-同步输出日志

APM监控下,在执行的五分钟内同步输出日志TPS平均为333rpm
发现TPS同步和异步相比还是不明显

又一次证明失败
虽然想不明白但后来和网友探讨了下,醍醐灌顶


我好菜啊

TPS变化不明显的原因如下:
TPS为每秒处理事务数,每个事务包括了如下3个过程:

  • 用户请求服务器
  • 服务器自己的内部处理
  • 服务器返回给用户

服务器自己的内部请求包括访问数据库、处理逻辑和打印日志,同步和异步中唯一不同的就是打印日志的方式。而从测试结果来看,打印日志耗时只占API访问请求的5.3%,所以缩短打印日志耗时不能很明显的提高TPS,因为打印时间和网络请求、业务处理消耗时间可以忽略不计
但是测试结果表明,虽然使用异步输出方式不能明显提高TPS,但是能够减少打印日志的耗时。所以使用logback日志框架还是推荐使用异步输出方式

推荐使用log4j2而不是logback

log4j2是log4j 1.x 的升级版,参考了logback的一些优秀的设计,并且修复了一些问题,带来了一些重大的提升,在异步方面的性能得到了巨大提升,其除了提供Async Append异步实现外还提供了Async Log异步实现,其中Async Append异步实现方式和logback的异步实现差不多,而Async Log基于LMAX Disruptor库,实现了一个高性能的异步记录器。本次测试中log4j2异步实现是基于Async Log。
JMeter测试参数和之前的logback测试一样,线程数200,循环次数100,重复五轮。并且logj2日志配置文件基本和logback异步配置相同,满足:

  • 控制台打印日志
  • 分类输出日志
  • 按天滚动
  • 同样的日志输出格式

测试结果如下:


logback和log4j2异步测试性能报告

将TPS制作为柱形图


logback和log4j2异步测试结果

** TPS提升了6倍!!!**,并且打印日志的耗时都快到统计不出来了
官方提供的测试报告中,log4j2和logback相比性能提升更明显。附官方测试报告:Asynchronous Loggers for Low-Latency Logging

结论

  • 如果使用logback框架,推荐使用异步输出日志方式
  • 选择日志框架,推荐使用log4j2




    最后附:测试代码
最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 215,076评论 6 497
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 91,658评论 3 389
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 160,732评论 0 350
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 57,493评论 1 288
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 66,591评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,598评论 1 293
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,601评论 3 415
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,348评论 0 270
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,797评论 1 307
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,114评论 2 330
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,278评论 1 344
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,953评论 5 339
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,585评论 3 322
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,202评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,442评论 1 268
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 47,180评论 2 367
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,139评论 2 352

推荐阅读更多精彩内容