问题描述
dmesg 中有如下报警信息:
netlink: 24 bytes leftover after parsing attributes in process `ip'.
netlink: 4 bytes leftover after parsing attributes in process `server'.
对问题的初步分析
网上搜索类似问题,找到了如下链接:
Fix for LLDP related netlink error messages #375
链接描述说明,这个问题是用户态程序发送给内核的 netlink 报文中填充的 nlmsg_len 字段长度存在问题。
链接中附上的 patch 如下:
这里的 patch 是针对 LLDP 的,并不能直接用到我们的程序中,但是它提供了一个定位问题的方向。
首先 dmesg 中的信息已经明确指出这个报警是 ip 命令与 server 程序触发的,应该是某某 send 系统调用所触发的,而 send 系统调用又依赖某个 socket 套接字,这样就需要先找到触发这个打印的 send 调用使用的 socket 套接字。
如何找到对应的 socket 套接字?
1. lsof 与 proc 目录
套接字也绑定到了文件描述符上,lsof 能够看到程序使用的套接字,访问 proc 目录能够看到其它的信息,但是 lsof 与 proc 目录的输入信息不能让人判断出是哪个 socket 套接字出现的问题。
2. gdb info os 子命令
gdb info os 子命令能够查看一些跟内核相关的资源的信息,info os sockets 能够查看程序使用的 sockets 的属性。
一个示例内容如下:
(gdb) info os sockets
local address local port remote address remote port state user family protocol
0.0.0.0 40487 0.0.0.0 0 LISTEN root INET STREAM
0.0.0.0 59179 0.0.0.0 0 LISTEN root INET STREAM
0.0.0.0 111 0.0.0.0 0 LISTEN root INET STREAM
0.0.0.0 57139 0.0.0.0 0 LISTEN rslsync INET STREAM
gdb info os sockets 得到的信息也不足以找到出问题的 socket。
3. strace
strace -p 跟踪程序,结果发现 strace 没有跟踪到系统调用过程。一段时间后想到这可能是跟踪多线程程序时踩到的一个坑,针对这个坑写了 strace 跟踪多线程程序不能打印系统调用的问题 这篇文章。
当时定位问题的时候没有进一步分析,直接跳过了。
4. 从源码中寻找端倪?
既然上面的三种尝试都失败了,只能从源代码中找一些端倪了。首先搜索了一下 netlink 相关内容,然后发现能够搜出来非常多的内容,要从这些内容中找到出问题的点也是非常困难的!
进一步的分析
dmesg 中的打印本身就是一种输入信息,这种输入信息将问题的范围界定到相关的程序——ip 命令与 server 程序中。
对于 ip 命令的 dmesg netlink 告警,也许可以通过手动执行 ip 命令来复现,使用了几个常见的 ip 命令测试了下没有触发问题。
同样搜索了一下业务中调用 ip 命令的代码,又搜出来了一堆内容,显然要从这一堆内容中找到触发问题的点非常困难,除非能够获取到更多的信息。
如果有某种方法能够获取到 ip 命令触发内核 dmesg netlink 告警信息时的命令行参数,这样问题的范围就进一步缩小了,那么有没有这种方法呢?我立刻就想到了在内核代码中调用用户态程序来获取 ip 命令的命令行内容。
内核代码中调用用户态程序的应用
既然已经确定要在内核代码中调用用户态程序,那么首先需要确定的是要在内核代码的哪个位置调用呢?
要解决这个问题,首先得确定 dmesg 信息是在哪里打印的。使用如下关键词搜索内核源码树:
leftover after parsing attributes
确定这个打印是在 lib/nlattr.c 中的 __nla_parse 函数中搞的,于是对 nlattr.c 源码进行修改,patch 内容如下:
Index: nlattr.c
===================================================================
--- nlattr.c (revision 37849)
+++ nlattr.c (working copy)
@@ -164,6 +164,32 @@
}
EXPORT_SYMBOL(nla_policy_len);
+static int run_umode_handler_example(int arg)
+{
+ char *argv[3], *envp[4], buffer[32];
+ int i = 0, value;
+
+ argv[i++] = "/usr/bin/debug.sh";
+
+ snprintf(buffer, sizeof(buffer), "%d", arg);
+
+ argv[i++] = buffer;
+
+ argv[i] = NULL;
+
+
+ i = 0;
+ /* minimal command environment */
+ envp[i++] = "HOME=/";
+ envp[i++] = "PATH=/sbin:/bin:/usr/sbin:/usr/bin";
+ envp[i] = NULL;
+
+ value = call_usermodehelper(argv[0], argv, envp, UMH_WAIT_PROC);
+
+ printk("value is %d\n", value);
+ return 0;
+}
+
/**
* nla_parse - Parse a stream of attributes into a tb buffer
* @tb: destination array with maxtype+1 elements
@@ -201,10 +227,11 @@
}
}
- if (unlikely(rem > 0))
+ if (unlikely(rem > 0)) {
pr_warn_ratelimited("netlink: %d bytes leftover after parsing attributes in process `%s'.\n",
rem, current->comm);
-
+ run_umode_handler_example(current->pid);
+ }
err = 0;
errout:
return err;
上述 patch 将会在内核打印 dmesg netlink 告警的时候调用用户态程序 /usr/bin/debug.sh,同时将当前进程的 pid 传递给这个脚本,有了这个 pid,就可以使用这个 debug.sh 脚本来 cat /proc/pid/cmdline 的信息,这样就得到了程序使用的命令行参数。
需要注意 call_usermodehelper 函数的参数 argv[0] 必须为绝对路径,不然会返回 -2,表示文件不存在!
debug.sh 脚本的内容如下:
#!/bin/bash
cat /proc/$1/cmdline >> /tmp/debug_message
重新编译内核并部署,当下一次问题出现后查看 /tmp/debug_message 文件内容得到了如下信息:
ipxfrmstate
这个内容有点奇怪,实际上是没有在子命令中添加空格,它表示的实际命令是 ip xfrm state。
直接在出问题设备上调用 ip xfrm state
命令,果然能够复现问题,这说明已经找到了必现的方法。
对 ip 命令的进一步分析
上文中已经描述了,通过在内核代码中调用用户态程序的方式获取到 ip 命令触发内核 dmesg 异常打印的参数。这时候我需要分析 ip 命令的源码,于是我找了下我们 svn 中维护的 iproute2 包的代码,结果发现有两个版本,一个是 3.10,一个是 4.12,出问题机器上用的是 3.10 版本。
一开始我并没有注意到版本的区别,直接使用了 4.12 版本,编译了一个测试发现不出问题了,这又把我整懵了,不过搞了一会后我注意到了版本的区别,使用 3.10 版本的 ip 命令还是会出的。
我怀疑可能是头文件的问题,首先看了下代码发现 iproute2 中使用的 netlink.h 头文件是本地的,并不会使用编译机器上 /usr/src/ 中的头文件。于是对比了 3.10 版本与 4.12 版本 netlink 相关的头文件内容,发现没有区别,这又让我感觉非常懵圈。
一阵懵圈后,我想到可以对比 strace 的结果来找差异点。收集到的相关信息如下:
4.12 版本 ip 命令 strace 信息:
socket(AF_NETLINK, SOCK_RAW|SOCK_CLOEXEC, NETLINK_ROUTE) = 3
setsockopt(3, SOL_SOCKET, SO_SNDBUF, [32768], 4) = 0
setsockopt(3, SOL_SOCKET, SO_RCVBUF, [1048576], 4) = 0
setsockopt(3, SOL_NETLINK, NETLINK_EXT_ACK, [1], 4) = 0
bind(3, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, 12) = 0
getsockname(3, {sa_family=AF_NETLINK, nl_pid=1894, nl_groups=00000000}, [12]) = 0
socket(AF_NETLINK, SOCK_RAW|SOCK_CLOEXEC, NETLINK_XFRM) = 4
setsockopt(4, SOL_SOCKET, SO_SNDBUF, [32768], 4) = 0
setsockopt(4, SOL_SOCKET, SO_RCVBUF, [1048576], 4) = 0
setsockopt(4, SOL_NETLINK, NETLINK_EXT_ACK, [1], 4) = 0
bind(4, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, 12) = 0
getsockname(4, {sa_family=AF_NETLINK, nl_pid=1894, nl_groups=00000000}, [12]) = 0
sendto(4, {{len=56, type=XFRM_MSG_GETSA, flags=NLM_F_REQUEST|NLM_F_DUMP, seq=1603850351, pid=0}, "\x28\x00\x1a\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"...}, 56, 0, NULL, 0) = 56
recvmsg(4, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=NULL, iov_len=0}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_TRUNC}, MSG_PEEK|MSG_TRUNC) = 20
recvmsg(4, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{len=20, type=NLMSG_DONE, flags=NLM_F_MULTI, seq=1603850351, pid=1894}, 0}, iov_len=20}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 20
close(4) = 0
3.10 版本 strace 信息:
socket(AF_NETLINK, SOCK_RAW|SOCK_CLOEXEC, NETLINK_ROUTE) = 3
setsockopt(3, SOL_SOCKET, SO_SNDBUF, [32768], 4) = 0
setsockopt(3, SOL_SOCKET, SO_RCVBUF, [1048576], 4) = 0
bind(3, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, 12) = 0
getsockname(3, {sa_family=AF_NETLINK, nl_pid=3142, nl_groups=00000000}, [12]) = 0
socket(AF_NETLINK, SOCK_RAW|SOCK_CLOEXEC, NETLINK_XFRM) = 4
setsockopt(4, SOL_SOCKET, SO_SNDBUF, [32768], 4) = 0
setsockopt(4, SOL_SOCKET, SO_RCVBUF, [1048576], 4) = 0
bind(4, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, 12) = 0
getsockname(4, {sa_family=AF_NETLINK, nl_pid=3142, nl_groups=00000000}, [12]) = 0
sendto(4, {{len=40, type=XFRM_MSG_GETSA, flags=NLM_F_REQUEST|NLM_F_DUMP, seq=1603850514, pid=0}, "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x08\x00\x1d\x00\x01\x00\x00\x00"}, 40, 0, NULL, 0) = 40
recvmsg(4, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{len=20, type=NLMSG_DONE, flags=NLM_F_MULTI, seq=1603850514, pid=3142}, 0}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 20
close(4) = 0
对比发现 sendto 系统调用中的 len 长度不同,4.12 是 56 字节,3.10 是 40 字节,可是这两者差别也是 16 字节呀,也解释不了 dmesg 中打印的 24 字节,看来需要分析分析相关的内核源码。
相关内核源码分析
有如下两篇博文的积累,我对 netlink 的工作流程有了一定的了解。
cn_proc demo 中创建一个 netlink socket 背后的内核行为
connector 框架与 cn_proc 使用 demo 的深入分析
这里的问题显然出在内核收到用户态发送的 netlink 消息后,那么内核中是如何处理 ip xfrm state 命令发出的 netlink 报文的呢?
首先使用 NETLINK_XFRM 在内核源码树的 net 目录中搜索,得到了如下内容:
./netlink/af_netlink.c:271: case NETLINK_XFRM:
./xfrm/xfrm_user.c:3327: nlsk = netlink_kernel_create(net, NETLINK_XFRM, &cfg);
./xfrm/xfrm_user.c:3374:MODULE_ALIAS_NET_PF_PROTO(PF_NETLINK, NETLINK_XFRM);
查看 xfrm_user.c 的代码,确定 NETLINK_XFRM socket 在 xfrm_user_net_init 函数中被调用。xfrm_user_net_init 函数的代码如下:
3319 static int __net_init xfrm_user_net_init(struct net *net)
3320 {
3321 struct sock *nlsk;
3322 struct netlink_kernel_cfg cfg = {
3323 .groups = XFRMNLGRP_MAX,
3324 .input = xfrm_netlink_rcv,
3325 };
3326
3327 nlsk = netlink_kernel_create(net, NETLINK_XFRM, &cfg);
3328 if (nlsk == NULL)
3329 return -ENOMEM;
3330 net->xfrm.nlsk_stash = nlsk; /* Don't set to NULL */
3331 rcu_assign_pointer(net->xfrm.nlsk, nlsk);
3332 return 0;
3333 }
注意这里创建 netlink sock 结构时传入的 cfg 结构体,其 input 函数指针指向 xfrm_netlink_rcv 函数,这个函数就是内核中接收到用户态发送的 xfrm netlink 消息时调用到的函数,下面直接跳到 xfrm_netlink_rcv 函数,此函数只有几行代码,贴到下面:
2671 static void xfrm_netlink_rcv(struct sk_buff *skb)
2672 {
2673 struct net *net = sock_net(skb->sk);
2674
2675 mutex_lock(&net->xfrm.xfrm_cfg_mutex);
2676 netlink_rcv_skb(skb, &xfrm_user_rcv_msg);
2677 mutex_unlock(&net->xfrm.xfrm_cfg_mutex);
2678 }
xfrm_netlink_rcv 在占用了互斥锁的情况下传入 xfrm_user_rcv_msg 回调函数调用 netlink_rcv_skb 处理 netlink 报文,
xfrm_user_rcv_msg 回调函数解析 netlink 报文的头部,根据 nlmsg_type 进行判断,在贴代码之前,先贴出之前 strace 跟踪输出的 sendto 的参数。
sendto(4, {{len=56, type=XFRM_MSG_GETSA, flags=NLM_F_REQUEST|NLM_F_DUMP, seq=1603850351, pid=0},
注意这里设定的 netlink 报文的类型为 XFRM_MSG_GETSA,flags 中设定了 NLM_F_DUMP 表示 dump 相关内容。
xfrm_user_rcv_msg 函数中的相关逻辑如下:
2636 type -= XFRM_MSG_BASE;
2637 link = &xfrm_dispatch[type];
..............................................................
2643 if ((type == (XFRM_MSG_GETSA - XFRM_MSG_BASE) ||
2644 type == (XFRM_MSG_GETPOLICY - XFRM_MSG_BASE)) &&
2645 (nlh->nlmsg_flags & NLM_F_DUMP)) {
2646 if (link->dump == NULL)
2647 return -EINVAL;
2648
2649 {
2650 struct netlink_dump_control c = {
2651 .start = link->start,
2652 .dump = link->dump,
2653 .done = link->done,
2654 };
2655 return netlink_dump_start(net->xfrm.nlsk, skb, nlh, &c);
2656 }
2657 }
这个函数会根据 netlink 报文类型确定一个 link 结构,这个 link 结构被用来设定一个 netlink_dump_control 结构体的内容,最终在 netlink_dump_start 函数中被使用。link 结构体的定义内容部分截取如下:
2584 static const struct xfrm_link {
2585 int (*doit)(struct sk_buff *, struct nlmsghdr *, struct nlattr **);
2586 int (*start)(struct netlink_callback *);
2587 int (*dump)(struct sk_buff *, struct netlink_callback *);
2588 int (*done)(struct netlink_callback *);
2589 const struct nla_policy *nla_pol;
2590 int nla_max;
2591 } xfrm_dispatch[XFRM_NR_MSGTYPES] = {
2592 [XFRM_MSG_NEWSA - XFRM_MSG_BASE] = { .doit = xfrm_add_sa },
2593 [XFRM_MSG_DELSA - XFRM_MSG_BASE] = { .doit = xfrm_del_sa },
2594 [XFRM_MSG_GETSA - XFRM_MSG_BASE] = { .doit = xfrm_get_sa,
2595 .dump = xfrm_dump_sa,
2596 .done = xfrm_dump_sa_done },
............
2619 };
这里 XFRM_MSG_BASE 是 xfrm_link 数组的起始下标,XFRM_MSG_GETA 没有实现 start 函数,在这个例子中,触发内核 netlink 打印的代码是在 xfrm_dump_sa 函数中,下面的 dumpstack 信息可以证明这点:
[ 2400.266042] ip D ffffffc000086d3c 0 12036 12031 0x00000001
[ 2400.266048] Call trace:
[ 2400.268834] [<ffffffc000086d3c>] __switch_to+0x8c/0xa0
[ 2400.268838] [<ffffffc000805a9c>] __schedule+0x170/0x504
[ 2400.268842] [<ffffffc000805e60>] schedule+0x30/0x88
[ 2400.268847] [<ffffffc0008087d4>] schedule_timeout+0x134/0x1a4
[ 2400.268851] [<ffffffc0008068b0>] wait_for_common+0xc4/0x174
[ 2400.268854] [<ffffffc000806974>] wait_for_completion+0x14/0x1c
[ 2400.268860] [<ffffffc0000b56e0>] call_usermodehelper_exec+0x13c/0x160
[ 2400.268864] [<ffffffc0000b59b8>] call_usermodehelper+0x44/0x58
[ 2400.268870] [<ffffffc0003fc5cc>] nla_parse+0xf0/0x1f8
[ 2400.268876] [<ffffffbffc229708>] xfrm_dump_sa+0x88/0x118 [xfrm_user]
[ 2400.268880] [<ffffffc0007184b0>] netlink_dump+0x1d0/0x2ac
[ 2400.268884] [<ffffffc000718a34>] __netlink_dump_start+0x14c/0x1a0
[ 2400.268890] [<ffffffbffc2295f8>] xfrm_user_rcv_msg+0x134/0x1bc [xfrm_user]
[ 2400.268894] [<ffffffc00071a3b4>] netlink_rcv_skb+0xc4/0xec
[ 2400.268900] [<ffffffbffc228a28>] xfrm_netlink_rcv+0x34/0x54 [xfrm_user]
[ 2400.268904] [<ffffffc000719cc0>] netlink_unicast+0x17c/0x224
[ 2400.268908] [<ffffffc00071a130>] netlink_sendmsg+0x310/0x374
[ 2400.268912] [<ffffffc0006ce45c>] sock_sendmsg+0x44/0x50
[ 2400.268916] [<ffffffc0006cf830>] SyS_sendto+0xb0/0xf0
[ 2400.268919] [<ffffffc000085c70>] el0_svc_naked+0x24/0x28
这个堆栈是我在 call_usermodehelper 调用后添加了 dumpstack 函数得到的内容。有了这个认识后直接跳到 xfrm_dump_sa 函数中,此函数中与这个问题相关的代码如下:
989 static int xfrm_dump_sa(struct sk_buff *skb, struct netlink_callback *cb)
990 {
991 struct net *net = sock_net(skb->sk);
992 struct xfrm_state_walk *walk = (struct xfrm_state_walk *) &cb->args[1];
993 struct xfrm_dump_info info;
994
995 BUILD_BUG_ON(sizeof(struct xfrm_state_walk) >
996 sizeof(cb->args) - sizeof(cb->args[0]));
997
998 info.in_skb = cb->skb;
999 info.out_skb = skb;
1000 info.nlmsg_seq = cb->nlh->nlmsg_seq;
1001 info.nlmsg_flags = NLM_F_MULTI;
1002
1003 if (!cb->args[0]) {
1004 struct nlattr *attrs[XFRMA_MAX+1];
1005 struct xfrm_address_filter *filter = NULL;
1006 u8 proto = 0;
1007 int err;
1008
1009 err = nlmsg_parse(cb->nlh, 0, attrs, XFRMA_MAX, xfrma_policy,
1010 cb->extack);
xfrm_dump_sa 中并没有调用 nla_parse 函数,其实 nla_parse 函数是在 nlmsg_parse 函数中调用的。nlmsg_parse 函数是一个内联函数,在 include/net/netlink.h 中定义,其代码如下:
static inline int nlmsg_parse(const struct nlmsghdr *nlh, int hdrlen,
struct nlattr *tb[], int maxtype,
const struct nla_policy *policy,
struct netlink_ext_ack *extack)
{
if (nlh->nlmsg_len < nlmsg_msg_size(hdrlen)) {
NL_SET_ERR_MSG(extack, "Invalid header length");
return -EINVAL;
}
return nla_parse(tb, maxtype, nlmsg_attrdata(nlh, hdrlen),
nlmsg_attrlen(nlh, hdrlen), policy, extack);
}
不过 nlmsg_parse 真的会被调用到吗?不是还有个判断 cb->args[0] 的操作吗?cb->args[0] 是在哪里被赋值的呢?
其实 cb->args 并没有在哪里被赋值,它只在 netlink_dump_start 函数调用时执行 memset 被清 0,相关代码如下:
2329 memset(cb, 0, sizeof(*cb));
到这里我们离 nla_parse 函数只有一步之遥,在进入到 nla_parse 函数之前,先看看 nlmsg_attrdata 与 nlmsg_attrlen 的定义,确定传给 nla_parse 函数的参数,从 netlink.h 中找到如下描述信息:
25 * Payload Format:
26 * <---------------------- nlmsg_len(nlh) --------------------->
27 * <------ hdrlen ------> <- nlmsg_attrlen(nlh, hdrlen) ->
28 * +----------------------+- - -+--------------------------------+
29 * | Family Header | Pad | Attributes |
30 * +----------------------+- - -+--------------------------------+
31 * nlmsg_attrdata(nlh, hdrlen)---^
nlmsghdr netlink 报文头部定义如下:
44 struct nlmsghdr {
45 __u32 nlmsg_len; /* Length of message including header */
46 __u16 nlmsg_type; /* Message content */
47 __u16 nlmsg_flags; /* Additional flags */
48 __u32 nlmsg_seq; /* Sequence number */
49 __u32 nlmsg_pid; /* Sending process port ID */
50 };
可以计算出 nlmsghdr 头的大小为 16 个字节,它在 4 字节的边界上因此不需要 Pad。在这里回到 ip 命令中 ip xfrm state 向内核发送 netlink 报文的代码:
97 int rtnl_wilddump_req_filter(struct rtnl_handle *rth, int family, int type,
98 __u32 filt_mask)
99 {
100 struct {
101 struct nlmsghdr nlh;
102 struct ifinfomsg ifm;
103 /* attribute has to be NLMSG aligned */
104 struct rtattr ext_req __attribute__ ((aligned(NLMSG_ALIGNTO)));
105 __u32 ext_filter_mask;
106 } req;
107
108 memset(&req, 0, sizeof(req));
109 req.nlh.nlmsg_len = sizeof(req);
110 req.nlh.nlmsg_type = type;
111 req.nlh.nlmsg_flags = NLM_F_DUMP|NLM_F_REQUEST;
112 req.nlh.nlmsg_pid = 0;
113 req.nlh.nlmsg_seq = rth->dump = ++rth->seq;
114 req.ifm.ifi_family = family;
115
116 req.ext_req.rta_type = IFLA_EXT_MASK;
117 req.ext_req.rta_len = RTA_LENGTH(sizeof(__u32));
118 req.ext_filter_mask = filt_mask;
119
120 return send(rth->fd, (void*)&req, sizeof(req), 0);
121 }
这里 nlh 的 nlmsg_len 被设定为 req 结构体的长度,其值为 40,同时 ifm.ifi_family 被设定为 0。内核中 nla_parse 的代码如下:
nla_parse(tb, maxtype, nlmsg_attrdata(nlh, hdrlen),
nlmsg_attrlen(nlh, hdrlen), policy, extack);
这里的 nlmsg_attrlen 得到的值将会是 24( 40 - 16(NLMSG_HDRLEN)),同时 nlmsg_attrdata 指向 netlink header 之后的内容,对应 ip 命令中填充的 req.nlh.ifm 结构体的其实地址。有了这些参数后进入到 nla_parse 中开始执行。
nla_parse 函数调用到的 __nla_parse 函数的核心代码如下所示:
static int __nla_parse(struct nlattr **tb, int maxtype,
const struct nlattr *head, int len,
bool strict, const struct nla_policy *policy,
struct netlink_ext_ack *extack)
{
..................................................
nla_for_each_attr(nla, head, len, rem) {
..................................................
}
if (unlikely(rem > 0)) {
pr_warn_ratelimited("netlink: %d bytes leftover after parsing attributes in process `%s'.\n",
rem, current->comm);
...................................................
nla_for_each_attr 会从 head 参数指向的地址开始解析,它是一个宏,其定义如下:
#define nla_for_each_attr(pos, head, len, rem) \
for (pos = head, rem = len; \
nla_ok(pos, rem); \
pos = nla_next(pos, &(rem)))
它的终止条件是 nla_ok,其代码如下:
static inline int nla_ok(const struct nlattr *nla, int remaining)
{
return remaining >= (int) sizeof(*nla) &&
nla->nla_len >= sizeof(*nla) &&
nla->nla_len <= remaining;
}
上文中已经提到 nla_parse 函数的 len 参数在这种情况下是 24,这时在 nla_ok 中的第二条判断处会返回 false,for 循环会终止,rem 的值为 24,就对应了 dmesg 中的 24bytes left over 的信息。
为啥会在 nla_ok 的第二条判断处返回呢?
上文中我已经说过,传递给 nla_parse 函数的 head 指向的是 ip 命令中设定的 req.ifm 的起始地址,而 nlattr 结构体中 len 是它的第一个元素,对应 req.ifm 中的第一个元素 ifi_family,其值在这个情境中为 0,不会大于 nlattr 的值,这样 nla_ok 就会返回 false,然后打印告警信息。
如何解决 ip 命令的告警信息?
可以修改 ip 命令,但是最好的方式是升级版本,最终我们确定通过升级版本来解决这个问题。
相同的分析过程用于 server 进程
server 进程不向 ip 命令,它并没有啥命令参数与发送 netlink 消息关联,意味着获取命令行参数将没有任何作用。
我针对这个特定的情景,设定了如下测试案例:
- 同样在 nla_parse 中调用用户态程序,不过这次直接调用 gdb 命令并执行 gdb 脚本来获取 server 运行堆栈
- 在 nla_parse 中添加 dumpstack 函数调用,打印内核执行路径
debug.sh 脚本修改为如下内容:
#!/bin/bash
# cat /proc/$1/cmdline >> /tmp/debug_message
gdb -p $1 -x /usr/bin/gdbscript >> /tmp/gdb_output
gdb 脚本内容如下:
thread apply all bt
quit
由于我们并不清楚 server 在什么时候打印,只能找了一台有打印的机器,在其上进行了部署,测试发现问题出现时内核打印了如下堆栈:
[ 2520.289509] server D ffffffc000086d3c 0 11730 1 0x00000000
[ 2520.289517] Call trace:
[ 2520.292312] [<ffffffc000086d3c>] __switch_to+0x8c/0xa0
[ 2520.292319] [<ffffffc000805a9c>] __schedule+0x170/0x504
[ 2520.292323] [<ffffffc000805e60>] schedule+0x30/0x88
[ 2520.292328] [<ffffffc00080616c>] schedule_preempt_disabled+0xc/0x14
[ 2520.292333] [<ffffffc00080768c>] __mutex_lock_slowpath+0xa0/0x13c
[ 2520.292336] [<ffffffc000807774>] mutex_lock+0x4c/0x64
[ 2520.292351] [<ffffffbffc228a1c>] xfrm_netlink_rcv+0x28/0x54 [xfrm_user]
[ 2520.292357] [<ffffffc000719cc0>] netlink_unicast+0x17c/0x224
[ 2520.292362] [<ffffffc00071a130>] netlink_sendmsg+0x310/0x374
[ 2520.292368] [<ffffffc0006ce45c>] sock_sendmsg+0x44/0x50
[ 2520.292372] [<ffffffc0006cf830>] SyS_sendto+0xb0/0xf0
[ 2520.292376] [<ffffffc000085c70>] el0_svc_naked+0x24/0x28
是不是有种似曾相识的感觉?xfrm_netlink_rcv 函数在上文中有分析过!到这里还不能完全确定问题,我查看 gdb 打出的堆栈信息,有如下内容:
#2 0x0000007fb6e1a900 in IpsecSaxxx::do_enforce_sync() () from
/lib/libxxx.so
#3 0x0000007fb6e1c760 in Ipsecxxx::do_sync() () from /lib/libxxx.so
这次直接确定了出问题所在的模块,联系写这个模块的同事,分析了下代码,立刻解决了问题。
跟同事沟通的过程中,她有提到 3.10 内核没有这个问题,于是看了下 3.10 内核的代码,发现它在 xfrm_dump_sa 中根本不会去解析 nlattr,自然就不会有这个问题了。
3.10 内核中 xfrm_dump_sa 函数代码如下:
static int xfrm_dump_sa(struct sk_buff *skb, struct netlink_callback *cb)
{
struct net *net = sock_net(skb->sk);
struct xfrm_state_walk *walk = (struct xfrm_state_walk *) &cb->args[1];
struct xfrm_dump_info info;
BUILD_BUG_ON(sizeof(struct xfrm_state_walk) >
sizeof(cb->args) - sizeof(cb->args[0]));
info.in_skb = cb->skb;
info.out_skb = skb;
info.nlmsg_seq = cb->nlh->nlmsg_seq;
info.nlmsg_flags = NLM_F_MULTI;
if (!cb->args[0]) {
cb->args[0] = 1;
xfrm_state_walk_init(walk, 0);
}
(void) xfrm_state_walk(net, walk, dump_one_state, &info);
return skb->len;
}
好了!圆满收工!
总结
本文描述了一个看似简单的问题,其实也只是看似简单而已。这个问题是在一个多月前解决的,本文的素材也是在一个多月前写的,整理过程中发现又踩了之前遇到的一个坑,说明在记录素材的时候漏掉了一些关键内容,这一点需要注意。
在解决这个 bug 前,我对 netlink 几乎一无所知,为了解决这个 bug,我研究了下 netlink 的相关原理,扩展了知识的广度,将问题拉到自己擅长的领域中,最终解决了这个问题。问题本身并不太重要,重要的是它蕴含的引领人思考的契机,抓住了这个契机就能获得更大的成长!