[TOC]

前言简述

在运维的日常工作中，故障处理和问题诊断是个主要的内容，也是必备的技能

0x00 系统诊断

strace 命令 - 可用于诊断、调试和教学的Linux用户空间跟踪器

描述:官方介绍 strace是一个可用于诊断、调试和教学的Linux用户空间跟踪器。我们用它来监控用户空间进程和内核的交互，比如系统调用、信号传递、进程状态变更等。其底层的实现方式是基于ptrace特性;

Q:strace究竟能做什么呢?

它作为一种动态跟踪工具，能够帮助运维高效地定位进程和服务故障。它像是一个侦探，通过系统调用的蛛丝马迹，告诉你异常的真相。
它能够打开应用进程的这个黑盒，通过系统调用的线索告诉你进程大概在干嘛。

Q:在进入strace使用的主题之前，我们的先理解什么是系统调用?

按维基百科中的解释，在计算机中，系统调用（英语：system call），又称为系统呼叫，指运行在用户空间的程序向操作系统内核请求需要更高权限运行的服务。
系统调用提供用户程序与操作系统之间的接口,在Linux系统上应用代码通过glibc库封装的函数间接使用系统调用。

操作系统的进程空间分为用户空间和内核空间：

  • 1.操作系统内核直接运行在硬件上，提供设备管理、内存管理、任务调度等功能。
  • 2.用户空间通过API请求内核空间的服务来完成其功能——内核提供给用户空间的这些API, 就是系统调用。

Linux内核目前有300多个系统调用，详细的列表以通过syscalls手册页查看,系统调用主要分为几类：

  • 文件和设备访问类 比如open/close/read/write/chmod等
  • 进程管理类 fork/clone/execve/exit/getpid等
  • 信号类 signal/sigaction/kill 等
  • 内存管理 brk/mmap/mlock等
  • 进程间通信IPC shmget/semget * 信号量，共享内存，消息队列等
  • 网络通信 socket/connect/sendto/sendmsg 等

Syntax & Parameter:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
# 安装
yum install -y strace

# 参数
strace [ -dffhiqrtttTvxx ] [ -acolumn ] [ -eexpr ] ... [ -ofile ] [-ppid ] ... [ -sstrsize ] [ -uusername ] [ -Evar=val ] ... [ -Evar ]... [ command [ arg ... ] ]
strace -c [ -eexpr ] ... [ -Ooverhead ] [ -Ssortby ] [ command [ arg... ] ]

# 参数:
-c 统计每一系统调用的所执行的时间,次数和出错的次数等. 
-d 输出strace关于标准错误的调试信息. 
-f 跟踪由fork调用所产生的子进程. 
-ff 如果提供-o filename,则所有进程的跟踪结果输出到相应的filename.pid中,pid是各进程的进程号. 
-F 尝试跟踪vfork调用.在-f时,vfork不被跟踪. 
-h 输出简要的帮助信息. 
-i 输出系统调用的入口指针. 
-q 禁止输出关于脱离的消息. 
-r 打印出相对时间关于,,每一个系统调用. 
-t 在输出中的每一行前加上时间信息. 
-tt 在输出中的每一行前加上时间信息,微秒级. 
-ttt 微秒级输出,以秒了表示时间. 
-T 显示每一调用所耗的时间. 
-v 输出所有的系统调用.一些调用关于环境变量,状态,输入输出等调用由于使用频繁,默认不输出. 
-V 输出strace的版本信息. 
-x 以十六进制形式输出非标准字符串 
-xx 所有字符串以十六进制形式输出. 
-a column 设置返回值的输出位置.默认 为40. 
-e expr 指定一个表达式,用来控制如何跟踪.格式如下: [qualifier=][!]value1[,value2]... 
  #qualifier只能是 trace,abbrev,verbose,raw,signal,read,write其中之一.value是用来限定的符号或数字.默认的 qualifier是 trace.感叹号是否定符号.
  #例如: -eopen等价于-e trace=open,表示只跟踪open调用.而-etrace!=open表示跟踪除了open以外的其他调用.有两个特殊的符号 all 和 none. 
  #注意有些shell使用!来执行历史记录里的命令,所以要使用\\.
-e trace=all  #只跟踪指定的系统 调用.例如:-e trace=open,close,rean,write表示只跟踪这四个系统调用.默认的为set=all. 
-e trace=file #只跟踪有关文件操作的系统调用. 
-e trace=process  #只跟踪有关进程控制的系统调用. 比如fork/exec/exit_group
-e trace=network  #跟踪与网络有关的所有系统调用. 比如socket/sendto/connect
-e trace=signal #跟踪所有与系统信号有关的系统调用. 比如kill/sigaction
-e trace=desc  #和文件描述符相关，比如write/read/select/epoll等
-e trace=ipc     #跟踪所有与进程通讯有关的系统调用 ，比如shmget等
-e execve   #跟踪某个脚本里面的执行程序
-e abbrev= #设定 strace输出的系统调用的结果集.-v 等与 abbrev=none.默认为abbrev=all. 
-e raw=   #将指定的系统调用的参数以十六进制显示. 
-e signal= #指定跟踪的系统信号.默认为all.如 signal=!SIGIO(或者signal=!io),表示不跟踪SIGIO信号. 
-e read=  #输出从指定文件中读出 的数据
-e write= #输出写入到指定文件中的数据.
-o filename  #将strace的输出写入文件filename 
-p pid  #跟踪指定的进程pid. (可跟踪多个进程PID)
-s strsize #指定输出的字符串的最大长度.默认为32.文件名一直全部输出. 
-u username #以username 的UID和GID执行被跟踪的命令

它的两种运行模式:
- 1.通过它启动要跟踪的进程(可以类似理解为沙箱进行程序运行分析) #strace ls -lh /var/log/messages
- 2.跟踪已经在运行的进程(在不中断进程执行的情况下理解它在干嘛) #strace -p <pid>

基础实例:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
# 0.简单的程序来演示strace的基本用法
$nano hello.c
#include<stdio.h>
int main()
{
  int a=0;
  printf("please input:\n");
  scanf("%d",&a);
  printf("%9d\n",a);                                                      
  return 0;
}

$gcc hello.c &&  ./a.out
# please input:
# 123
#       123

$strace -s 2049 ./a.out
# 从下图输出中可以得出系统首先调用execve开始一个新的进行，接着进行些环境的初始化操作，最后停顿在”read(0,"上面,此时等待执行到了我们的scanf函数之中并且输入1024数字格式,在调用write函数将格式化后的数值"1024″输出到屏幕，最后调用exit_group退出进行，完成整个程序的执行过程。

WeiyiGeek.实例0

WeiyiGeek.实例0


1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
# 1.跟踪nginx查看其启动时都访问了哪些文件
strace -tt -T -f -e trace=file -o /data/log/strace.log -s 1024 ./nginx

# 2.跟踪已启动的nginx(pid=23489)进程
strace -tt -T -v -f -e trace=file -o /data/log/strace.log -s 1024 -p 23489

# 3.指定跟踪相关的系统调用这里监控所有的系统调用
#  跟踪28979进程的所有系统调用（-e trace=all），并统计系统调用的花费时间，以及开始时间（并以可视化的时分秒格式显示），最后将记录结果存在output.txt文件里面。
strace -o output.txt -T -tt -e trace=all -p 28979

# 4.跟踪信号传递（此处还是以上面的hello.c代码与a.out为例）指定进程的pid号
[root@terminal-1 ~]$ ./a.out  #终端1 执行
# please input:
# 已终止
[root@terminal-1 ~]$ strace -s 1024 -p 2225 #终端2 跟踪进程信号
# strace: Process 2225 attached
# read(0, 0x7f9b2ab43000, 1024)           = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
# --- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=2277, si_uid=0} ---
#+++ killed by SIGTERM +++             #关键点 捕捉到终端停止信号
[root@terminal-1 ~]$ killall ./a.out  #终端3 kill掉./a.out进程


# 5.系统调用统计通过使用参数-c能将进程所有的系统调用做一个统计分析;
strace -c -o hello.txt ./a.out
# please input:
# 10247
#     10247
cat hello.txt 
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
  0.00    0.000000           0         2           read
  0.00    0.000000           0         2           write
  0.00    0.000000           0         2           open
  0.00    0.000000           0         2           close
  0.00    0.000000           0         4           fstat
  0.00    0.000000           0         9           mmap
  0.00    0.000000           0         4           mprotect
  0.00    0.000000           0         1           munmap
  0.00    0.000000           0         1           brk
  0.00    0.000000           0         1         1 access
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         1           arch_prctl
------ ----------- ----------- --------- --------- ----------------
100.00    0.000000                    30         1 total

# 6. 截断输出长度设置与限制跟踪特定的系统调用
strace -f -s10 -o text.txt -e execve ./a.out && cat text.txt
# please input:
# 1024
#      1024
# 2377  execve("./a.out", ["./a.out"], 0x7fff80272970 /* 26 vars */) = 0
# 2377  +++ exited with 0 +++

# 7. 系统调用计时，参数-T将每个系统所花费的时间打印出来
strace -T -tt -o hello1.txt ./a.out && cat hello1.txt

# 8. 查看进程打开的文件进行过滤
strace -e trace=file killall bt_uinfo_memcached 2>&1 | grep open | tail
WeiyiGeek.实例7系统调用计时

WeiyiGeek.实例7系统调用计时


1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
# 8.strace实战定位共享内存异常
# 有个服务启动时报错,错误日志大概告诉我们是获取共享内存出错通过strace看下
# shmget 267264 30097568: Invalid argument Can not get shm...exit!
strace -tt -f -e trace=ipc ./a_mon_svr ../conf/a_mon_svr.conf # 只跟踪和进程通信相关的系统调用。
# 输出结果:
# 22:46:36.351798 shmget(0x5feb, 12000, 0666) = 0
# 22:46:36.351939 shmat(0, 0, 0)          = ?
# Process 21406 attached
# 22:46:36.355439 shmget(0x41400, 30097568, 0666) = -1 EINVAL (Invalid argument)
# shmget 267264 30097568: Invalid argument
# Can not get shm...exit!

从strace输出我们知道是shmget系统调用出错了errno是EINVAL。同样查询下shmget手册页搜索EINVAL的错误码的说明:
# EINVAL A new segment was to be created and size < SHMMIN or size > SHMMAX, or no new segment was to be created, a segment with given key existed, but size is greater than the size of that segment
shmget设置EINVAL错误码的原因为下列之一：
* 要创建的共享内存段比 SHMMIN小 (一般是1个字节)
* 要创建的共享内存段比 SHMMAX 大 (内核参数kernel.shmmax配置)
* 指定key的共享内存段已存在，其大小和调用shmget时传递的值不同。

从strace输出看我们要连的共享内存key 0x41400, 指定的大小是30097568字节，明显与第1、2种情况不匹配。
那只剩下第三种情况使用ipcs看下是否真的是大小不匹配,可以看到已经0x41400这个key已经存在，并且其大小为30095516字节，和我们调用参数中的30097568不匹配于是产生了这个错误。
# ipcs -m | grep 41400
# key        shmid      owner      perms      bytes      nattch     status    
# 0x00041400 1015822    root       666        30095516   1

在我们这个案例里面导致共享内存大小不一致的原因是一组程序中，`其中一个编译为32位另外一个编译为64位`,代码里面使用了long这个变长int数据类型, 把两个程序都编译为64解决了这个问题。

补充示例:

1
2
3
4
# 1.使用 strace 追踪 sysctl 命令的系统调用可发现该命令最终是访问 `/proc/sys/vm/swappiness` 这个文件
sudo strace sysctl -w vm.swappiness = 0
cat /proc/sys/vm/swappiness
0

总结

  • 1.当发现进程或服务异常时我们可以通过strace命令进行快速定位异常原因;
  • 2.其可以让我们熟悉常用系统调用，能够更好地理解和使用strace命令;
  • 3.当目标进程卡死在用户态时strace没有输出，此时我们需要其他的跟踪手段，比如gdb/perf/SystemTap等。
    • 3.1) perf原因kernel支持
    • 3.2) ftrace kernel支持可编程
    • 3.3) systemtap 功能强大RedHat系统支持，对用户态，内核态逻辑都能探查，使用范围更广;

0x01 应用诊断