int main(void){for (int i = 0; i < 1000000; ++i){DTRACE_PROBE1(probe_group, probe_name, i); // 这就是我的探针usleep(10000);}return 0;}
示例 1
[][]
示例2
[root@el8-168 ff]# gdb trc1GNU gdb (GDB) Red Hat Enterprise Linux 8.2-16.el8Copyright (C) 2018 Free Software Foundation, Inc.......(gdb) disassemble mainDump of assembler code for function main:0x0000000000400410 <+0>: push %rbx0x0000000000400411 <+1>: xor %ebx,%ebx0x0000000000400413 <+3>: nopl 0x0(%rax,%rax,1)0x0000000000400418 <+8>: nop0x0000000000400419 <+9>: mov $0x2710,%edi0x000000000040041e <+14>: add $0x1,%ebx0x0000000000400421 <+17>: callq 0x400400 <usleep@plt>0x0000000000400426 <+22>: cmp $0xf4240,%ebx0x000000000040042c <+28>: jne 0x400418 <main+8>0x000000000040042e <+30>: xor %eax,%eax0x0000000000400430 <+32>: pop %rbx0x0000000000400431 <+33>: retqEnd of assembler dump.(gdb)
示例3
#!/usr/bin/stapprobe begin{printf("Start tracing USDT probes in my_app...\n\n")}// 定义跟踪点:process("可执行文件路径").provider("探针组名").mark("探针名")probe process("./trc1").provider("probe_group").mark("probe_name"){// $arg1 代表我们传递给探针的第一个参数printf(">>> Probe operation_start fired. Input value: %d\n", $arg1)printf(" [Context] PID: %d, Executable: %s\n\n", pid(), execname())}probe end{printf("\nTracing stopped.\n")}
示例 4
(gdb) rStarting program: /root/ff/trc1Missing separate debuginfos, use: yum debuginfo-install glibc-2.28-164.el8.x86_64
示例 5
换到另一个窗口,使用stap,运行trc.d脚本,激活探针:
[]Start tracing USDT probes in my_app...>>> Probe operation_start fired. Input value: 165[] PID: 95672, Executable: trc1>>> Probe operation_start fired. Input value: 166[] PID: 95672, Executable: trc1............
示例 6
可以看到,有大量的输出。
可执行文件trc1中的探针、也就是nop指令,被trc.d脚本替换为一条int3指令。
CPU在执行到原来的nop、现在的int3处时,会中断trc1的执行,向OS发送中断消息。然后OS会保存上下文,转去执行中断代码,也就是示例4中的脚本。再然后OS会恢复上下文,让trc1继续执行。
我们可以看看被修改后的代码:
(gdb) rStarting program: /root/ff/trc1Missing separate debuginfos, use: yum debuginfo-install glibc-2.28-164.el8.x86_64^CProgram received signal SIGINT, Interrupt.0x00007ffff7ad3d68 in nanosleep () from /lib64/libc.so.6(gdb) nSingle stepping until exit from function nanosleep,which has no line number information.0x00007ffff7affb28 in usleep () from /lib64/libc.so.6(gdb) nSingle stepping until exit from function usleep,which has no line number information.main () at trc1.c:66 for (int i = 0; i < 1000000; ++i)(gdb)8 DTRACE_PROBE1(probe_group, probe_name, i); // 这就是我的探针(gdb) disasDump of assembler code for function main:0x0000000000400410 <+0>: push %rbx0x0000000000400411 <+1>: xor %ebx,%ebx0x0000000000400413 <+3>: nopl 0x0(%rax,%rax,1)=> 0x0000000000400418 <+8>: int30x0000000000400419 <+9>: mov $0x2710,%edi0x000000000040041e <+14>: add $0x1,%ebx0x0000000000400421 <+17>: callq 0x400400 <usleep@plt>0x0000000000400426 <+22>: cmp $0xf4240,%ebx0x000000000040042c <+28>: jne 0x400418 <main+8>0x000000000040042e <+30>: xor %eax,%eax0x0000000000400430 <+32>: pop %rbx0x0000000000400431 <+33>: retqEnd of assembler dump.(gdb)
示例 7
如果示例7所示,在23行这里,地址为”0x400418“处的指令,原来是nop,现在换成int3了。
这就是探针激活。
探针激活后,可执行文件 trc1 被修改,nop指令被替换为int3。那么,trc1如何恢复原样呢?
也很简单,只要停止trc.d脚本就可以了:
[]Start tracing USDT probes in my_app...>>> Probe operation_start fired. Input value: 165[] PID: 95672, Executable: trc1............>>> Probe operation_start fired. Input value: 870[] PID: 95954, Executable: trc1^CTracing stopped.[]
示例8
如示例8所示,CTRL+C,停止trc.d。再回头看看可执行文件trc1:
(gdb) disasDump of assembler code for function main:0x0000000000400410 <+0>: push %rbx0x0000000000400411 <+1>: xor %ebx,%ebx0x0000000000400413 <+3>: nopl 0x0(%rax,%rax,1)=> 0x0000000000400418 <+8>: int30x0000000000400419 <+9>: mov $0x2710,%edi0x000000000040041e <+14>: add $0x1,%ebx0x0000000000400421 <+17>: callq 0x400400 <usleep@plt>0x0000000000400426 <+22>: cmp $0xf4240,%ebx0x000000000040042c <+28>: jne 0x400418 <main+8>0x000000000040042e <+30>: xor %eax,%eax0x0000000000400430 <+32>: pop %rbx0x0000000000400431 <+33>: retqEnd of assembler dump.(gdb) n9 usleep(10000);(gdb)6 for (int i = 0; i < 1000000; ++i)(gdb)8 DTRACE_PROBE1(probe_group, probe_name, i); // 这就是我的探针(gdb) disassembleDump of assembler code for function main:0x0000000000400410 <+0>: push %rbx0x0000000000400411 <+1>: xor %ebx,%ebx0x0000000000400413 <+3>: nopl 0x0(%rax,%rax,1)=> 0x0000000000400418 <+8>: nop0x0000000000400419 <+9>: mov $0x2710,%edi0x000000000040041e <+14>: add $0x1,%ebx0x0000000000400421 <+17>: callq 0x400400 <usleep@plt>0x0000000000400426 <+22>: cmp $0xf4240,%ebx0x000000000040042c <+28>: jne 0x400418 <main+8>0x000000000040042e <+30>: xor %eax,%eax0x0000000000400430 <+32>: pop %rbx0x0000000000400431 <+33>: retqEnd of assembler dump.(gdb)
示例 9
1至10行是示例7中的输出,从第11行是新的。
在第27行可以看到,0x400418处的指令,又变为原来的int3了。
这就是USDT,用户态静态跟踪。“静态”的意思就是,它被固定在编译后的结果中。激活时需要修改代码段,替换指令。
在前一篇 可观测性利器--USDT用户态静态追踪详解(一)中已经说过了,静态的固定在目标可执行文件中的nop指令,并不会影响性能。
使用USDT,你可以方便的增加任意多数量的探针,提升可观测性。
除了USDT,AI的回答让我震精,准确、详细。它不只是一个更好的搜索引擎,它至少像一个助教一样,为我详细的解答USDT的原理、例子。
一时之间,我甚至在想,学这些东西还有用吗?
AI都会,它可以替代我做这些事情,我还要学习USDT的原理吗?
这是个值得深思的问题,不过,在向Deepseek和kimi的进一步请教后,我也有了想法。
我继续问:“USDT的缺陷与不足,以及使用场景的限制,能帮我总结下吗?”
Deepseek直接回答稳定币如何如何的。我不得不改为“USDT,Userland Statically Defined Tracing,的缺陷与不足,以及使用场景的限制,能帮我总结下吗?”,但整体回答不如kimi。
kimi回答很精准,总结就是int3产生的上下文切换,性能开销高,不适合高频、低延迟场景。
这是kimi给出的总结:
图1
它认为USDT适用于数据库的事务,因为数据库事务符合“低频”但“关键”的特性。
你认为呢?
下面“一句话”部分,它的总结是“高频、超低延迟”场景不适用。
我最后问了kimi一个问题:“哪么,在”高频、超低延迟“下,有源码的情况下,有什么更好的可观测性的技术吗?”
这是kimi给的回复:
给出了4点建议,还有参考的网络资料。
总的来说,非常不错。
但其实还有更好的方式,就是我们在谛听中使用的方式。
AI并没有真实把CPU体系结构、操作系统原理组合起来,它还是一个更更更聪明、更理解人的搜索、分类工具。
在真正理解了CPU和OS原理的基础上,是可以产生更新的知识的。从这个层面上说,人类的神经网络,层数、参数数量,应该比AI还是要高出不少数量级。
我们的“谛听”,将int3换为jmp无条件跳转,没有上下文切换,而且无条件跳转总是跳转,CPU不会分枝预测失败。相比int3,损耗可以降低万倍以上。
kimi总结的方式,已经触摸到了“jmp无条件跳转”,但是,缺乏在大型项目中使用的方式。
USDT相当于普通的显微镜,“谛听”则相当于电子显微镜。AI给出的结果,还实现不了电子显微镜。
除了int3本身耗时,USDT还有一点缺陷也很明显:激活时开销有点高,这是kimi没有指出的。
USDT在激活探针时,经过我的测试,开销可以达到6毫秒以上。影响巨大,无法在高频代码中使用。
你想想,你使用eBPF/Systemtap/DTrace激活目标程序的探针,目标程序停了6毫秒,然后探针被激活。
怎么样,6毫秒,如果是高频代码,延迟6毫秒足够让系统宕机了。
我们的“谛听”激活探针只需要12微秒左右,单位是微秒啊。一次内存访问操作,如果跨了NUMA节点,大概在500到800纳秒间。谛听被激活的消耗,和几十次读写内存差不多。这个开销已经十分低了。
如果对谛听感兴趣的,11月29号,PG生态大会,我们线下面对面讨论:


