[20190314]使用strace注意的问题.txt
--//使用strace跟踪进程,我发现我自己忽略一个问题.一般看函数调用花费时间一般使用如下参数:
-r Print a relative timestamp upon entry to each system call. This records the time difference between the beginning
of successive system calls.
-t Prefix each line of the trace with the time of day.
-tt If given twice, the time printed will include the microseconds.
-ttt If given thrice, the time printed will include the microseconds and the leading portion will be printed as the
number of seconds since the epoch.
-T Show the time spent in system calls. This records the time difference between the beginning and the end of each
system call.
--//注意-T,-r参数的区别.-T显示的system calls的时间,显示在最后.
--//-r 显示相对时间,显示在前面.
--//通过例子说明:
$ export TNS_ADMIN=/tmp
--//在tmp目录下建立如下文件:
$ cat tnsnames.ora
CLIENT_CON =
(DESCRIPTION =
(LOAD_BALANCE=OFF)
(TRANSPORT_CONNECT_TIMEOUT=1)
(ADDRESS = (PROTOCOL = TCP)(HOST =10.10.10.10)(PORT = 1522))
(ADDRESS = (PROTOCOL = TCP)(HOST =11.11.11.11)(PORT = 1522))
(ADDRESS = (PROTOCOL = TCP)(HOST =12.12.12.12)(PORT = 1522))
(ADDRESS = (PROTOCOL = TCP)(HOST =13.13.13.13)(PORT = 1522))
(ADDRESS = (PROTOCOL = TCP)(HOST =14.14.14.14)(PORT = 1522))
(ADDRESS = (PROTOCOL = TCP)(HOST =15.15.15.15)(PORT = 1522))
(CONNECT_DATA =
(SERVER = DEDICATED)
(SERVICE_NAME = orclgg)
))
$ strace -r -tT -f tnsping client_con 2>&1 | grep -C1 -E 'poll'
0.000084 mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0c2342a000 <0.000023>
0.000078 poll([{fd=4, events=POLLOUT}], 1, 1000) = 0 (Timeout) <1.001095>
1.001171 close(4) = 0 <0.000076>
--
0.000122 times({tms_utime=0, tms_stime=0, tms_cutime=0, tms_cstime=0}) = 10709770534 <0.000027>
0.000085 poll([{fd=4, events=POLLOUT}], 1, 1000) = 0 (Timeout) <1.001072>
1.001181 close(4) = 0 <0.000111>
--
0.000128 times({tms_utime=0, tms_stime=0, tms_cutime=0, tms_cstime=0}) = 10709770634 <0.000026>
0.000084 poll([{fd=4, events=POLLOUT}], 1, 1000) = 0 (Timeout) <1.001086>
1.001340 close(4) = 0 <0.000055>
--
0.000126 times({tms_utime=0, tms_stime=0, tms_cutime=0, tms_cstime=0}) = 10709770735 <0.000056>
0.000116 poll([{fd=4, events=POLLOUT}], 1, 1000) = 0 (Timeout) <1.001093>
1.001261 close(4) = 0 <0.000080>
--
0.000125 times({tms_utime=1, tms_stime=0, tms_cutime=0, tms_cstime=0}) = 10709770835 <0.000027>
0.000084 poll([{fd=4, events=POLLOUT}], 1, 1000) = 0 (Timeout) <1.001079>
1.001265 close(4) = 0 <0.000082>
--
0.000120 times({tms_utime=1, tms_stime=0, tms_cutime=0, tms_cstime=0}) = 10709770935 <0.000027>
0.000085 poll([{fd=4, events=POLLOUT}], 1, 1000) = 0 (Timeout) <1.001085>
1.001255 close(4) = 0 <0.000055>
--//说明-C1,显示匹配poll前后1行.
--//另外可以发现-t显示时间的参数如下,在使用-r参数时.
--//-r显示的时间在前面,不可能close花费1秒,实际上poll调用后,调用close前的时间.
--//-T显示的时间在后面,这个是system call花费的时间.
--//注意这些区别对于诊断问题帮助很大.遇到不熟悉的函数可以使用man查看,比如:
$ man poll
POLL(2) Linux Programmer's Manual POLL(2)
NAME
poll, ppoll - wait for some event on a file descriptor
SYNOPSIS
#include <poll.h>
int poll(struct pollfd *fds, nfds_t nfds, int timeout);
#define _GNU_SOURCE
#include <poll.h>
int ppoll(struct pollfd *fds, nfds_t nfds,
const struct timespec *timeout, const sigset_t *sigmask);
DESCRIPTION
poll() performs a similar task to select(2): it waits for one of a set of file descriptors to become ready to perform I/O.
The set of file descriptors to be monitored is specified in the fds argument, which is an array of nfds
structures of the following form:
struct pollfd {
int fd; /* file descriptor */
short events; /* requested events */
short revents; /* returned events */
};
The field fd contains a file descriptor for an open file.
来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/267265/viewspace-2638331/,如需转载,请注明出处,否则将追究法律责任。
转载于:http://blog.itpub.net/267265/viewspace-2638331/