记一次由内核版本引起的奇异问题
本作品采用知识共享署名-非商业性使用-相同方式共享 4.0 国际许可协议进行许可。
本作品 (李兆龙 博文, 由 李兆龙 创作)，由 李兆龙 确认，转载请注明版权。
引言
这篇文章在于去记录一个解决问题的过程，我想这种文章于我而言相比于一些无聊的笔记是有意思的多的。
描述
问题的起源在于现在要去分析多线程持有锁时花费在锁争抢上的时间，其实也就是因为锁竞争而导致线程挂起的时间，想到Stap，BPFTrace这种动态追踪方案可以很好的解决问题，而且机缘巧合之下在官网发现了有人已经写了这么一个Stap的脚本去解决问题。
这个脚本的思路并不难，就是通过sys_futex处埋一个probe，进入的时候判断如果是FUTEX_WAIT则证明这个线程应该陷入阻塞的，通过记录进入和离开sys_futex的时间去计算在锁上阻塞的时间。
global thread_thislock
global thread_blocktime
global FUTEX_WAIT = 0, FUTEX_WAKE = 1
global lock_waits # long-lived stats on (tid,lock) blockage elapsed time
global process_names # long-lived pid-to-execname mapping
probe syscall.futex {
if (op != FUTEX_WAIT) next # we don't care about originators of WAKE events
t = tid ()
process_names[pid()] = execname()
thread_thislock[t] = $uaddr
thread_blocktime[t] = gettimeofday_us()
}
probe syscall.futex.return {
t = tid()
ts = thread_blocktime[t]
if (ts) {
elapsed = gettimeofday_us() - ts
lock_waits[pid(), thread_thislock[t]] <<< elapsed
delete thread_blocktime[t]
delete thread_thislock[t]
}
}
probe end {
foreach ([pid+, lock] in lock_waits)
printf ("%s[%d] lock %p contended %d times, %d avg us\n",
process_names[pid], pid, lock, @count(lock_waits[pid,lock]), @avg(lock_waits[pid,lock]))
}
至少现在看起来没有什么问题，我们可以看到数据非常的清晰。
OK，让我们加一个小需求，我想去查看固定进程中线程的抢锁时间，其实也很简单，就是在执行的时候把监控进程的pid带上，然后在进入syscall.futex的时候判断下是不是我们需要的那个就可以了。
我们写一个简单的示例，模拟N个线程抢锁：
#include <bits/stdc++.h>
#include <unistd.h>
using namespace std;
std::mutex mu;
int a = 20201030;
void work() {
while(1) {
mu.lock();
a++; // 防止编译器优化
mu.unlock();
}
}
int main(){
cout << getpid() << endl;
vector<std::thread> threads;
for (int i = 0; i < 10; ++i) {
threads.emplace_back(thread(work));
}
std::for_each(threads.begin(), threads.end(), std::mem_fn(&std::thread::join));
return 0;
}
OK，跑起来这个示例，然后执行修改过的脚本就可以，
probe syscall.futex {
if (op != FUTEX_WAIT) next # we don't care about originators of WAKE events
if (pid() == target()) {
t = tid ()
process_names[pid()] = execname()
thread_thislock[t] = $uaddr
thread_blocktime[t] = gettimeofday_us()
}
}
奇怪的事情发生了，脚本抓不到任何指定进程的锁信息，这就奇了大怪了，理论来讲现代的锁基本都是使用了sys_futex机制去解决问题，现在却抓不到数据，到底是为什么呢？
首先定位问题，lock操作是否调用了sys_futex呢？换个样例，看看栈帧吧
int a = 10;
int main(){
mutex mu;
cout << getpid() << endl;
std::thread th = thread([&]{
while(1) {
mu.lock();
sleep(200);
a++;
mu.unlock();
cout << a << endl;
}
});
while(1) {
mu.lock();
sleep(1);
a++;
mu.unlock();
cout << a << endl;
}
return 0;
}
这样理论上来说我们可以看到主线程的用户栈，让我们pstack一下：
我们可以看到主函数最后阻塞到了_L_lock_883这里，我们看看pthread_mutex_lock这里的实现逻辑：
# define LLL_MUTEX_LOCK(mutex) \
lll_lock ((mutex)->__data.__lock, PTHREAD_MUTEX_PSHARED (mutex))
#define lll_lock(futex, private) \
__lll_lock (&(futex), private)
#define __lll_lock(futex, private) \
((void) \
({ \
int *__futex = (futex); \
if (__glibc_unlikely \
(atomic_compare_and_exchange_bool_acq (__futex, 1, 0))) \
{ \
if (__builtin_constant_p (private) && (private) == LLL_PRIVATE) \
__lll_lock_wait_private (__futex); \
else \
__lll_lock_wait (__futex, private); \
} \
}))
void
__lll_lock_wait_private (int *futex)
{
if (*futex == 2)
lll_futex_wait (futex, 2, LLL_PRIVATE); /* Wait if *futex == 2. */
while (atomic_exchange_acq (futex, 2) != 0)
lll_futex_wait (futex, 2, LLL_PRIVATE); /* Wait if *futex == 2. */
}
__lll_lock_wait (int *futex, int private)
{
if (*futex == 2)
lll_futex_wait (futex, 2, private); /* Wait if *futex == 2. */
while (atomic_exchange_acq (futex, 2) != 0)
lll_futex_wait (futex, 2, private); /* Wait if *futex == 2. */
}
/* Wait while * FUTEXP == VAL for a lll_futex_wake call on FUTEXP */
#define lll_futex_wait(futexp, val, private) \
((void)) (private), \
-__nacl_irt_futex.futex_wait_abs((volatitle int *)(futexp), val, NULL))
我们可以看到一个比较经典的futex机制的实现，很多人总是区分不清楚futex系统调用和futex机制的区别，futex机制需要用户态的配合，也就是上面代码中用户态的自旋操作，判断*futex是否是2，是的话才会调用lll_futex_wait操作，也就是最后的系统调用。
文档中对于sys_futex的描述是这样的：
The futex() system call provides a method for waiting until a certain condition becomes true. It is typically used as a blocking construct in the context of shared-memory synchronization. When using futexes, the majority of the synchronization operations are performed in user space. A user-space program employs the futex() system call only when it is likely that the program has to block for a longer time until the condition becomes true. Other futex() operations can be used to wake any processes or threads waiting for a particular condition.
futex() 系统调用提供了一种等待特定条件成立的方法。 它通常用作共享内存同步上下文中的阻塞构造。 使用 futex 时，大部分同步操作是在用户空间执行的。 用户空间程序仅在程序可能必须阻塞更长的时间直到条件变为真时才使用 futex() 系统调用。 其他 futex() 操作可用于唤醒等待特定条件的任何进程或线程。
但是奇了怪了，也就是说竞争时也会调用sys_futex时也会陷入内核啊，理论上来说我们的probe也可以抓到这条数据啊，我们来看看内核栈：
可以看到确实进入了sys_futex，也就说脚本端有问题。
机器的内核版本是Centos 3.10.0，我们来看看源码到底做了什么：
我们可以看到op在进入时会和FUTEX_CMD_MASK执行与操作，随后真正有效的是cmd，也就是说脚本开始判断op是有问题，老哥开始写那个脚本的时候估计还没有这样的逻辑，打印一下op操作，发现基本都是128，129，所以op基本就是（FUTEX_PRIVATE_FLAG&FUTEX_WAIT）和（FUTEX_PRIVATE_FLAG&FUTEX_WAKE），所以就真相大白了，代码根本没跑到我们的判断处就退出了，我们只需要把脚本改成下面这样就可以了：
probe syscall.futex {
if (op-128 != FUTEX_WAIT) next # we don't care about originators of WAKE events
if (pid() == target()) {
printf("%s -> %s\n", execname(), usymname($uaddr))
t = tid ()
process_names[pid()] = execname()
thread_thislock[t] = $uaddr
thread_blocktime[t] = gettimeofday_us()
}
}
Nice！没有什么问题，需要的数据基本都抓到了。当然这里有一个小问题，就是在内核态打印用户态信息貌似是不可以的，当然锁的示例程序是加-g的。所以就导致虽然调用了usymname还是打印不出用户态符号。
当然难不到机智的我，objdump把符号表导出来照着地址找就可以了：
objdump -t ./a.out | less
这就找到这把锁了，跑的是第一个样例，理所应当在bss。
总结
一个有意思的解决问题的过程，前后花了一下午，总归是解决了问题。后面有时间可以写一篇关于动态追踪的文章，确实是一个非常强大的工具，但是想要窥探到更加细致的信息，必须得学习内核代码，不然probe都没办法埋。好了，看起来毕设要跟着陈莉君老师搞ebpf了。
花絮
在guru模式下我们能做非常多的事情。偶然间看到一个有意思的小玩意：
这样就可以把以前整蛊别人时用的alias换为stap了，好像有些邪恶哈哈哈。
参考：
