在之前的一篇文章中，我介绍了一种调试手段：利用LD_PRELOAD机制，拦截动态链接器对动态库的符号解析，达到监控程序IO的目的。事实证明我还是太naive了，我们大可利用现成的工具——strace，来更好地完成这一项工作。

strace不只能跟踪程序IO，它能跟踪程序的所有系统调用，实现的基本手段是ptrace系统调用，不过实现细节还没研究过，今天只总结一下它的用法。

首先用strace来跟踪一下喜闻乐见的hello world：

#include <stdio.h>

int main()
{
    printf("Hello, world!\n");
    return 0;
}

$ gcc main.c -o main
$ strace ./main

输出是这样的（由于太长，省略了大部分内容）：

execve("./main", ["./main"], 0x7ffcea3db620 /* 33 vars */) = 0

......(太长省略)

write(1, "Hello, world!\n", 14Hello, world!
)         = 14
exit_group(0)                           = ?
+++ exited with 0 +++

所有系统调用被一一记录了下来，我们可以看出来，printf是通过write系统调用将字符串“Hello, world!\n”写到文件描述符为1的文件（即标准输出）中，从而输出到屏幕上的。

这就是strace最基本的用法，它还提供一些非常实用的参数，我们可以来看一下：

-e

这个参数可以用来过滤输出，它功能很多，具体可以查看strace的手册，我们只用其最基本的功能：跟踪特定的系统调用。

$ strace -e write ./main

输出瞬间清爽了：

write(1, "Hello, world!\n", 14Hello, world!
)         = 14
+++ exited with 0 +++

-k

这个参数可以用来输出堆栈，不过strace的帮助将其标记为了实验性功能。

$ strace -e write -k ./main

输出为：

write(1, "Hello, world!\n", 14Hello, world!
)         = 14
 > /lib/x86_64-linux-gnu/libc-2.27.so(__write+0x14) [0x110154]
 > /lib/x86_64-linux-gnu/libc-2.27.so(_IO_file_write+0x2d) [0x8b1bd]
 > /lib/x86_64-linux-gnu/libc-2.27.so(_IO_do_write+0xb1) [0x8cf51]
 > /lib/x86_64-linux-gnu/libc-2.27.so(_IO_file_overflow+0x103) [0x8d403]
 > /lib/x86_64-linux-gnu/libc-2.27.so(_IO_puts+0x1a2) [0x80b62]
 > /home/imred/Documents/Workspace/playground/strace_blog/main(main+0x10) [0x64a]
 > /lib/x86_64-linux-gnu/libc-2.27.so(__libc_start_main+0xe7) [0x21b97]
 > /home/imred/Documents/Workspace/playground/strace_blog/main(_start+0x2a) [0x55a]
+++ exited with 0 +++

-t/-tt

这组参数可以用来打印时间戳

-y

这个参数可以在打印文件描述符相关参数时同时把文件描述符对应的文件路径打印出来：

$ strace -e write -y ./main

输出为：

write(1</dev/pts/0>, "Hello, world!\n", 14Hello, world!
) = 14
+++ exited with 0 +++

可以看出来当前内容被输出到了序号为0的伪终端。

由于下面的参数与时间统计有关，所以最好调用耗时较长的系统调用来分析其作用，我使用的是usleep函数，它调用了nanosleep系统调用，代码为：

#include <unistd.h>

int main()
{
    for (int i = 0; i < 10; i++)
    {
        usleep(1000);
    }
    return 0;
}

-T

这个参数可以用来输出每个系统耗费的时间，这个时间是系统调用开始时间和结束时间之差。

$ strace -e nanosleep -T ./main

输出为：

nanosleep({tv_sec=0, tv_nsec=1000000}, NULL) = 0 <0.001089>
nanosleep({tv_sec=0, tv_nsec=1000000}, NULL) = 0 <0.001078>
nanosleep({tv_sec=0, tv_nsec=1000000}, NULL) = 0 <0.001972>
nanosleep({tv_sec=0, tv_nsec=1000000}, NULL) = 0 <0.001108>
nanosleep({tv_sec=0, tv_nsec=1000000}, NULL) = 0 <0.001139>
nanosleep({tv_sec=0, tv_nsec=1000000}, NULL) = 0 <0.001091>
nanosleep({tv_sec=0, tv_nsec=1000000}, NULL) = 0 <0.001093>
nanosleep({tv_sec=0, tv_nsec=1000000}, NULL) = 0 <0.001326>
nanosleep({tv_sec=0, tv_nsec=1000000}, NULL) = 0 <0.001029>
nanosleep({tv_sec=0, tv_nsec=1000000}, NULL) = 0 <0.001297>
+++ exited with 0 +++

看出来这时间统计的算不上十分准确，最大的误差甚至接近100%，不过这是strace的问题还是系统调用本身的问题并不确定，也还有可能是我使用了虚拟机的缘故。

-c

这个参数用来汇总系统调用的数据。

$ strace -c ./main

输出为：

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
  0.00    0.000000           0         1           read
  0.00    0.000000           0         2           close
  0.00    0.000000           0         8         7 stat
  0.00    0.000000           0         2           fstat
  0.00    0.000000           0         5           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         3         3 access
  0.00    0.000000           0        10           nanosleep
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0        10         8 openat
------ ----------- ----------- --------- --------- ----------------
100.00    0.000000                    49        18 total

能够分析出每种系统调用总的相对时间、总的绝对时间、平均开销、调用次数、出错次数信息。

你可能会比较奇怪为什么上面汇总出来的时间消耗都是0，至少nanosleep该消耗了时间。这是因为在默认情况下统计的都是系统时间，即进程在内核空间执行代码消耗的cpu时间，而不是墙上时间。调用了nanosleep虽然消耗了用户的时间，但并没有占用多少cpu时间，所以统计出来就是0了，如果要统计墙上时间，需要下面的这个选项。

-w

这个参数指定-c参数统计墙上时间。

$ strace -wc ./main

输出为：

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 97.95    0.015065        1507        10           nanosleep
  0.64    0.000098          98         1           execve
  0.38    0.000058           6        10         8 openat
  0.24    0.000037           5         8         7 stat
  0.20    0.000031           6         5           mmap
  0.18    0.000028           7         4           mprotect
  0.11    0.000017           6         3         3 access
  0.10    0.000016          16         1           munmap
  0.06    0.000009           5         2           fstat
  0.05    0.000008           4         2           close
  0.03    0.000005           5         1           read
  0.03    0.000005           5         1           brk
  0.03    0.000004           4         1           arch_prctl
------ ----------- ----------- --------- --------- ----------------
100.00    0.015381                    49        18 total

这回输出结果大致符合我们的预期了（虽然误差很大）。

-f

这个参数指定strace要跟踪从主线程衍生出来的其他线程和进程。

对于下面的程序：

#include <thread>
#include <unistd.h>

void loopSleep()
{
    for (int i = 0; i < 10; i++)
    {
        usleep(1000);
    }
}

int main()
{
    std::thread t1([](){ loopSleep(); });
    std::thread t2([](){ loopSleep(); });

    t1.join();
    t2.join();

    return 0;
}

nanosleep都没有在主线程调用，如果我们直接这样调用strace的话：

$ strace -e nanosleep ./main

其输出为：

+++ exited with 0 +++

并没有追踪到nanosleep的调用。这时就需要指定-f参数了：

$ strace -e nanosleep -f ./main

其输出为：

strace: Process 4623 attached
[pid  4623] nanosleep({tv_sec=0, tv_nsec=1000000}, strace: Process 4622 attached
 <unfinished ...>
[pid  4622] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4623] <... nanosleep resumed> NULL) = 0
[pid  4623] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4622] <... nanosleep resumed> NULL) = 0
[pid  4622] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4623] <... nanosleep resumed> NULL) = 0
[pid  4623] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4622] <... nanosleep resumed> NULL) = 0
[pid  4622] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4623] <... nanosleep resumed> NULL) = 0
[pid  4623] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4622] <... nanosleep resumed> NULL) = 0
[pid  4622] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4623] <... nanosleep resumed> NULL) = 0
[pid  4623] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4622] <... nanosleep resumed> NULL) = 0
[pid  4622] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4623] <... nanosleep resumed> NULL) = 0
[pid  4623] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4622] <... nanosleep resumed> NULL) = 0
[pid  4622] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4623] <... nanosleep resumed> NULL) = 0
[pid  4623] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4622] <... nanosleep resumed> NULL) = 0
[pid  4622] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4623] <... nanosleep resumed> NULL) = 0
[pid  4623] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4622] <... nanosleep resumed> NULL) = 0
[pid  4622] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4623] <... nanosleep resumed> NULL) = 0
[pid  4623] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4622] <... nanosleep resumed> NULL) = 0
[pid  4622] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4623] <... nanosleep resumed> NULL) = 0
[pid  4623] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4622] <... nanosleep resumed> NULL) = 0
[pid  4622] nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
[pid  4623] <... nanosleep resumed> NULL) = 0
[pid  4623] +++ exited with 0 +++
[pid  4622] <... nanosleep resumed> NULL) = 0
[pid  4622] +++ exited with 0 +++
+++ exited with 0 +++

追踪到了我们指定的nanosleep系统调用。

-p

这个参数指定strace连接到指定进程上。

以上就是strace这把“锤子”的大致使用手册，但是如何把我们当前遇到的问题归约成“钉子”就没有手册可以参考了，需要各位各显神通了。

13. int stime(const time_t *when)

头文件：#include <time.h>

说明：该函数用于设置系统日期和时间，需要root权限，其内部实现是调用settimeofday。

返回值：成功返回0，失败返回-1，错误码存于errno

示例：

#include <time.h>
#include <errno.h>
#include <stdio.h>

int main(int argc, char *argv[])
{
	int ret = -1;
	time_t t = 3600*2;
	time_t now = time(NULL);
	printf("System old time: %s\n", ctime(&now));
	ret = stime(&t);
	if (ret == 0) {
		now = time(NULL);
		printf("System new time: %s\n", ctime(&now));
	} else {
		printf("stime error, code: %d\n", errno);
	}
	return 0;
}

运行结果：

14. size_t strftime(char *s, size_t maxsize, const char *format, const struct tm *tp)

头文件：#include <time.h>

说明：该函数主要用于格式化时间字符串，它根据format指向的字符串中格式命令把tp中保存的时间信息放在s指向的字符串中，最多向s中存放maxsize个字符。

返回值：返回储存到s的字符数。

示例：

#include <time.h>
#include <stdio.h>

int main(int argc, char *argv[])
{
	struct tm *p;
	char buf[128] = {0};
	time_t now = time(NULL);
	p=localtime(&now);
	printf("System now time: %s\n", asctime(p));
	strftime(buf, sizeof(buf), "Now is: %A %B %d %T %Y\n", p);
	printf("%s", buf);
	return 0;
}

运行结果：

15. char *strptime(const char *buf, const char *format, struct tm *tm)

头文件：#include <time.h>

说明：该函数用于将特定时间格式字符串转换为tm时间类型。

返回值：成功返回指向此函数调用中未处理的第一个字符的指针，失败返回空指针

示例：

#include <time.h>
#include <stdio.h>

int main(int argc, char *argv[])
{
	struct tm timeinfo;
	char buf[] = "2020-1-6 18:00:00";
	char fmt[] = "%Y-%m-%d %H:%M:%S";
	if (strptime(buf, fmt, &timeinfo) != NULL) {
		printf("Format time: %s\n", asctime(&timeinfo));
	}
	return 0;
}

运行结果：

16. int clock_gettime(clockid_t clock_id, struct timespec *tp)

头文件：#include <time.h>

说明：该函数可以根据clock_id，获取不同类型的精确时间（纳秒）。clock_id指定需要获取的时钟时间，常用的有4种时间：1）CLOCK_REALTIME，系统实时时间，随系统实时时间改变而改变（从UTC 1970-1-1 0:0:0开始计时）；2）CLOCK_MONOTONIC，从系统启动时刻起开始计时，不受系统时间改变的影响，不能被设置；3）CLOCK_PROCESS_CPUTIME_ID，本进程启动后至当前所占用系统处理器的时间；4）CLOCK_THREAD_CPUTIME_ID，本线程启动后至当前所占用系统处理器的时间。

返回值：成功返回0，失败返回-1

示例：

#include <time.h>
#include <stdio.h>

// 返回自系统开机以来的秒数（tick）
unsigned long GetTickCount()
{
	struct timespec ts;
	clock_gettime(CLOCK_MONOTONIC, &ts);
	return (ts.tv_sec*1000 + ts.tv_nsec/1000000);
}

int main(int argc, char *argv[])
{
	struct timespec t = {0, 0};

	clock_gettime(CLOCK_REALTIME, &t);
	printf("CLOCK_REALTIME: %ld, %ld\n", t.tv_sec, t.tv_nsec);
	clock_gettime(CLOCK_MONOTONIC, &t);
	printf("CLOCK_MONOTONIC: %ld, %ld\n", t.tv_sec, t.tv_nsec);
	clock_gettime(CLOCK_MONOTONIC_RAW, &t);
	printf("CLOCK_MONOTONIC_RAW: %ld, %ld\n", t.tv_sec, t.tv_nsec);
	clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &t);
	printf("CLOCK_PROCESS_CPUTIME_ID: %ld, %ld\n", t.tv_sec, t.tv_nsec);
	clock_gettime(CLOCK_THREAD_CPUTIME_ID, &t);
	printf("CLOCK_THREAD_CPUTIME_ID: %ld, %ld\n", t.tv_sec, t.tv_nsec);
	printf("Time now %ld\n", time(NULL));

	printf("Tick count %lums\n", GetTickCount());
	return 0;
}

运行结果：

17. int clock_settime(clockid_t clock_id, const struct timespec *tp)

头文件：#include <time.h>

说明：该函数主要用于设置系统时间，clock_id取值跟clock_gettime相同。

返回值：成功返回0，失败返回-1

示例：

#include <time.h>
#include <errno.h>
#include <stdio.h>

int main(int argc, char *argv[])
{
	int ret = -1;
	struct timespec tpset;
	time_t now = time(NULL);
	printf("System old time: %s\n", ctime(&now));
	tpset.tv_sec = 3600*2;
	tpset.tv_nsec = 0;
	ret = clock_settime(CLOCK_REALTIME, &tpset);
	if (ret == 0) {
		now = time(NULL);
		printf("System new time: %s\n", ctime(&now));
	} else {
		printf("clock_settime error, code: %d\n", errno);
	}
}

运行结果：

18. clock_t clock(void)

头文件：#include <time.h>

说明：该函数用于统计某个进程或函数占用处理器的时间。为了获取占用处理器所使用的秒数，需要除以CLOCKS_PER_SEC。不过一般使用gettimeofday替代。

返回值：成功返回自程序启动起，占用处理器时钟所使用的时间，失败返回-1

示例：

#include <time.h>
#include <stdio.h>

int main(int argc, char *argv[])
{
	double total = 0;
	clock_t t1, t2;

	t1 = clock();
	printf("t1=%ld\n", t1);
	for (int i=0; i< 10000000; i++) {
		;
	}
	t2 = clock();
	printf("t2=%ld\n", t2);
	total = (double)(t2 - t1)/CLOCKS_PER_SEC;
	printf("total time：%fs\n", total);
	return 0;
}

运行结果：

19. double difftime(time_t time1, time_t time0)

头文件：#include <time.h>

说明：该函数用于计算time1和time0之间相差的秒数 (time1 - time0)。这两个时间均表示自纪元 Epoch（协调世界时 UTC：1970-01-01 00:00:00）起经过的秒数。

返回值：两个时间之间相差的秒数

示例：

#include <time.h>
#include <stdio.h>
#include <unistd.h>

int main(int argc, char *argv[])
{
	double diff;
	time_t start, end;

	time(&start);
	printf("start=%ld\n", start);
	sleep(5);
	time(&end);
	printf("end=%ld\n", end);
	diff = difftime(end, start);
	printf("Total time consuming=%f\n", diff);
	return 0;
}

运行结果：

使用timerfd的好处是可以结合epoll或poll或select使用，当超时时间到时epoll等会返回可读。

1.

int timerfd_create(int clockid,int flags)

timerfd_create返回一个文件描述符，该文件描述符和定时器所关联。

clockid:

clockid可以为CLOCK_REALTIME或者CLOCK_MONOTONIC。最好使用CLOCK_MONOTONIC，这样的话即使你改变了系统时钟的话也不会受到影响，但是CLOCK_REALTIME会受到硬性。如果对这两个选项感兴趣的话可以自行去网上查写关于他们的资料。

flags:

flags可以是TFD_NONBLOCK、TFD_CLOEXEC的或。设置TFD_NONBLOCK代表把返回的文件描述符设置为非阻塞模式，这个和用fcntl设置该文件描述符的O_NONBLOCK的效果一样。设置TFP_CLOEXEC代表当执行exec时该文件描述符会自动关闭。

2.

int timerfd_settime(int fd,int flags,const struct itimerspec *new_value,struct itimerspec *old_value)

timerfd_settime可以启动或者停止定时器。

让我们先看看两个结构体：

                         struct timespec{

                                time_t  tv_sec;//秒数

                                long tv_nsec;//纳秒数

                       }

                      struct itimerspec{

                               struct timespec it_interval;

                               struct timespec it_value;

                     }

参数说明：

new_value.it_value：设置初始定时器时间。只要new_value.it_value中的tv_sec和tv_nsec有一个不为0，则启动定时器。把new_value.it_value中的tv_sec和tv_nsec都设为0，则停止定时器。（视flags而定，如果flags是0那么new_value.it_value就是相对值，如果flags是TFD_TIMER_ABSTIME，那么new_value.it_value就是绝对时间）

new_value.it_interval：设置定时时间间隔（定时器可以一直定时）。只要new_value.it_interval中的tv_sec和tv_nsec有一个不为0，那么就会在第一次超时之后把定时时间设为这个值。如果把tv_sec和tv_nsec都设为0，那么定时器只会定时一次，不会重复定时。（new_value.it_interval总是设置为相对时间）

flags：flags参数为0，表示启动相对计时器（new_value.it_value指定相对定时时间）， TFD_TIMER_ABSTIME用于启动绝对定时器（当时钟的值达到new_value中指定的值时，定时器将到期）。

old_value.it_value：表示上一次设置的定时器还有多久就到时间了(返回相对时间，不管flags设置成什么）

old_value.it_interval：返回上一次设置的值（总是返回相对时间）

3.

int timerfd_gettime(int fd,struct itimerspec *curr_value);

参数：

curr_value:返回还有多久定时器要到期,以及当前设置的循环定时周期。如果it_value中的中的tv_sec和tv_nsec都为0,那么表示定时器已经停止了。curr_value->it_interval返回当前甚至的循环定时周期，如果it_value中的中的tv_sec和tv_nsec都为0,表示该定时器只定时一次，不会循环定时（it_value和it_interval返回的总是相对值）

4.read的返回值

read(timerfd,buf,sizeof(buf));   buf应该是uint64_t。如果有超时时间发生，则从buf返回超时的次数。

1.如果没有设定O_NONBLOCK，则read阻塞，知道下一次超时时间到来。

2.如果设定了O_NONBLOCK，且没有超时时间发生，则置error为EAGAIN。

3.如果buf的大小小于8个字节，那么read置error为EINVAL。

下面附上一段测试程序：第一个参数为第一次超时什么时候发生，第二个参数为超时间隔设为多少，第三个参数为你想要发生多少次超时时间。程序可以在man timerfd_create的最后面找到。

#include <sys/timerfd.h>
#include <time.h>
#include <unistd.h>
#include <stdlib.h>
#include <stdio.h>
#include <stdint.h>        /* Definition of uint64_t */

#define handle_error(msg) \
               do { perror(msg); exit(EXIT_FAILURE); } while (0)

static void print_elapsed_time(void)
{
      static struct timespec start;
      struct timespec curr;
      static int first_call = 1;
      int secs, nsecs;

      if (first_call) {
          first_call = 0;
          if (clock_gettime(CLOCK_MONOTONIC, &start) == -1)
              handle_error("clock_gettime");
      }

      if (clock_gettime(CLOCK_MONOTONIC, &curr) == -1)
          handle_error("clock_gettime");

          secs = curr.tv_sec - start.tv_sec;
          nsecs = curr.tv_nsec - start.tv_nsec;
          if (nsecs < 0) {
              secs--;
              nsecs += 1000000000;
          }
          printf("%d.%03d: ", secs, (nsecs + 500000) / 1000000);
      }

int main(int argc, char *argv[])
{
           struct itimerspec new_value;
           int max_exp, fd;
           struct timespec now;
           uint64_t exp, tot_exp;
           ssize_t s;

           if ((argc != 2) && (argc != 4)) {
               fprintf(stderr, "%s init-secs [interval-secs max-exp]\n",
                       argv[0]);
               exit(EXIT_FAILURE);
           }

           if (clock_gettime(CLOCK_REALTIME, &now) == -1)
               handle_error("clock_gettime");

           /* Create a CLOCK_REALTIME absolute timer with initial
              expiration and interval as specified in command line */

           new_value.it_value.tv_sec = now.tv_sec + atoi(argv[1]);
           new_value.it_value.tv_nsec = now.tv_nsec;
           if (argc == 2) {
               new_value.it_interval.tv_sec = 0;
               max_exp = 1;
           } else {
               new_value.it_interval.tv_sec = atoi(argv[2]);
               max_exp = atoi(argv[3]);
           }
           new_value.it_interval.tv_nsec = 20;

           fd = timerfd_create(CLOCK_REALTIME, 0);
           if (fd == -1)
               handle_error("timerfd_create");

           if (timerfd_settime(fd,TFD_TIMER_ABSTIME, &new_value, NULL) == -1)
               handle_error("timerfd_settime");

      
       struct itimerspec old_value;
           if (timerfd_settime(fd, TFD_TIMER_ABSTIME, &new_value, &old_value) == -1)
               handle_error("timerfd_settime");
      
           print_elapsed_time();
           printf("timer started\n");

           for (tot_exp = 0; tot_exp < max_exp;) {
               s = read(fd, &exp, sizeof(uint64_t));
               if (s != sizeof(uint64_t))
                   handle_error("read");

               tot_exp += exp;
               print_elapsed_time();
               printf("read: %llu; total=%llu\n",
                       (unsigned long long) exp,
                       (unsigned long long) tot_exp);
           }

           exit(EXIT_SUCCESS);
}