Kernel space lock contention配置及其使用

本文详细介绍Linux内核中锁调试的配置与使用,包括lock contention的跟踪、lock trace event的捕获及proc节点信息的解析,为解决锁竞争和死锁问题提供有效手段。
概述

本文涉及到的内容如下:

  1. kernel lock相关debug方式,比如lock耗时,拿不到lock,lock依赖等等
  2. trace的使用
1.开启lock contenttion涉及到的config配置
config LOCKDEP  
        bool  
        depends on DEBUG_KERNEL && TRACE_IRQFLAGS_SUPPORT && STACKTRACE_SUPPORT && LOCKDEP_SUPPORT  
        select STACKTRACE  
        select FRAME_POINTER if !MIPS && !PPC && !ARM_UNWIND && !S390 && !MICROBLAZE && !ARC && !SCORE && !X86  
        select KALLSYMS  
        select KALLSYMS_ALL  
  
config LOCKDEP_SMALL  
        bool  
  
config LOCK_STAT  
        bool "Lock usage statistics"  
        depends on DEBUG_KERNEL && TRACE_IRQFLAGS_SUPPORT && STACKTRACE_SUPPORT && LOCKDEP_SUPPORT  
        select LOCKDEP  
        select DEBUG_SPINLOCK  
        select DEBUG_MUTEXES  
        select DEBUG_RT_MUTEXES if RT_MUTEXES  
        select DEBUG_LOCK_ALLOC  
        default n  
        help  
         This feature enables tracking lock contention points  
  
         For more details, see Documentation/locking/lockstat.txt  
  
         This also enables lock events required by "perf lock",  
         subcommand of perf.  
         If you want to use "perf lock", you also need to turn on  
         CONFIG_EVENT_TRACING.  
  
         CONFIG_LOCK_STAT defines "contended" and "acquired" lock events.  
         (CONFIG_LOCKDEP defines "acquire" and "release" events.)  

上面的config默认是关闭状态。

2 menuconfig开启config配置

kernel hacking —> Lock Debugging (spinlock, mutexs, etc…) —>进入之后勾选
Lock Debugging: detect incorrect freeing of live locks 和Lcok usage statistics,就会把依赖项自动勾选.
在这里插入图片描述

保存退出之后,可以查看kernel下面新产生的config diff文件:

# Lock Debugging (spinlocks, mutexes, etc...)  
 #  
-# CONFIG_DEBUG_RT_MUTEXES is not set  
-# CONFIG_DEBUG_SPINLOCK is not set  
-# CONFIG_DEBUG_MUTEXES is not set  
+CONFIG_DEBUG_RT_MUTEXES=y  
+CONFIG_DEBUG_SPINLOCK=y  
+CONFIG_DEBUG_MUTEXES=y  
 # CONFIG_DEBUG_WW_MUTEX_SLOWPATH is not set  
-# CONFIG_DEBUG_LOCK_ALLOC is not set  
+CONFIG_DEBUG_LOCK_ALLOC=y  
 # CONFIG_PROVE_LOCKING is not set  
-# CONFIG_LOCK_STAT is not set  
+CONFIG_LOCKDEP=y  
+CONFIG_LOCK_STAT=y  
+# CONFIG_DEBUG_LOCKDEP is not set  
 # CONFIG_DEBUG_ATOMIC_SLEEP is not set  
 # CONFIG_DEBUG_LOCKING_API_SELFTESTS is not set  
 # CONFIG_LOCK_TORTURE_TEST is not set  

这样开启lock trace event了.。编译boot并刷机即可!

3 确定是否开启trace lock content feature

上面步骤二中开启之后,在adb shell里面多了如下几个接口:

  1. 增加了lock trace event, 有四个lock trace event,具体做什么使用,下面在详细讲解
    在这里插入图片描述
  2. 增加了lock的统计信息, 节点信息实现源码kernel/locking/lockdep_proc.c文件中:
    ● lock_stat: 统计各种类型lock的时延
    ● lockdep: 表示锁的的深度,即一个lock里面调用了多少个lock,并将这些lock的调用全部显示出来
    ● lockdep_stats: 即锁深度里面包含了哪些lock以及频次
    ● locks:锁的状态,这个实现在fs/locks.c文件里面

在这里插入图片描述

4 如何使用lock trace event和proc node信息
4.1 lock trace event

从第三部分可以知道,lock trace event包含四个event,分别讲解如下:
四个event定义在include/trace/event/lock.h里面, 使用在kernel/locking/lockdep.c文件,

  1. lock_acquire: 获取lock,比如mutex lock ,rcu read lock 或者spinlock等等lock
  2. lock_acquired: 表示已经获取lock了
  3. lock_release: lock释放的event
  4. lock_contended: lock被谁hold了

那么如何抓取lock相关的trace event呢?
可以使用下面的脚本抓取(必须添加lock event ),即正常的抓取trace 命令:

echo 40000 > buffer_size_kb && echo irq sched_switch sched_wakeup sched_waking cpu_frequency cpu_idle lock > set_event && cat set_event && echo > trace  && echo 1 > tracing_on && sleep 10 && echo 0 > tracing_on && cat trace > /data/trace.txt   

脚本执行完毕之后, pull出data目录下的trace.txt文件,vim打开即可看到下面类似的信息:

┊   ┊  sleep-2875  [004] d.s2   748.861607: sched_waking: comm=rcu_sched pid=9 prio=120 target_cpu=000  
┊   ┊  sleep-2875  [004] d.s3   748.861608: lock_acquire: 00000000d4eff177 &rq->lock  
┊   ┊  sleep-2875  [004] d.s3   748.861609: lock_contended: 00000000d4eff177 &rq->lock  
┊   ┊  sleep-2875  [004] d.s3   748.861662: lock_acquired: 00000000d4eff177 &rq->lock  
┊   ┊  sleep-2875  [004] d.s3   748.861663: lock_acquire: 000000000ff04d65 read tk_core.seq  
┊   ┊  sleep-2875  [004] d.s3   748.861664: lock_release: 000000000ff04d65 tk_core.seq  
┊   ┊  sleep-2875  [004] d.s3   748.861666: lock_acquire: 00000000cc726398 read rcu_read_lock  
┊   ┊  sleep-2875  [004] d.s3   748.861667: lock_release: 00000000cc726398 rcu_read_lock  
┊   ┊  sleep-2875  [004] d.s3   748.861668: lock_release: 00000000d4eff177 &rq->lock  
┊   ┊  sleep-2875  [004] d.s2   748.861669: lock_acquire: 00000000cc726398 read rcu_read_lock  
┊   ┊  sleep-2875  [004] d.s2   748.861670: lock_acquire: 00000000cc726398 read rcu_read_lock  
┊   ┊  sleep-2875  [004] d.s2   748.861671: lock_release: 00000000cc726398 rcu_read_lock  
┊   ┊  sleep-2875  [004] d.s2   748.861672: lock_acquire: 00000000cc726398 read rcu_read_lock  
┊   ┊  sleep-2875  [004] d.s2   748.861673: lock_release: 00000000cc726398 rcu_read_lock  
┊   ┊  sleep-2875  [004] d.s2   748.861674: lock_acquire: 00000000cc726398 read rcu_read_lock  
┊   ┊  sleep-2875  [004] d.s2   748.861675: lock_release: 00000000cc726398 rcu_read_lock  
┊   ┊  sleep-2875  [004] d.s2   748.861676: lock_acquire: 00000000cc726398 read rcu_read_lock  
┊   ┊  sleep-2875  [004] d.s2   748.861677: lock_release: 00000000cc726398 rcu_read_lock  
┊   ┊  sleep-2875  [004] d.s2   748.861678: lock_acquire: 00000000cc726398 read rcu_read_lock  
┊   ┊  sleep-2875  [004] d.s2   748.861679: lock_release: 00000000cc726
那中间怎么漏了这么多时间,不是有问题吗? yuanhaixiong@yuanhaixiong-PC:~/machine/Log/#K1-8G-KASAN版本monkey异常停止0806/debuglogger/mobilelog$ ls APLog_2025_0806_173133__3 APLog_2025_0807_065857__5 APLog_2025_0807_080020__7 APLog_2025_0807_112654__9 APLog_2025_0807_130603__11 APLog_2025_0807_134712__13 APLog_2025_0807_153818__15 APLog_2025_0807_042752__4 APLog_2025_0807_073742__6 APLog_2025_0807_111445__8 APLog_2025_0807_121702__10 APLog_2025_0807_134043__12 APLog_2025_0807_150142__14 file_tree.txt yuanhaixiong@yuanhaixiong-PC:~/machine/Log/#K1-8G-KASAN版本monkey异常停止0806/debuglogger/mobilelog$ tail APLog_2025_0807_150142__14/ atf_log_8__2025_0807_151258 crash_log_6__2025_0807_151258 main_log_1__2025_0807_151029 pl_lk sspm_log_12__2025_0807_151258 bootprof events_log_4__2025_0807_151258 main_log_2__2025_0807_151258 properties sys_log_5__2025_0807_151258 bsp_log_10__2025_0807_151258 gz_log_9__2025_0807_151258 mblog_history radio_log_3__2025_0807_151258 connsys_picus_log_14__2025_0807_151258 kernel_log_7__2025_0807_151258 mcupm_log_13__2025_0807_151258 scp_log_11__2025_0807_151258 yuanhaixiong@yuanhaixiong-PC:~/machine/Log/#K1-8G-KASAN版本monkey异常停止0806/debuglogger/mobilelog$ tail APLog_2025_0807_150142__14/main_log_2__2025_0807_151258 08-07 15:12:58.266055 1388 1388 D BufferQueueConsumer: [](id:56c00000a64,api:0,p:-1,c:1388) connect: controlledByApp=false 08-07 15:12:58.267110 1388 1388 D BLASTBufferQueue: [VRI[0 fl=}]#2576](f:0,a:0) constructor() 08-07 15:12:58.267446 1388 1388 D BLASTBufferQueue: [VRI[0 fl=}]#2576](f:0,a:0) update width=1080 height=2412 format=-2 mTransformHint=0 08-07 15:12:58.268282 1478 1671 I PowerHalWrapper: amsBoostNotify pid:24443,activity:com.android.searchlauncher.SearchLauncher, package:com.android.launcher3, mProcessCreatePackcom.google.android.apps.safetyhub 08-07 15:12:58.268479 1478 1671 I PowerHalWrapper: state: 1 08-07 15:12:58.269953 1478 1671 I mtkpower_client: [PowerHal_Wrap_notifyAppState] com.android.launcher3/com.android.searchlauncher.SearchLauncher pid=24443 activityId:211372178 state:1 08-07 15:12:58.270392 1478 1671 I mtkpower_client: [Legacy][PowerHal_Wrap_notifyAppState] com.android.launcher3/com.android.searchlauncher.SearchLauncher pid=24443 state:211372178 08-07 15:12:58.271280 6355 6355 I Monkey : :Sending Touch (ACTION_DOWN): 0:(638.0,2182.0) 08-07 15:12:58.271369 1388 1388 I cioz : (REDACTED) onApplyWindowInsets: systemWindowInsets=%s 08-07 15:12:58.271549 897 954 I libPowerHal: [perfNotifyAppState] pack:com.android.launcher3, act:com.android.searchlauncher.SearchLauncher, state:1, pid:24443, uid:1000, fps:-1 yuanhaixiong@yuanhaixiong-PC:~/machine/Log/#K1-8G-KASAN版本monkey异常停止0806/debuglogger/mobilelog$ ls APLog_2025_0806_173133__3 APLog_2025_0807_065857__5 APLog_2025_0807_080020__7 APLog_2025_0807_112654__9 APLog_2025_0807_130603__11 APLog_2025_0807_134712__13 APLog_2025_0807_153818__15 APLog_2025_0807_042752__4 APLog_2025_0807_073742__6 APLog_2025_0807_111445__8 APLog_2025_0807_121702__10 APLog_2025_0807_134043__12 APLog_2025_0807_150142__14 file_tree.txt yuanhaixiong@yuanhaixiong-PC:~/machine/Log/#K1-8G-KASAN版本monkey异常停止0806/debuglogger/mobilelog$ head APLog_2025_0807_153818__15/ atf_log_7__2025_0807_155133 crash_log_5__2025_0807_155133 main_log_1__2025_0807_155133 properties sys_log_4__2025_0807_155133 bootprof events_log_3__2025_0807_155133 mblog_history radio_log_2__2025_0807_155133 bsp_log_9__2025_0807_155133 gz_log_8__2025_0807_155133 mcupm_log_12__2025_0807_155133 scp_log_10__2025_0807_155133 connsys_picus_log_13__2025_0807_155133 kernel_log_6__2025_0807_155133 pl_lk sspm_log_11__2025_0807_155133 yuanhaixiong@yuanhaixiong-PC:~/machine/Log/#K1-8G-KASAN版本monkey异常停止0806/debuglogger/mobilelog$ head APLog_2025_0807_153818__15/main_log_1__2025_0807_155133 ----- timezone:Asia/Shanghai 08-07 15:37:42.020551 1899 1899 D BLASTBufferQueue: [VRI[VolumeDialogImpl]#20808](f:0,a:0) constructor() 08-07 15:37:42.020644 1899 1899 D BLASTBufferQueue: [VRI[VolumeDialogImpl]#20808](f:0,a:0) update width=192 height=1584 format=-2 mTransformHint=0 08-07 15:37:42.022698 1899 2022 D BufferQueueProducer: [VRI[VolumeDialogImpl]#20808(BLAST Consumer)20808](id:76b000051cf,api:1,p:1899,c:1899) connect: api=1 producerControlledByApp=true 08-07 15:37:42.038344 1899 2022 D BLASTBufferQueue: [VRI[VolumeDialogImpl]#20808](f:0,a:1) acquireNextBufferLocked size=192x1584 mFrameNumber=1 applyTransaction=true mTimestamp=80052119459001(auto) mPendingTransactions.size=0 graphicBufferId=8156143212544 transform=0 08-07 15:37:42.039933 934 986 E surfaceflinger: == MALI DEBUG ===eglp_winsys_populate_image_templates ==12288 08-07 15:37:42.049390 1478 1606 E system_server: No package ID ff found for resource ID 0xffffffff. 08-07 15:37:42.058021 934 1710 I BufferQueueDebug: [Surface(name=e81a44d VolumeDialogImpl)/@0x36c1005 - animation-leash of window_animation#399493](this:0xb40000777fcdb730,id:-1,api:0,p:-1,c:-1) BufferQueue core=(934:/system/bin/surfaceflinger) 08-07 15:37:42.067688 1899 1899 D BLASTBufferQueue: [VRI[VolumeDialogImpl]#20808](f:0,a:1) update width=192 height=1392 format=-2 mTransformHint=0 08-07 15:37:42.069336 1899 2022 D BufferQueueProducer: [VRI[VolumeDialogImpl]#20808(BLAST Consumer)20808](id:76b000051cf,api:1,p:1899,c:1899) disconnect: api 1 yuanhaixiong@yuanhaixiong-PC:~/machine/Log/#K1-8G-KASAN版本monkey异常停止0806/debuglogger/mobilelog$
08-21
评论
成就一亿技术人!
拼手气红包6.0元
还能输入1000个字符
 
红包 添加红包
表情包 插入表情
 条评论被折叠 查看
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值