OpenJ9的jps,jstack无响应问题

OpenJ9是IBM&Eclipse开源的一款jvm。与Oracle jvm(所谓“官方”)相比,memory footprint较小,启动速度快是它的主要优势。
我们在实施过程中,主要遇到了jps, jstack无响应问题,不影响程序运行,但影响程序问题排查。本文记录了解决该问题的过程。

问题现象

jvm运行约半个月后,使用依赖jvm attach api的工具(如jps, jstack等)attach到目标jvm上,很长一段时间无响应直至SocketTimeout,无法attach成功。
出现该情况后,使用kill -3 目标jvm,触发jvm coredump之后,再次使用jps, jstack等工具进行attach,可以attach成功,并能正确返回相应调试信息。

最终结论

根本原因是centos对/tmp目录的自动清理造成。
修改/usr/lib/tmpfiles.d/tmp.conf,设置

x /tmp/.com_ibm_tools_attach/*

可以彻底解决该问题。

排查过程

首先肯定去网上找有没有类似的场景类似的问题,最后找到一个比较相近的:
https://github.com/eclipse-openj9/openj9/issues/13010

github.com/eclipse-openj9/openj9/issues/13010

但是很不幸,这个场景是jvm停止之后残留的ipc文件导致,而我的场景中,jvm是一直正常运行着的,并未停止。所以,这个issue唯一有参考价值的地方,就是/tmp/.com_ibm_tools_attach这个目录,起码知道了这个目录是OpenJ9 jvm用于存放ipc文件的,是jps, jstack等工具依赖的关键目录。
这个时候我立马想到了/tmp目录的自动清理。运行半个月出问题,大概率是自动清理造成。于是立马查看了/tmp/.com_ibm_tools_attach这个目录之下的内容,很遗憾的发现,貌似所有进程的ipc文件都完好无损,压根就没有被清理的迹象。
其实此时离真相已经非常接近了,但对于一个从未接触过ipc的人来说,谁会发现inode中的玄机,谁会想到去查inode号呢?
所以当时,我错误地排除了文件被清理的这种可能,从OpenJ9源码入手,想找到一些线索。
OpenJ9中与attach api相关的实现有2部分,java部分和c++部分。
java部分实现主要集中在openj9.internal.tools.attach.target包的这几个类:AttachHandler, WaitLoop, Attachment, CommonDirectory, IPC
主要负责①ipc文件的管理以及②提供attach api服务,外部工具就是通过attach请求创建一个tcp连接进来,与jvm通信的。
c++部分主要通过ipc文件、共享内存、信号量等手段来实现进程间的ipc通信。
以jstack为例,具体流程如下:
目标jvm在启动后,会检查/tmp/.com_ibm_tools_attach(下文简称common directory)这个目录下的ipc文件,如果没有或者过期则会重新创建;
目标jvm在启动后,会创建1个Attach API wait loop的线程,用于监听外部的attach请求;
jstack内部开启一个ServerSocket,用于与目标jvm通信;
jstack向common directory/jvm进程号 这个目录写入replyInfo文件,文件内容为ServerSocket的端口号
jstack通过common directory下的信号量专用文件_notifier发送信号量。注意此操作不会向文件写入内容,不会改变_notifier文件的修改日期;
目标jvm收到信号量,读取replyInfo文件获取与jstack通信的端口号,通过该端口号连接jstack;
jstack与目标jvm通过端口连接后,删除replyInfo文件,后续两者就通过tcp通信。
这些过程会有很多日志,如果出现问题,可以通过:
OpenJ9 jvm参数-Dcom.ibm.tools.attach.logging=yes可以看到java部分的日志;
OpenJ9 jvm参数-Xtrace:maximal=j9prt,output=trace.out可以看到c++部分的日志。
好,说了这么多,回到之前的问题:ipc文件看上去没有被清理,为什么ipc无法正常工作?
起初我猜测信号量文件_notifier应该会有过期时间,因为问题半个月出现一次。但是从jvm的ipc相关代码中,并没有看到设置信号量过期时间为半个月的这种逻辑出现。
那问题就很诡异了,到底发生了什么,只有通过相关工具来跟踪信号量文件,才能找到真相,我这边使用的是ipcs工具。

ipcs -a
------ Semaphore Arrays --------
key        semid      owner      perms      nsems
0xd7549b54 4          root      600        152
0xd7549b55 5          root      600        152
0xd7549b56 6          root      600        152

ipcs输出的列中,我比较关心的是key和semid。semid不用过多解释,就是信号量的id,那这个key是如何生成的?
继续查看jvm代码,这个key是通过ftok()函数生成出来的,ftok会根据文件的inode号来生成,也就是说,这个key截取了_notifier文件的inode号一部分,如果文件名相同,inode号不对,是不能正常通信的。
到这里我似乎有些明白了,有没有可能出现_notifier文件被删除,但是后面又重新生成这种情况?
我把common directory整个删除,然后执行jstack,报错Error getting data from xxx...然后一看,common directory重新生成了,_notifier也重新生成了。因为重新生成的信号量文件与之前使用的信号量文件inode号不一致,所以两者的semid也肯定不一致,所以看上去文件还在,但是无法正常ipc通信,所以jstack调不通。
centos的自动清理功能是根据文件修改时间,上文说过,使用信号量文件通信,文件的修改时间是不会发生变化的,也就最终导致了_notifier文件被清理;被清理之后,我发现jstack调不通的时候,因为执行了jstack,jstack也是基于jvm运行,故_notifier文件被重新生成出来,造成了当初的错觉。
真相大白,不容易啊。

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

推荐阅读更多精彩内容