systemtap使用：跟踪应用的执行流程

Easter79
• 阅读 1217

一、如何确定探测点

这就需要跟踪一下sshd进程的执行流程，分析一下密码输入的上下文执行函数的位置。

#函数还真的挺多- -
#  stap -l 'process("/usr/sbin/sshd").function("*")' | wc -l 
1433

二、编写SystemTap安装探测点 ：

    1.探测点思路（ 信号处理方式）：

    在指定内核信号文件中匹配所有函数并打上探测点 ，分别打上 call和return两个探测点 ， call和retrun的时候输出函数名 ， 并利用thread_indent函数增加缩进， 这样就可以体现出函数的调用过程了。因为内核处理信号比较频繁，所以上面脚本中就用target()来过滤指定进程pid值（stap -x），只要一个pid的信号处理流程，这样输出比较少才好分析。

# stap -l 'kernel.function("sys_signal")'
kernel.function("SyS_signal@kernel/signal.c:3554")
#pid=1710
# ps -ef | grep '/usr/sbin/sshd' |grep -v 'grep'
root      1710     1  0 Aug31 ?        00:00:00 /usr/sbin/sshd -D

    2.内核跟踪代码的执行流程Tap：

# cat kernel_signal_process.stp 
probe begin {
            printf("Tracert begin...\n")
}

#function::thread_indent — returns an amount of space with the current task information  
#function::ppfunc — Returns the function name parsed from pp
#function::target — Return the process ID of the target process 
probe kernel.function("*@kernel/signal.c").call {
            if (target() == pid()) {
                printf("%s -> %s\n", thread_indent(4),ppfunc())
            }
 }

probe kernel.function("*@kernel/signal.c").return {
            if (target() == pid()) {
                printf("%s <- %s\n", thread_indent(-4), ppfunc())
            }
}

3. 启动SystemTap安装探测点

# stap -x 1710 kernel_signal_process.stp 
WARNING: function signals_init is in blacklisted section: keyword at kernel_signal_process.stp:8:1
 source: probe kernel.function("*@kernel/signal.c").call {
         ^
WARNING: function setup_print_fatal_signals is in blacklisted section: keyword at :8:1
 source: probe kernel.function("*@kernel/signal.c").call {
         ^
Tracert begin...
     0 sshd(1710):    -> __lock_task_sighand
     9 sshd(1710):    <- __lock_task_sighand
     0 sshd(1710):    -> recalc_sigpending
     5 sshd(1710):        -> recalc_sigpending_tsk
     8 sshd(1710):        <- recalc_sigpending_tsk
    10 sshd(1710):    <- recalc_sigpending
#输入密码之后的执行流程
    10 sshd(1710):    <- recalc_sigpending
     0 sshd(1710):    -> do_notify_resume
    10 sshd(1710):    <- do_notify_resume
#退出登录的执行流程
     0 sshd(1710):    -> do_notify_resume
     8 sshd(1710):        -> do_signal
    10 sshd(1710):            -> get_signal_to_deliver
    13 sshd(1710):                -> dequeue_signal
    15 sshd(1710):                    -> __dequeue_signal
    18 sshd(1710):                    <- __dequeue_signal
    20 sshd(1710):                    -> __dequeue_signal
    23 sshd(1710):                        -> __sigqueue_free
    26 sshd(1710):                        <- __sigqueue_free
    27 sshd(1710):                    <- __dequeue_signal
    29 sshd(1710):                    -> recalc_sigpending
    31 sshd(1710):                        -> recalc_sigpending_tsk
    44 sshd(1710):                        <- recalc_sigpending_tsk
    46 sshd(1710):                    <- recalc_sigpending
    48 sshd(1710):                <- dequeue_signal
    50 sshd(1710):            <- get_signal_to_deliver
    53 sshd(1710):            -> setup_sigcontext
    55 sshd(1710):            <- setup_sigcontext
    57 sshd(1710):            -> signal_setup_done
    60 sshd(1710):                -> signal_delivered
    62 sshd(1710):                    -> __set_current_blocked
    65 sshd(1710):                        -> __set_task_blocked
    67 sshd(1710):                            -> recalc_sigpending
    68 sshd(1710):                                -> recalc_sigpending_tsk
    70 sshd(1710):                                <- recalc_sigpending_tsk
    72 sshd(1710):                            <- recalc_sigpending
    73 sshd(1710):                        <- __set_task_blocked
    75 sshd(1710):                    <- __set_current_blocked
    77 sshd(1710):                <- signal_delivered
    78 sshd(1710):            <- signal_setup_done
    80 sshd(1710):        <- do_signal
    82 sshd(1710):    <- do_notify_resume
     0 sshd(1710):    -> flush_sigqueue
     2 sshd(1710):    <- flush_sigqueue
     0 sshd(1710):    -> flush_sigqueue
     1 sshd(1710):    <- flush_sigqueue
     0 sshd(1710):    -> SyS_rt_sigaction
     2 sshd(1710):        -> do_sigaction
     4 sshd(1710):        <- do_sigaction
     5 sshd(1710):    <- SyS_rt_sigaction
     0 sshd(1710):    -> sys_rt_sigreturn
     2 sshd(1710):        -> set_current_blocked
     4 sshd(1710):            -> __set_current_blocked
     6 sshd(1710):                -> __set_task_blocked
     7 sshd(1710):                    -> recalc_sigpending
     9 sshd(1710):                        -> recalc_sigpending_tsk
    11 sshd(1710):                        <- recalc_sigpending_tsk
    12 sshd(1710):                    <- recalc_sigpending
    14 sshd(1710):                <- __set_task_blocked
    15 sshd(1710):            <- __set_current_blocked
    17 sshd(1710):        <- set_current_blocked
    19 sshd(1710):        -> restore_sigcontext
    21 sshd(1710):        <- restore_sigcontext
    22 sshd(1710):        -> restore_altstack
    24 sshd(1710):            -> do_sigaltstack
    26 sshd(1710):            <- do_sigaltstack
    28 sshd(1710):        <- restore_altstack
    29 sshd(1710):    <- sys_rt_sigreturn


# stap -l 'kernel.function("recalc_sigpending")'
kernel.function("recalc_sigpending@kernel/signal.c:160")
#内核空间和用户空间交换数据时，使用get_user*和put_user*函数完成简单类型变量拷贝任务
158 #ifdef CONFIG_X86_32
159                 put_user_ex(regs->cs, (unsigned int __user *)&sc->cs);
160                 put_user_ex(regs->flags, &sc->flags);
161                 put_user_ex(regs->sp, &sc->sp_at_signal);
162                 put_user_ex(regs->ss, (unsigned int __user *)&sc->ss);

4.使用strace命令能更清晰的看到程序执行的调用流程：

#trace=signal
#strace -tt -f -e trace=signal -p 1710
strace: Process 1710 attached
strace: Process 39362 attached
[pid 39362] 23:28:57.980098 rt_sigaction(SIGRTMIN, {sa_handler=0x7fea2694b860, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x7fea26954630}, NULL, 8) = 0
[pid 39362] 23:28:57.980326 rt_sigaction(SIGRT_1, {sa_handler=0x7fea2694b8f0, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART|SA_SIGINFO, sa_restorer=0x7fea26954630}, NULL, 8) = 0
[pid 39362] 23:28:57.980391 rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
[pid 39362] 23:28:57.988670 rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=0}, 8) = 0
[pid 39362] 23:28:57.989008 rt_sigaction(SIGALRM, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
[pid 39362] 23:28:57.989067 rt_sigaction(SIGHUP, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
[pid 39362] 23:28:57.989120 rt_sigaction(SIGTERM, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
[pid 39362] 23:28:57.989172 rt_sigaction(SIGQUIT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
[pid 39362] 23:28:57.989220 rt_sigaction(SIGCHLD, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
[pid 39362] 23:28:57.989268 rt_sigaction(SIGINT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
[pid 39362] 23:28:57.989954 rt_sigaction(SIGALRM, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
[pid 39362] 23:28:57.990029 rt_sigaction(SIGALRM, {sa_handler=0x562069f8bf30, sa_mask=[], sa_flags=SA_RESTORER|SA_INTERRUPT, sa_restorer=0x7fea28650400}, NULL, 8) = 0
strace: Process 39363 attached

#trace=file
# strace -tt -f -e trace=file -p 1710
strace: Process 1710 attached
[pid 40200] 23:33:45.287284 open("/proc/self/oom_score_adj", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 10
[pid 40200] 23:33:45.288205 execve("/usr/sbin/sshd", ["/usr/sbin/sshd", "-D", "-R"], 0x564a53c46ab0 /* 4 vars */) = 0
[pid 40200] 23:33:45.288958 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
[pid 40200] 23:33:45.289206 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
[pid 40200] 23:33:45.289367 open("/lib64/libfipscheck.so.1", O_RDONLY|O_CLOEXEC) = 3
[pid 40200] 23:33:45.289642 open("/lib64/libwrap.so.0", O_RDONLY|O_CLOEXEC) = 3
...
[pid 40200] 23:33:45.374997 open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
[pid 40200] 23:33:45.375237 stat("/bin/bash", {st_mode=S_IFREG|0755, st_size=964536, ...}) = 0
[pid 40200] 23:33:45.375697 stat("/etc/pam.d", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 40200] 23:33:45.375770 open("/etc/pam.d/sshd", O_RDONLY) = 4
[pid 40200] 23:33:45.376006 open("/usr/lib64/security/pam_sepermit.so", O_RDONLY|O_CLOEXEC) = 8
[pid 40200] 23:33:45.376378 open("/etc/pam.d/password-auth", O_RDONLY) = 8
[pid 40200] 23:33:45.376553 open("/usr/lib64/security/pam_env.so", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.376899 open("/usr/lib64/security/pam_faildelay.so", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.377230 open("/usr/lib64/security/pam_unix.so", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.377694 open("/usr/lib64/security/pam_succeed_if.so", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.377981 stat("/etc/sysconfig/64bit_strstr_via_64bit_strstr_sse2_unaligned", 0x7fff90575f10) = -1 ENOENT (No such file or directory)
[pid 40200] 23:33:45.378098 open("/usr/lib64/security/pam_deny.so", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.378513 open("/etc/pam.d/postlogin", O_RDONLY) = 8
[pid 40200] 23:33:45.378769 open("/usr/lib64/security/pam_reauthorize.so", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
[pid 40200] 23:33:45.378834 stat("/etc/sysconfig/64bit_strstr_via_64bit_strstr_sse2_unaligned", 0x7fff905765f0) = -1 ENOENT (No such file or directory)
[pid 40200] 23:33:45.378913 open("/usr/lib64/security/pam_nologin.so", O_RDONLY|O_CLOEXEC) = 8
[pid 40200] 23:33:45.379227 open("/etc/pam.d/password-auth", O_RDONLY) = 8
[pid 40200] 23:33:45.379396 open("/usr/lib64/security/pam_localuser.so", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.379723 open("/usr/lib64/security/pam_permit.so", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.380115 open("/etc/pam.d/password-auth", O_RDONLY) = 8
[pid 40200] 23:33:45.380283 open("/usr/lib64/security/pam_pwquality.so", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.380556 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.380716 open("/lib64/libpwquality.so.1", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.380982 open("/lib64/libcrack.so.2", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.381391 stat("/etc/sysconfig/64bit_strstr_via_64bit_strstr_sse2_unaligned", 0x7fff90575f00) = -1 ENOENT (No such file or directory)
[pid 40200] 23:33:45.381716 open("/usr/lib64/security/pam_selinux.so", O_RDONLY|O_CLOEXEC) = 8
[pid 40200] 23:33:45.382076 open("/usr/lib64/security/pam_loginuid.so", O_RDONLY|O_CLOEXEC) = 8
[pid 40200] 23:33:45.382411 open("/usr/lib64/security/pam_namespace.so", O_RDONLY|O_CLOEXEC) = 8
[pid 40200] 23:33:45.382752 stat("/etc/sysconfig/64bit_strstr_via_64bit_strstr_sse2_unaligned", 0x7fff90576470) = -1 ENOENT (No such file or directory)
[pid 40200] 23:33:45.382874 open("/usr/lib64/security/pam_keyinit.so", O_RDONLY|O_CLOEXEC) = 8
[pid 40200] 23:33:45.383203 open("/etc/pam.d/password-auth", O_RDONLY) = 8
[pid 40200] 23:33:45.383397 open("/usr/lib64/security/pam_limits.so", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.383760 open("/usr/lib64/security/pam_systemd.so", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.384034 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.384196 open("/lib64/libpam_misc.so.0", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.384928 open("/etc/pam.d/postlogin", O_RDONLY) = 8
[pid 40200] 23:33:45.385115 open("/usr/lib64/security/pam_lastlog.so", O_RDONLY|O_CLOEXEC) = 9
[pid 40200] 23:33:45.385677 open("/etc/pam.d/other", O_RDONLY) = 4
....

#其实可以看到在PAM认证时相关的文件，在挂载对应的函数point.

5.使用process 跟踪调用的函数执行流程：

# cat func_trace.stp 
probe process("/usr/sbin/sshd").function("*").call
{
        printf("%s -> %s\n", thread_indent(4), ppfunc());
}

probe process("/usr/sbin/sshd").function("*").return
{
        printf("%s <- %s\n", thread_indent(-4), ppfunc());
}

######################################################################
9233994 sshd(14355):                        <- buffer_get_string
9233998 sshd(14355):                        -> auth_password
9234007 sshd(14355):                            -> sshpam_auth_passwd
9234352 sshd(14355):                                -> sshpam_passwd_conv
9234358 sshd(14355):                                    -> debug3
9234363 sshd(14355):                                        -> do_log
9234368 sshd(14355):                                        <- do_log
9234370 sshd(14355):                                    <- debug3
9234374 sshd(14355):                                <- sshpam_passwd_conv
11649789 sshd(14355):                                -> debug
11649804 sshd(14355):                                    -> do_log
11649810 sshd(14355):                                    <- do_log
11649813 sshd(14355):                                <- debug
11649817 sshd(14355):                            <- sshpam_auth_passwd
11649823 sshd(14355):                        <- auth_password
11649829 sshd(14355):                        -> explicit_bzero
11649834 sshd(14355):                        <- explicit_bzero
11649840 sshd(14355):                        -> sshbuf_reset
11649845 sshd(14355):                            -> explicit_bzero
11649849 sshd(14355):                            <- explicit_bzero
11649852 sshd(14355):                        <- sshbuf_reset
11649857 sshd(14355):                        -> buffer_put_int
11649863 sshd(14355):                            -> sshbuf_put_u32
11649868 sshd(14355):                                -> sshbuf_reserve
11649873 sshd(14355):                                    -> sshbuf_allocate
11649879 sshd(14355):                                        -> sshbuf_check_reserve
11649883 sshd(14355):                                        <- sshbuf_check_reserve
11649888 sshd(14355):                                        -> sshbuf_maybe_pack
11649893 sshd(14355):                                        <- sshbuf_maybe_pack
11649895 sshd(14355):                                    <- sshbuf_allocate
sigactionstracesystemtapkernel前端前端
点赞
收藏
评论区
推荐文章
blmius blmius
•
3年前
MySQL:[Err] 1292 - Incorrect datetime value: ‘0000-00-00 00:00:00‘ for column ‘CREATE_TIME‘ at row 1
文章目录问题用navicat导入数据时，报错：原因这是因为当前的MySQL不支持datetime为0的情况。解决修改sql\mode:sql\mode:SQLMode定义了MySQL应支持的SQL语法、数据校验等，这样可以更容易地在不同的环境中使用MySQL。全局s
4121
0
0
helloworld_34035044 helloworld_34035044
•
2年前
皕杰报表之UUID
​在我们用皕杰报表工具设计填报报表时，如何在新增行里自动增加id呢？能新增整数排序id吗？目前可以在新增行里自动增加id，但只能用uuid函数增加UUID编码，不能新增整数排序id。uuid函数说明：获取一个UUID，可以在填报表中用来创建数据ID语法：uuid()或uuid(sep)参数说明：sep布尔值，生成的uuid中是否包含分隔符''，缺省为
1141
0
0
Jacquelyn38 Jacquelyn38
•
3年前
2020年前端实用代码段，为你的工作保驾护航
有空的时候，自己总结了几个代码段，在开发中也经常使用，谢谢。1、使用解构获取json数据let jsonData  id: 1,status: "OK",data: 'a', 'b';let  id, status, data: number   jsonData;console.log(id, status, number )
2383
0
0
Wesley13 Wesley13
•
3年前
mysql设置时区
mysql设置时区mysql\_query("SETtime\_zone'8:00'")ordie('时区设置失败，请联系管理员！');中国在东8区所以加8方法二：selectcount(user\_id)asdevice,CONVERT\_TZ(FROM\_UNIXTIME(reg\_time),'08:00','0
1313
0
0
Stella981 Stella981
•
3年前
JS 对象数组Array 根据对象object key的值排序sort,很风骚哦
有个js对象数组varary\{id:1,name:"b"},{id:2,name:"b"}\需求是根据name或者id的值来排序,这里有个风骚的函数函数定义:function keysrt(key,desc) {  return function(a,b){    return desc ? ~~(ak
1030
0
0
Wesley13 Wesley13
•
3年前
Java日期时间API系列36
　　十二时辰，古代劳动人民把一昼夜划分成十二个时段，每一个时段叫一个时辰。二十四小时和十二时辰对照表：时辰时间24时制子时深夜11：00凌晨01：0023：0001：00丑时上午01：00上午03：0001：0003：00寅时上午03：00上午0
1214
0
0
Wesley13 Wesley13
•
3年前
00：Java简单了解
浅谈Java之概述Java是SUN(StanfordUniversityNetwork)，斯坦福大学网络公司)1995年推出的一门高级编程语言。Java是一种面向Internet的编程语言。随着Java技术在web方面的不断成熟，已经成为Web应用程序的首选开发语言。Java是简单易学，完全面向对象，安全可靠，与平台无关的编程语言。
1252
0
0
Stella981 Stella981
•
3年前
Django中Admin中的一些参数配置
设置在列表中显示的字段，id为django模型默认的主键list_display('id','name','sex','profession','email','qq','phone','status','create_time')设置在列表可编辑字段list_editable
1167
0
0
Wesley13 Wesley13
•
3年前
MySQL部分从库上面因为大量的临时表tmp_table造成慢查询
背景描述Time:20190124T00:08:14.70572408:00User@Host:@Id:Schema:sentrymetaLast_errno:0Killed:0Query_time:0.315758Lock_
1513
0
0
Python进阶者 Python进阶者
•
10个月前
Excel中这日期老是出来00：00：00，怎么用Pandas把这个去除
大家好，我是皮皮。一、前言前几天在Python白银交流群【上海新年人】问了一个Pandas数据筛选的问题。问题如下：这日期老是出来00：00：00，怎么把这个去除。二、实现过程后来【论草莓如何成为冻干莓】给了一个思路和代码如下：pd.toexcel之前把这
505
0
0
Easter79
Easter79
Lv1
今生可爱与温柔，每一样都不能少。
文章
2.8k
粉丝
5
获赞
1.2k
热门文章
uni app video、视频播放开发
tmux的复制粘贴
tableau地图源之高德地图
storybook配置之基本配置和webpack配置
twint 安装及使用