[linux][perf]list过长导致CPU消耗过高的问题分析
[linux][perf]list过长导致CPU消耗过高的问题分析
前言
某机器上网络出现时断时续的问题，网络的同事发现ovs进程的CPU消耗很高，硬件offload的规则下发卡住的问题。即通过netlink向内核发送消息卡住。
分析
perf分析热点函数
可见，CPU的主要消耗是在__tcf_chain_get函数和__mutex_lock上。
为什么锁消耗那么高
rtnetlink_rcv_msg函数（去掉参数检查等等，保留关键逻辑），通过这段逻辑我们可以知道，在执行每个netlink命令的时候，都会先执行锁操作，在执行具体的回调函数（即link->doit），再解锁的过程。
如果其中某一个回调函数执行时间过长，就会长时间占用锁，造成其他的link->doit回调函数block住更长的时间，那么锁的消耗也会更高。
再结合其他的代码逻辑可以发现，__tcf_chain_get函数就刚好在某一个回调函数的路径上。
Annotate __tcf_chain_get
分析上面的热点函数__tcf_chain_get
__tcf_chain_get比较长，理论上来说，一个cmp指令只要一个cycle即可，那么在这里为什么一个cmp指令使用了99.13%的CPU时间呢？可以从汇编中看到，需要取rax偏移0x18的地址上数值和esi进行比较。这里存在一次读取内存的操作，如果是链表的话，前后两个链表元素未必在内存上相邻，容易造成CPU的cache miss。
计算热点代码的路径
ffffffff8161ab40+1d= ffffffff8161ab5d
所以执行addr2line -e /usr/lib/debug/vmlinux-4.19 -a 0xffffffff8161ab5d
0xffffffff8161ab5d
可以得到/linux/net/sched/cls_api.c:268
可以看到268行是对chain->index和chain_index进行对比。
继续看tcf_chain结构体
index结构在tcf_chain结构体中偏移0x20，为什么反汇编的代码在0x18上？
结合上下文我们可以看到，使用list来遍历：
chain的地址是在list的地址-0x8，index的地址是在chain+0x20,那么index的地址相对于list的地址就是+0x18，计算chain的过程都被编译器优化掉了，只需要使用list的地址+0x18即可完成代码逻辑中的遍历过程。
综上，可以证实，__tcf_chain_get消耗过高的原因是：遍历list的过程中遇到了比较多的cache miss;遍历了太多的链表元素的导致的。
计算链表的长度
基于kprobe实现kmod，来dump出来链表的长度。
#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/kprobes.h>
#include <linux/uaccess.h>
#include <net/sch_generic.h>
static long filter_count(struct tcf_chain *chain)
{
struct tcf_proto *tp;
long count = 0;
for (tp = rtnl_dereference(chain->filter_chain);
tp; tp = rtnl_dereference(tp->next)) {
count++;
}
return count;
}
static int kp_do_tcf_handler(struct kprobe *p, struct pt_regs *regs)
{
struct tcf_block *block = (void __user *)regs->di;
struct tcf_chain *chain;
long count = 0;
list_for_each_entry(chain, &block->chain_list, list) {
count++;
}
printk("[always]count = %ld\n", count);
return 0;
}
static struct kprobe kp = {
.symbol_name = "__tcf_chain_get",
.pre_handler = kp_do_tcf_handler,
};
static int __init kprobe_init(void)
{
int ret;
ret = register_kprobe(&kp);
if (ret < 0) {
pr_err("register_kprobe failed, returned %d\n", ret);
return ret;
}
pr_info("[probe-tcf]Planted kprobe at %p\n", kp.addr);
return 0;
}
static void __exit kprobe_exit(void)
{
unregister_kprobe(&kp);
pr_info("[probe-unregistered]kprobe at %p unregistered\n", kp.addr);
}
module_init(kprobe_init)
module_exit(kprobe_exit)
MODULE_LICENSE("GPL");
MODULE_AUTHOR("pizhenwei pizhenwei@bytedance.com");得到dump的结果
可以知道list的元素多少不等，有的不到100，有的到达了接近25W个元素。由此可以论证上面的猜测，链表元素太多。
找到哪个dev的链表元素过多
再进一步完善kprobe的逻辑，
#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/kprobes.h>
#include <linux/uaccess.h>
#include <net/sch_generic.h>
static long filter_count(struct tcf_chain *chain)
{
struct tcf_proto *tp;
long count = 0;
for (tp = rtnl_dereference(chain->filter_chain);
tp; tp = rtnl_dereference(tp->next)) {
count++;
}
return count;
}
static int kp_do_tcf_handler(struct kprobe *p, struct pt_regs *regs)
{
struct tcf_block *block = (void __user *)regs->di;
struct tcf_chain *chain;
long count = 0, tps;
long tpc[4] = {0}; //绘制filter count分布图
long ref[4] = {0}; //绘制refcnt的分布图
long action_ref[4] = {0}; //绘制action_refcnt的分布图
long actrefonly = 0; //过滤出来action_refcnt等于refcnt的分布图
list_for_each_entry(chain, &block->chain_list, list) {
count++;
tps = filter_count(chain);
if (tps == 0)
tpc[0]++;
else if (tps > 0 && tps <= 1)
tpc[1]++;
else if (tps > 1 && tps <= 2)
tpc[2]++;
else
tpc[3]++;
if (chain->refcnt == 0)
ref[0]++;
else if (chain->refcnt > 0 && chain->refcnt <= 1)
ref[1]++;
else if (chain->refcnt > 1 && chain->refcnt <= 2)
ref[2]++;
else
ref[3]++;
if (chain->action_refcnt == 0)
action_ref[0]++;
else if (chain->action_refcnt > 0 && chain->action_refcnt <= 1)
action_ref[1]++;
else if (chain->action_refcnt > 1 && chain->action_refcnt <= 2)
action_ref[2]++;
else
action_ref[3]++;
if (chain->action_refcnt == chain->refcnt)
actrefonly++;
}
#if 1
if (count < 1000) //过滤链表元素少于1000的情况
return 0;
#endif
printk("[always]DEV %s\n", block→q→dev_queue→dev→name); //打印出来异常的netdev的名字
printk("[always][0]count = %ld\t", tpc[0]);
printk("[always][1]count = %ld\t", tpc[1]);
printk("[always][2]count = %ld\t", tpc[2]);
printk("[always][4]count = %ld\n", tpc[3]);
printk("[always][0]action_ref = %ld\t", action_ref[0]);
printk("[always][1]action_ref = %ld\t", action_ref[1]);
printk("[always][2]action_ref = %ld\t", action_ref[2]);
printk("[always][4]action_ref = %ld\n", action_ref[3]);
printk("[always][0]ref = %ld\t", ref[0]);
printk("[always][1]ref = %ld\t", ref[1]);
printk("[always][2]ref = %ld\t", ref[2]);
printk("[always][4]ref = %ld\n", ref[3]);
printk("[always]actrefonly = %ld\n", actrefonly);
return 0;
}
static struct kprobe kp = {
.symbol_name = "__tcf_chain_get",
.pre_handler = kp_do_tcf_handler,
};
static int __init kprobe_init(void)
{
int ret;
ret = register_kprobe(&kp);
if (ret < 0) {
pr_err("register_kprobe failed, returned %d\n", ret);
return ret;
}
pr_info("[probe-tcf]Planted kprobe at %p\n", kp.addr);
return 0;
}
static void __exit kprobe_exit(void)
{
unregister_kprobe(&kp);
pr_info("[probe-unregistered]kprobe at %p unregistered\n", kp.addr);
}
module_init(kprobe_init)
module_exit(kprobe_exit)
MODULE_LICENSE("GPL");
MODULE_AUTHOR("pizhenwei pizhenwei@bytedance.com");得到dump出来的结果
至此，我们已经找到了vxlan_sys_4789上的元素比较多。
后面，经过网络同事的验证（通过tc命令dump出来结果），vxlan_sys_4789上的chain确实过多。脚本删除空的chain后，ovs的cpu消耗下降到10%以内，网络恢复正常。