程序中输出日志, 是正常普通的事情, 可是由于对日志的输出的预估不足, 可能导致意想不到的后果. 曾经遇到过几次由于程序代码狂打日志, 导致 CPU 报警的情况. 今天就聊曾经遇到过的一次.
某天, 某开发人员说他们生产上有些机器 CPU 使用率不知道什么时候已经飙升到 90%以上了, 不知道怎么回事, 我心想, 这不是好事么, CPU 使用率高, 说明你们代码没让 CPU 闲着, 提高生产效率. 简单抛了几个问题给开发人员. 开发人员给了具体的回答.
一般 CPU 高, 要从线程看起, 做了几个 thread dump, 大概推断出问题的所在, 进一步分析, 验证了这个推断.
为什么会调用这个 println 方法呢? 原来这些 thread 都遇到了一个 CommonException, 程序捕获这个 CommonException 之后, 就在 catch 块里面调用了 CommonException 的 printStacktrace() 方法; 然而这个方法对于没有指定要 print 到哪里去的情况, 默认是输出到 System.err, 这个 System.err 正是一个 PrintStream.
其实看到这里感觉也没啥问题, 很多人都是把 log 输出到 System.out, System.err 的. 这个应用里面, System.out, System.err 都是重定向到 log 文件的, 也就是和 log4j 一样, 都输出到了文件系统. 他们的文件都叫 stdout.log. 仔细查看输出的问题, 就会发现, 输出文件的效率真是太高了. 每秒 2 个文件, 每个 6M:
那么这样问题就可以解释了: 30 个线程不停的在出错, 不停的要写日志到 System.err 中, 这里有个锁, 它们要频繁的获取 /释放, 它们从获取到释放的时间又超短, 仅仅写一个 10 行日志. 本来获取释放锁操作就是一个比较重量的操作, 这个重量就是指的 CPU 消耗比较高. 频繁短期的获取释放锁必然会导致 CPU 飙升.
1
jaskle 2019-06-24 08:04:14 +08:00 via Android
日志最好是无锁队列进行消费,当然也存在问题比如突然断电或程序崩掉导致后面的未记录,当然这是 c 系当心的问题。Java 是不会崩掉的,除非内存炸了,当然,这样最后几条也没意义
|
2
petelin 2019-06-24 08:11:44 +08:00 via iPhone
很有意义多谢 一楼是最佳实践 几乎所有 metric 上传 都应该放在 channel 里慢慢搞
|