漫话：应用程序被拖慢？罪魁祸首竟然是Log4j！
The following article is from 漫话编程 Author 漫话编程
之前一段时间，为我们发现的一个SaaS应用程序会间歇性地卡顿、变慢，因为很长时间都没有定位到原因，所以解决的办法就只能是重启。
这个现象和之前我们遇到的程序变得卡顿不太一样，因为我们发现这个应用程序不仅在高流量期间时会变慢，有时在低流量时期也会变慢。所以这令大家都很奇怪。
这类应用程序的变慢，重新启动之后就可以维持一段时间，但是过段时间又有可能会再次出现。
当我们准备排查这个问题的时候，我们在应用程序速度很慢的时候，尝试着捕获了这个应用程序的线程Dump。有很多种方式来捕获线程转Dump，我们选择了“jstack”工具来获取。
在问题发生时获得线程Dump是非常关键的！
然后我们将捕获的线程Dump上传到一个线上线程Dump分析工具（https://fastthread.io/）。该工具立即帮我们生成了一份报告。
报告立即找出了问题的根本原因。分析工具上显示“http-nio-8080-exec-121”线程阻塞了100多个线程。下面是传递依赖图，展示了阻塞线程:
从图中可以看到100多个线程被“http-nio-8080-exec-121”线程阻塞。当我们点击图中的“http-nio-8080-exec-121”超链接时，它会打印出线程的堆栈轨迹:
仔细观察图中被框出来的部分，你可以看到该线程已经获取到org.apache.log4j.Logger的锁，正在进行其他的操作。
接下来，我们随便找一个被"http-nio-8080-exec-121"阻塞的线程，看一下他的堆栈信息：
看一下上面堆栈跟踪中被框出来的部分。我们可以看到“http-nio-8080-exec-56”当前正处于阻塞（BLOCKED）状态，而阻塞的原因是它正在等待获取org.apache.log4j.Logger的锁。
前面我们刚刚分析过，“http-nio-8080-exec-121”获得了org.apache.log4j.Logger的锁，正在进行其他操作，而锁并没有被释放，所以其他线程想要获得锁就只能被阻塞。
其余的所有被阻塞的线程也在等待获取org.apache.log4j.Logger的锁。因此，每当任何应用程序线程试图记录日志时，它都会因为无法获取到锁而进入阻塞状态。
刚开始我们也没有太多的头绪，后来我们尝试借助Google的力量，然后我们用谷歌搜索了"org.apache.log4j.Logger 阻塞 线程"这样的关键字。
我们在Apache Log4j bug数据库中偶然发现了这个有趣的Bug，而且这个Bug早在2015年就被发现了。（https://bz.apache.org/bugzilla/show_bug.cgi?id=57714 ）。
这是Log4J框架中已知的bug之一，也是开发新的Log4j2框架的主要原因之一。
由于这个bug，任何试图打印日志的线程都进入了阻塞状态。它导致整个应用程序嘎然而止。一旦应用程序从Log4j迁移到Log4j2框架，问题就解决了。
Log4j已经在2015年8月开始就不再被维护了。如果您的应用程序仍在使用Log4J框架，强烈建议升级到Log4j2框架。Log4j2不仅仅是Log4j框架的下一个版本，它是一个从零开始编写的新框架，它有很多性能改进。
最后，如果网站遇到程序被拖慢的问题，那么也可以考虑一下这个因素。
关于作者：漫话编程，是一个通过漫画+音频的形式讲解枯燥的编程知识的公众号。致力于让编程变得更有乐趣。
推荐阅读：
漫话：如何给女朋友解释为什么计算机从0开始计数，而不是从1开始？漫话：为什么键盘以QWER排列，而不是ABCD？
漫话：为什么生僻字计算机上打不出来，或者打出来也无法显示呢？
Today's Interaction
今日互动
你有遇到过文章中的这种情况吗？最后如何解决的？
在留言区参与互动，精彩留言将获得脚本之家小程序积分，积分可直接兑换书籍。