kprobe分析内核kworker占用CPU 100%问题总结

kprobe分析内核kworker占用CPU 100%问题总结kprobe分析内核kworker占用CPU100%问题总结CreatebyBillow.Jen,2020.3.8前言[引用]有的工程师在线上出问题的时候,非常慌乱,会去胡乱猜测可能的原因,但又缺乏任何证据去支持或者否证他的猜测与假设。他甚至会在线上反复地试错,反复地折腾,搞得一团乱麻,毫无头绪,让自己和身边的同事都很痛苦,白白浪费了宝贵的排错时间。但是当我们有了动态追踪技术之后,排…

大家好,又见面了,我是你们的朋友全栈君。如果您正在找激活码,请点击查看最新教程,关注关注公众号 “全栈程序员社区” 获取激活教程,可能之前旧版本教程已经失效.最新Idea2022.1教程亲测有效,一键激活。

Jetbrains全系列IDE稳定放心使用

kprobe分析内核kworker占用CPU 100%问题总结

Create by Billow.Jen,2020.3.8

前言

利用linux kernel 动态追踪技术,排查问题本身就可能会变成一个非常有趣的过程,让我们遇到线上的诡异问题就感到兴奋,就仿佛好不容易又逮着机会,可以去解一道迷人的谜题。


一、系统问题说明

背景说明

负载均衡模块独立主机部署,运行BIRD、quagga、nftbl、contiv、ovs等进程,实现网络NAT功能。
内核版本:centos7-4.19.8

问题描述

在调用nftlb写入nft规则的过程中,发现部分主机性能低(因操作系统为centos且内核进行了升级,红帽服务不支持。)
过程如下:
1、执行命令:

time ip netns exec vpc067871207-lbalance curl -H "Key: spidernet" -X POST http://127.0.0.1:06787/farms --data '{"farms":[{"name":"b1","family":"ipv4","virtual-addr":"XX.XX.XX.XX","virtual-ports":"1001","mode":"snat","protocol":"tcp","scheduler":"weight","state":"up","backends":[{"name":"bck01","ip-addr":"192.168.0.1","port":"80","weight":"5","mark":"0x00000001","priority":"1","state":"up"}]}]}'

该命令正常应该在0.2ms内完成,但在部分主机上耗时到2、3s。
2、利用strace命令跟踪:

strace -tt -T -v -f  -s 1024 -p 2727846

发现耗时在sendmsg(AF_NETLINK…)函数上,有长有短,短的在几十us,但有四个长在0.5s左右的sendmsg,如:
[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-eAfNbx6U-1584208688223)(en-resource://database/1982:1)]
3、继续分析主机进程,发现一个进程kworker一直100%
[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-QxeEl9NA-1584208688224)(en-resource://database/1984:1)]
4、观察主机性能,nmon如下:[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-ewVOFHNl-1584208688225)(en-resource://database/1990:1)]
此时主机内存、cpu、网络、存储都很空闲,但中断比正常主机高1~2倍。
5、用perf工具查看kworker耗时
[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-CEyDfmjJ-1584208688226)(en-resource://database/1988:1)]
6、网卡中断,经确认(/proc/interrupts)网卡中断分布在每个cpu上,网络中断均衡
7、继续ftrace,分析事件:

cd /sys/kernel/debug/tracing
echo wakeup_rt > current_tracer
echo 0 > options/function-trace
echo 1 > events/enable
echo 1 > tracing_on
echo 0 > tracing_max_latency
chrt -f 5 sleep 1
echo 0 > tracing_on
cat trace

结果没有针对性,不具备进一步分析条件。初步问题分析完了,下步进行内核态深度分析。

小结

内核该kworker进程的性能影响了work处理效率,导致内核较慢,响应sendmsg的work延迟,导致curl耗时长。

二、内核性能分析、跟踪工具简述

ftrace、kprobe、perf、operf/oprofile、systemtap都是跟踪内核的好工具,但有所区别。
Linux内核提供的基础设施:

  1. tarcepoints => 静态探测点
  2. kprobe => 内核态动态探测点(kernel/kprobe.c, example:sample/kprobe)
  3. uprobe => 用户态动态探测点(kernel/events/uprobe.c)
  • ftrace是后面工具的基础,但使用比较繁琐
  • perf可图形化展示函数耗时,但不能自定义跟踪调试。
  • operf/oprofile依赖vmlinux,并且得带有debug信息。
  • systemtap依赖太多,kernel-debuginfo、内核编译参数等等,生产环境基本不可用。

kprobe作为轻量级内核调试工具,在诊断内核bug时有着先天独厚的优势,相关其他工具,kprobe有如下优点:
1、不用更新内核
2、可以以模块的形式加载进内核,用完后直接卸载即可,不会对内核造成污染
3、动态跟踪,自由构造,灵巧轻便。

经过大量实验探索,依赖少并可深入自定义的,kprobe胜出。

三、利用kprobe分析kworker行为

调试源码见附录,kprobe使用及原理自行学习,本文不做基础介绍,重点在思路、步骤,主要展示方法论的形成过程。
准备工作,说明下kprobe的参数示例:

    struct file *file = (struct file *)regs->di;
    //因为x86的参数传递规则是di,si,dx,cx,r8,r9,所以di就是vfs_write的第一个参数。arm默认是r0,r1,r2,r3,相应的取r0

看看kworker在做什么:

[root@04b280305 kprobe]# cat /proc/352560/stack
[<0>] insert_work+0x6e/0xa0
[<0>] __queue_work+0x131/0x3b0
[<0>] queue_work_on+0x28/0x40
[<0>] rht_deferred_worker+0x8b/0x3e0
[<0>] process_one_work+0x179/0x390
[<0>] worker_thread+0x4f/0x3e0
[<0>] kthread+0x105/0x140
[<0>] ret_from_fork+0x35/0x40
[<0>] 0xffffffffffffffff

可知,rht_deferred_worker是特定任务,需要重点分析。
写kprobe代码对rht_deferred_worker函数加探针,分析rht_deferred_worker事件(/var/log/messages,当时dmesg没记录被覆盖了,所以从messages中直接看):


[root@04b280305 kprobe]# grep rht_deferred_worker /var/log/messages |tail
Mar  9 21:35:14 04b280305 kernel: <rht_deferred_worker> pre_handler: 813f99c0
Mar  9 21:35:14 04b280305 kernel: <rht_deferred_worker> post_handler: 813f99c0
Mar  9 21:35:14 04b280305 kernel: <rht_deferred_worker> pre_handler: 813f99c0
Mar  9 21:35:14 04b280305 kernel: <rht_deferred_worker> post_handler: 813f99c0
Mar  9 21:35:14 04b280305 kernel: <rht_deferred_worker> pre_handler: 813f99c0

看看813f99c0是什么work:

[root@04b280305 kprobe]# cat /proc/kallsyms |grep 813f99c0
ffffffff813f99c0 t rht_deferred_worker

分析rht_deferred_worker源码,得知在重新分配或者收缩失败时,会触发插入work:rht_deferred_worker,此处是关键。

static void rht_deferred_worker(struct work_struct *work)
{
    struct rhashtable *ht;
    struct bucket_table *tbl;
    int err = 0;
    ht = container_of(work, struct rhashtable, run_work);
    mutex_lock(&ht->mutex);
    tbl = rht_dereference(ht->tbl, ht);
    tbl = rhashtable_last_table(ht, tbl);
    if (rht_grow_above_75(ht, tbl))
        err = rhashtable_rehash_alloc(ht, tbl, tbl->size * 2);
    else if (ht->p.automatic_shrinking && rht_shrink_below_30(ht, tbl))
        err = rhashtable_shrink(ht);
    else if (tbl->nest)
        err = rhashtable_rehash_alloc(ht, tbl, tbl->size);
    if (!err)//出错时,返回非0,执行不到
        err = rhashtable_rehash_table(ht);
    mutex_unlock(&ht->mutex);
    if (err)
        schedule_work(&ht->run_work);
        /*上行是关键,造成了死循环*/
}

确认下是alloc失败还是shrink失败:
写kprobe代码对 rhashtable_rehash_alloc函数加探针,查看结果:

Mar  9 22:50:03 04b280305 kernel: Planted kprobe at rhashtable_rehash_alloc+0x0/0x50
Mar  9 22:50:07 04b280305 kernel: kprobe at rhashtable_rehash_alloc+0x0/0x50 unregistered

只执行了一次,说明不是alloc的问题,继续分析shrink,rhashtable_shrink不是系统导出符号,不能kprobe,看下源码:

static int rhashtable_shrink(struct rhashtable *ht)
{
    struct bucket_table *old_tbl = rht_dereference(ht->tbl, ht);
    unsigned int nelems = atomic_read(&ht->nelems);
    unsigned int size = 0;
    if (nelems)
        size = roundup_pow_of_two(nelems * 3 / 2);
    if (size < ht->p.min_size)
        size = ht->p.min_size;
    if (old_tbl->size <= size)
        return 0;
    if (rht_dereference(old_tbl->future_tbl, ht))
        return -EEXIST;
    return rhashtable_rehash_alloc(ht, old_tbl, size);
}

写了个test_shirnk的探测函数,一安装服务器崩了…
去看看高版本内核,从5.1版本解决了此问题:

static void rht_deferred_worker(struct work_struct *work)
{
	struct rhashtable *ht;
	struct bucket_table *tbl;
	int err = 0;
	ht = container_of(work, struct rhashtable, run_work);
	mutex_lock(&ht->mutex);

	tbl = rht_dereference(ht->tbl, ht);
	tbl = rhashtable_last_table(ht, tbl);

    if (rht_grow_above_75(ht, tbl))
		err = rhashtable_rehash_alloc(ht, tbl, tbl->size * 2);
    else if (ht->p.automatic_shrinking && rht_shrink_below_30(ht, tbl))
    	err = rhashtable_shrink(ht);
	else if (tbl->nest)
		err = rhashtable_rehash_alloc(ht, tbl, tbl->size);
  
    /*此块代码,修复了BUG*/  
	if (!err || err == -EEXIST) {
		int nerr;
		nerr = rhashtable_rehash_table(ht);
		err = err ?: nerr;
	}

mutex_unlock(&ht->mutex);
if (err)
		schedule_work(&ht->run_work);
}

BUG说明:
rhashtable: Still do rehash when we get EEXIST
As it stands if a shrink is delayed because of an outstanding
rehash, we will go into a rescheduling loop without ever doing
the rehash.

This patch fixes this by still carrying out the rehash and then
rescheduling so that we can shrink after the completion of the
rehash should it still be necessary.

The return value of EEXIST captures this case and other cases
(e.g., another thread expanded/rehashed the table at the same
time) where we should still proceed with the rehash.

Fixes: da20420 (“rhashtable: Add nested tables”)

英文不知所云,我自己的理解是:
哈希表收缩时(rhashtable_shrink),会去判断该表是否被间接引用,如果存在则不缩容,返回-EEXIST。
v5.1之前的版本,该返回值会触发重新生成一个rht_deferred_worker的work,这样就形成了递归,如果间接引用一直存在则形成死循环,导致CPU 100%。
v5.1之后的版本,该返回值会触发重新哈希,若此期间间接引用还存在则返回0,不再会触发产生新rht_deferred_worker的work,以此来解决BUG。

探测完注意尽快卸载驱动,影响性能,会打印大量日志,并且可能会把服务器搞崩

四、打patch,修复BUG

从https://www.kernel.org下载patch文件,升级解决。

$ diff -up linux-4.19.8-1/lib/rhashtable.c linux-4.19.8-2/lib/rhashtable.c > rht_patch
$ patch -p1 < rht_patch

五、总结回顾

遇到操作系统性能或功能问题,可采用如下步骤定位:

  1. 通过top工具,确定问题进程
  2. 使用strace分析系统调用耗时或阻塞情况
  3. 使用nmon工具,查看系统中断、负载、cpu、内存、IO、net等情况,分析是否正常,初步判断可能存在的问题
  4. 使用perf工具,分析函数栈性能
  5. 查询资料、阅读相关源码,初步判断位置
  6. 若问题可在测试环境复现,使用systemtap工具进行跟踪分析
  7. 若问题在生产环境上可遇不可求,使用kprobe工具进行动态分析
  8. 定位问题后,查看高版本是否修复
  9. 若修复则通过kernel官网patch升级;未修复时,若自己可修,则自改自测,否则git上提交bug

内核调试博大精深,本文非常有局限性,具体问题还得具体分析

推荐几个链接:
https://zhuanlan.zhihu.com/p/71437161
https://www.csdndoc.com/article/8015807
https://blog.csdn.net/yuntongsf/article/details/78707576

附kprobe探测代码

Talk is cheap,show you the code!
kprobe_kworker.c

#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/kprobes.h>

#define MAX_SYMBOL_LEN    64
static char symbol[MAX_SYMBOL_LEN] = "rht_deferred_worker";
//rht_deferred_worker可根据需要改成要探测的函数
module_param_string(symbol, symbol, sizeof(symbol), 0644);

/* For each probe you need to allocate a kprobe structure */
static struct kprobe kp = {
    .symbol_name    = symbol,
};

/* kprobe pre_handler: called just before the probed instruction is executed */
static int handler_pre(struct kprobe *p, struct pt_regs *regs)
{
#ifdef CONFIG_X86
pr_info("<%s>,pid = %ld\n",current->comm, current->pid);
struct work_struct *work = (struct work_struct *)regs->di;
pr_info("<%s> pre_handler: %x\n",p->symbol_name,work->func);

#endif
#ifdef CONFIG_ARM64
    pr_info("<%s> pre_handler: p->addr = %pF, pc = 0x%lx,"
            " pstate = 0x%lx\n",
        p->symbol_name, p->addr, (long)regs->pc, (long)regs->pstate);
#endif

    /* A dump_stack() here will give a stack backtrace */
    return 0;
}

/* kprobe post_handler: called after the probed instruction is executed */
static void handler_post(struct kprobe *p, struct pt_regs *regs,
                unsigned long flags)
{
#ifdef CONFIG_X86
struct work_struct *work = (struct work_struct *)regs->di;
pr_info("<%s> post_handler: %x\n",p->symbol_name,work->func);

//    pr_info("<%s> post_handler: p->addr = %pF, flags = 0x%lx\n",
 //       p->symbol_name, p->addr, regs->flags);
#endif
#ifdef CONFIG_ARM64
    pr_info("<%s> post_handler: p->addr = %pF, pstate = 0x%lx\n",
        p->symbol_name, p->addr, (long)regs->pstate);
#endif
}

/*
 * fault_handler: this is called if an exception is generated for any
 * instruction within the pre- or post-handler, or when Kprobes
 * single-steps the probed instruction.
 */
static int handler_fault(struct kprobe *p, struct pt_regs *regs, int trapnr)
{
    pr_info("fault_handler: p->addr = %pF, trap #%dn", p->addr, trapnr);
    /* Return 0 because we don't handle the fault. */
    return 0;
}

static int __init kprobe_init(void)
{
    int ret;
    kp.pre_handler = handler_pre;
    kp.post_handler = handler_post;
    kp.fault_handler = handler_fault;

    ret = register_kprobe(&kp);
    if (ret < 0) {
        pr_err("register_kprobe failed, returned %d\n", ret);
        return ret;
    }
    pr_info("Planted kprobe at %pF\n", kp.addr);
    return 0;
}

static void __exit kprobe_exit(void)
{
    unregister_kprobe(&kp);
    pr_info("kprobe at %pF unregistered\n", kp.addr);
}

module_init(kprobe_init)
module_exit(kprobe_exit)
MODULE_LICENSE("GPL");

Makefile

obj-m := kprobe_kworker.o
KBUILD_EXTRA_SYMBOLS:=/mod_a/Module.symvers

CROSS_COMPILE=''

KDIR := /lib/modules/4.19.8-1.el7.elrepo.x86_64/build
all:
        make -C $(KDIR) M=$(PWD) modules
clean:
        rm -f *.ko *.o *.mod.o *.mod.c .*.cmd *.symvers  modul*

执行命令

make
insmod kprobe_kworker.ko
rmmod kprobe_kworker.ko

dmesg查看结果

dmesg 
版权声明:本文内容由互联网用户自发贡献,该文观点仅代表作者本人。本站仅提供信息存储空间服务,不拥有所有权,不承担相关法律责任。如发现本站有涉嫌侵权/违法违规的内容, 请发送邮件至 举报,一经查实,本站将立刻删除。

发布者:全栈程序员-用户IM,转载请注明出处:https://javaforall.cn/189944.html原文链接:https://javaforall.cn

【正版授权,激活自己账号】: Jetbrains全家桶Ide使用,1年售后保障,每天仅需1毛

【官方授权 正版激活】: 官方授权 正版激活 支持Jetbrains家族下所有IDE 使用个人JB账号...

(2)


相关推荐

  • centos 安装 python3_python加密解密库

    centos 安装 python3_python加密解密库今天使用pip3installvirtualenv命令安装virtualenv的时候一直安装不了,

  • 正态分布方差推导_均匀分布的期望和方差公式

    正态分布方差推导_均匀分布的期望和方差公式概论:一维随机变量期望与方差二维随机变量期望与方差协方差1.一维随机变量期望与方差:公式:离散型:E(X)=∑i=1->nXiPiY=g(x)E(Y)=∑i=1->ng(x)Pi连续型:E(X)=∫-∞->+∞xf(x)dxY=g(x)E(Y)=∫-∞->+∞g(x)f(x)dx方差:D(x)=E(x²)-E²(x)标准差:根号下的方差常用分布的数学期望和方差:0~1分布…

  • 总结:相关滤波器(Correlation Filters)

    总结:相关滤波器(Correlation Filters)本文是对相关滤波器(CorrelationFilters)相关paper的理解和总结,不过对于我来说,KCF实在不好理解,感觉好多地方理解的不彻底,错误之处还请指出,共同进步。

  • 一步一步学习androidNDK编程(hello world)

    一步一步学习androidNDK编程(hello world)上一篇博客,已经搭建好了windows下的linux环境(cygwine),这次我们试着写一个helloworld。首先需要去android的官网下载android-ndk压缩包,之后解压,进入解压后的目录,我们发现有一个ndk-build的脚本文件,这个脚本文件就是我们用交叉编译的文件。我们通过 “./ndk-build” 来运行该命令,如下图:    因为目前我们没有

  • Java开发经典实战!java编程培训学校排名

    Java开发经典实战!java编程培训学校排名GC概述垃圾收集(GarbageCollection)通常被称为“GC”,由虚拟机“自动化”完成垃圾回收工作。思考一个问题,既然GC会自动回收,开发人员为什么要学习GC和内存分配呢?为了能够配置上面的参数配置?参数配置又是为了什么?“当需要排查各种内存溢出,内存泄露问题时,当垃圾成为系统达到更高并发量的瓶颈时,我们就需要对GC的自动回收实施必要的监控和调节。”JVM中程序计数器、虚拟机栈、本地方法栈3个区域随线程而生随线程而灭。栈帧随着方法的进入和退出做入栈和出栈操作,实现了自动的内存清理。它们的

  • navicat for MySQL版本15激活码_最新在线免费激活2022.02.02

    (navicat for MySQL版本15激活码)JetBrains旗下有多款编译器工具(如:IntelliJ、WebStorm、PyCharm等)在各编程领域几乎都占据了垄断地位。建立在开源IntelliJ平台之上,过去15年以来,JetBrains一直在不断发展和完善这个平台。这个平台可以针对您的开发工作流进行微调并且能够提供…

发表回复

您的电子邮箱地址不会被公开。

关注全栈程序员社区公众号