logback 在打印完一个很大的内容的时候,程序会卡在那里很久是为什么?

2022-04-12 12:34:23 +08:00
 abcbuzhiming
这个问题是无意中发现的:

有个新人不太懂数据处理,一口气把数据库 4w 多条数据都拿了出来,然后转换成了 json 字符串,调用 log 打印。


它测试是在 IDEA 里执行调试模式。打印是立刻就打印出来了——可以看到打印结果,以及数组 json 最后的结尾括号]。这应该说明 logback 至少打印 api 执行成功。


但是会在这里卡住,是程序卡住,并非 IDEA 卡住了,IDEA 还能做各种操作,然而程序就卡在这里,它也不崩溃,一开始我们以为 OOM 了,但是没有。反正就卡在这。然后等待约 10 分钟的时候。程序又继续若无其事的往下走了。


这个现象我们现在还没想明白咋回事,高度怀疑是触发 full GC 了,但是 full GC 需要接近 10 分钟吗?我们这其实就是个小程序,平时跑起来就几百 M 内存的那种。

我们该如何分析这个问题?

补充:后来我们尝试把 XMX 扩大到 8G ,这个现象没有任何缓解。
1927 次点击
所在节点    Java
10 条回复
chendy
2022-04-12 12:40:07 +08:00
目测是 idea 的输出卡住了吧……
vacuitym
2022-04-12 13:37:00 +08:00
不如试试异步输出能不能解决
abcbuzhiming
2022-04-12 13:41:32 +08:00
@chendy 输出没卡啊,你看那行打印代码的打印结果已经全部输出到 Console 里了,都看到数组结构的 json 结尾的中括号了。但是它就不往后继续执行了,我们试过在后面加一行代码 System.out.println 。确认是一直卡着没往下走。也就是说,log 的那行代码,它把内容完整的输出了,但是程序却停在了这里


@vacuitym 异步输出是为了做什么?
warcraft1236
2022-04-12 13:46:01 +08:00
@abcbuzhiming 提供一个思路,加上类似 printstacktrace 之类的东西,看看 Jvm 这时候是什么状态,在干什么
polarbear007
2022-04-12 13:46:11 +08:00
我猜只是输出的内容太长了(特别是那种没有换行的),控制台卡住了而已。你可以尝试把打印的日志信息写到一个文件中,就不会卡了,当然使用文本编辑器打开这个文件的话估计同样会卡。
senninha
2022-04-12 14:07:17 +08:00
本地的话直接开 jmc 连上去看看不就知道了
XhstormR02
2022-04-12 23:01:15 +08:00
开 RDP 让我上去看看
wineast
2022-04-13 14:40:54 +08:00
之前在 idea 上碰过一个类似的问题,就是程序在本地运行的速度比服务器上慢很多,后来发现是因为日志配置了输出到文件和 console 的关系,每次输出到 console ,打印花了大量的时间和资源,去掉 console 输出后,就快了很多,基本和服务器没什么区别。
所以我建议加内存是从 idea 上入手,而不是程序本身
zhady009
2022-04-18 09:46:28 +08:00
用 arthas trace 下一步一步找下去试试
vacuitym
2022-04-24 13:40:25 +08:00
@abcbuzhiming 正常生产日志都会异步吧,避免占用资源导致阻塞

这是一个专为移动设备优化的页面(即为了让你能够在 Google 搜索结果里秒开这个页面),如果你希望参与 V2EX 社区的讨论,你可以继续到 V2EX 上打开本讨论主题的完整版本。

https://www.v2ex.com/t/846490

V2EX 是创意工作者们的社区,是一个分享自己正在做的有趣事物、交流想法,可以遇见新朋友甚至新机会的地方。

V2EX is a community of developers, designers and creative people.

© 2021 V2EX