charleschchen
作者charleschchen·2021-01-04 08:46
系统架构师·浪潮商用机器有限公司

使用ProbeVue/System trace定位消息队列ID泄漏问题

字数 4559阅读 2357评论 0赞 1

问题现象

客户使用System V消息队列用作进程间通讯用途,但随着使用时间的增长,消息队列数量呈较快速上升趋势,在业务繁忙时期一小时增加数千,一整天增加2万左右。客户需要每周定期重启来规避此问题。

观察发现,增加的消息队列主要是私有队列,其特征是消息队列key值为0xffffffff, 而且权限位为“--rw———”,用户属主为root/system.
此外,看起来这些消息队列从创建以来,从未被访问过(STIME/RTIME均显示为no-entry)。
形如:

# ipcs -qab  
IPC status from /dev/mem as of Wed Dec 30 15:10:38 BEIST 2020  
T ID KEY MODE OWNER GROUP CREATOR CGROUP CBYTES QNUM QBYTES LSPID LRPID STIME RTIME CTIME   
Message Queues:  
...
q 1025 0xffffffff --rw------- root system root system 0 0 4194304 0 0 no-entry no-entry 15:10:28

问题分析

初步看,系统中存在某类任务存在消息队列ID泄漏。鉴于泄漏
速度一天两万,尚在可容忍范围内,不会短期内耗尽消息队列ID资源。
参考:
https://www.ibm.com/support/knowledgecenter/en/ssw_aix_72/generalprogramming/ipc_limits.html
AIX上消息队列ID数的上限为1048576,按当前的泄漏速度,客户每周重启一次是可以有效避免故障发生的。

定位此问题可以使用System trace或probevue方法监控消息队列创建的过程。

System trace方法

需要开启循环trace(指定-l选项),然后在发现问题后立即停止trace:

  1. 开启循环trace,跟踪消息队列创建
# trcrpt -j|grep -i msg  
3c70 MSGCONV EVENT  
3c80 MSGCTL SYSTEM CALL  
3c90 MSGGET SYSTEM CALL  
3ca0 MSGRCV SYSTEM CALL  
3cb0 MSGSELECT SYSTEM CALL  
3cc0 MSGSND SYSTEM CALL  
3cd0 MSGXRCV SYSTEM CALL  
可以看到,消息队列创建对应的trace hook为3c8、3c9。

  

#trace -anl -J tidhk -j 3c8,3c9 -L 100000000 -T 50000000 -o /tmp/ips/trace.raw  
  1. 发现问题后,停止trace

    #trcstop

Probevue方法

使用probevue可以很容易针对系统调用进行追踪,相对来说probevue使用的系统资源比system trace更少,相对更适合在生产环境使用。entry方法可以用于获取系统调用参数,exit方法可以用于获取返回值。

#!/bin/ksh  
#NO WARRANTY IMPLIED. USE AT YOUR OWN RISK. by Charles Chen.  
  
cat <<\\\\ENDMARKER > ipcmon.e  
int msgget (unsigned int Key, int MessageFlag);  
int count;  
@@BEGIN  
{  
printf("begin probing\\\\n");  
count = 0;  
}  
  
@@syscallx:*:msgget:entry  
{  
printf("\\\\n\\\\nProgram <%s>, Pid <%ld>, Tid <%ld> called msgget, key = 0x%x, flag = 0%o (oct)\\\\n", __pname, __pid, __tid, __arg1, __arg2);  
printf("Group ID: %ld, parent Pid : %ld.\\\\n", __pgid, __ppid);  
printf("real user id = %d, effective user id = %d.\\\\n", __uid, __euid);  
stktrace(PRINT_SYMBOLS | GET_USER_TRACE, -1);  
count++;  
}  
  
@@syscallx:*:msgget:exit  
{  
printf("Program <%s>, Pid <%ld>, Tid <%ld> msgget returned, msgid = %d\\\\n", __pname, __pid, __tid, __rv);  
}  
  
@@interval:*:clock:60000  
{  
printf("%d event traced\\\\n", count);  
}  
ENDMARKER  
  
probevue -o probe`date '+%Y-%m-%d-%H-%M-%S'`.out ipcmon.e  
  
  

System trace方法跟踪结果

我们在 13:50:36启动trace,然后在13:50:39 ipcs发现具备问题特征的消息队列ID=133193746 (0x7F06012) 被创建。 :

q 133193746 0xffffffff --rw------- root system root system 0 0 4194304 0 0 no-entry no-entry 13:50:39 

解析trace报告,可以很容易看到,该队列是由rmmsgq进程创建:

#trcrpt -Opid=on,tid=on,exec=on,svc=on,timestamp=1 ./trace.raw > trace.int
#grep 7F06012 trace.int 
3C9 rmmsgq 9371682 110887083 2.879396 msgget key=FFFFFFFFFFFFFFFF IPC_PRIVATE msgflg=0180 msgid=7F06012 
3C8 rmmsgq 9371682 110887083 2.879396 msgctl msgid=7F06012 cmd=0066 buf=2FF226E0

调用msgget创建消息队列所带flag为0180 (16进制),换算成8进制即600,即MSG_R + MSG_W,并未设置IPC_CREAT.
相关参数定义可以参考:
/usr/include/sys/ipc.h、/usr/include/sys/msg.h

Probevue方法跟踪结果

在发现具备问题特征的消息队列被创建后,可以很容易在probevue输出中获取到调用参数以及调用栈信息:

Program <rmmsgq>, Pid <21299626>, Tid <55247117> called msgget, key = 0xffffffff, flag = 0600 (oct)  
Group ID: 21299626, parent Pid : 19399122.  
real user id = 0, effective user id = 0.  
0x100001b8  
0x10000588  
sc_entry_etrc_point+0x4  
.msgget+0x0  
Program <rmmsgq>, Pid <21299626>, Tid <55247117> msgget returned, msgid = 133193746  
1 event traced
  

  

其中0x100001b8/0x10000588为应用代码段地址,可以通过dbx分析对应函数名称:

# dbx /rmmsgq  
Type 'help' for help.  
reading symbolic information ...  
(dbx) 0x100001b8/i  
0x100001b8 (__start+0x68) 48000361 bl 0x10000518 (main)   
(dbx) 0x10000588/i  
0x10000588 (main+0x70) 4800016d bl 0x100006f4 (msgget)   

可以看到0x100001b8/0x10000588分别对应__start以及main函数。

问题结论

通过上述分析,可以看到消息队列为rmmsgq进程创建。经了解,rmmsgq是用户用来清理废弃消息队列的工具。进一步分析rmmsgq程序执行栈以及代码发现,其代码逻辑在处理消息队列键值时存在缺陷,未能考虑ftok返回-1的情况(-1在AIX上正好对应IPC_PRIVATE取值)。
因此,本意是删除废弃消息队列,但执行过程中意外造成了很多私有消息队列被创建。

如果key=-1(即IPC_RPIVATE)时调用msget,按msgget接口规范,如果key为IPC_PRIVATE, 无论flags中是否设置了IPC_CREAT,系统都会据此创建一个消息队列;参考如下的接口说明(man msgget).

#man msgget  
...  
A message queue identifier, associated message queue, and data structure are created for the value of the Key parameter if one of the following conditions is true:  
* The Key parameter is equal to the IPC_PRIVATE value.  
* The Key parameter does not already have a message queue identifier associated with it, and the IPC_CREAT value is set.  
  

解决方案

调整应用代码,在消息队列清理部分增加异常处理。由于队列名称queuename对应的文件可能不可访问(比如权限不符),或者已经被删除,这样ftok生成key值时会返回-1;从trace数据看,实际业务场景中,这种因为找不到文件,造成ftok返回-1的情况确实存在。
因此,对于这种情况,应当直接记录并返回失败,而不是继续调用msgget创建一个完全无关的私有消息队列。经过调整后,问题解决。

如果觉得我的文章对您有用,请点赞。您的支持将鼓励我继续创作!

1

添加新评论0 条评论

Ctrl+Enter 发表

作者其他文章

相关文章

相关问题

相关资料

X社区推广