Process tracing could help identify all system calls the process made. This is very helpful for debugging a process if we don't have the source code base.
script_1:
#! /bin/bash
echo "Hello world!"
1. Trace all system calls script_1 has made:
terminal:
After running script_1 script, it outputs all system calls it has made.
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ strace ./script_1
execve("./script_1", ["./script_1"], [/* 64 vars */]) = 0
brk(0) = 0x9c64000
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb772e000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
......
read(255, "#! /bin/bash\n\necho \"Hello world!"..., 34) = 34
write(1, "Hello world!\n", 13Hello world!
) = 13
read(255, "", 34) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
exit_group(0) = ?
+++ exited with 0 +++
2. Trace only specified system calls script_1 has made:
terminal:
1) Only output the "write" system call script_1 has made
2) Output the "read" and "write" system call script_1 has made
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ strace -e write ./script_1
write(1, "Hello world!\n", 13Hello world!
) = 13
+++ exited with 0 +++
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ strace -e trace=open,write ./script_1
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
open("/lib/i386-linux-gnu/libtinfo.so.5", O_RDONLY|O_CLOEXEC) = 3
open("/lib/i386-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
open("/lib/i386-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
open("/dev/tty", O_RDWR|O_NONBLOCK|O_LARGEFILE) = 3
open("/usr/lib/locale/locale-archive", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
open("/proc/meminfo", O_RDONLY|O_CLOEXEC) = 3
open("/usr/lib/i386-linux-gnu/gconv/gconv-modules.cache", O_RDONLY) = 3
open("./script_1", O_RDONLY|O_LARGEFILE) = 3
write(1, "Hello world!\n", 13Hello world!
) = 13
+++ exited with 0 +++
3. Output the tracing result to external file
terminal:
1) run strace command to output only "write" system call script_1 has made, output the tracing result to external file trace.txt
2) Print out the file content of trace.txt
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ strace -e write -o trace.txt ./script_1
Hello world!
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ cat ./trace.txt
write(1, "Hello world!\n", 13) = 13
+++ exited with 0 +++
4. Trace the running process
script_2:
This is a simple process which is doing non-stop loop
#! /bin/bash
a=1
while [ $a -ne 0 ]
do
((a++))
sleep 5
done
terminal:
1) Run ps command , script_2 is already launched
2) Use root user(we have to use root user in this case), to monitor the system call made by process with id 3519, which is script_2. Then it will keep outputting the system call list.
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ ps
PID TTY TIME CMD
2833 pts/1 00:00:00 bash
2968 pts/1 00:00:17 emacs
3519 pts/1 00:00:00 script_2
3554 pts/1 00:00:00 sleep
3555 pts/1 00:00:00 ps
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ sudo strace -p 3519
Process 3519 attached
waitpid(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0) = 3557
rt_sigaction(SIGINT, {SIG_DFL, [], 0}, {0x8087c50, [], 0}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=3557, si_status=0, si_utime=0, si_stime=2} ---
waitpid(-1, 0xbfd244f8, WNOHANG) = -1 ECHILD (No child processes)
sigreturn() (mask []) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
......
5. Trace the process with timestamp
terminal:
-t option will make strace output the command
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ strace -t -e trace=open,write ./script_1
11:29:40 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
11:29:40 open("/lib/i386-linux-gnu/libtinfo.so.5", O_RDONLY|O_CLOEXEC) = 3
11:29:40 open("/lib/i386-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
11:29:40 open("/lib/i386-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
11:29:40 open("/dev/tty", O_RDWR|O_NONBLOCK|O_LARGEFILE) = 3
11:29:40 open("/usr/lib/locale/locale-archive", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
11:29:40 open("/proc/meminfo", O_RDONLY|O_CLOEXEC) = 3
11:29:40 open("/usr/lib/i386-linux-gnu/gconv/gconv-modules.cache", O_RDONLY) = 3
11:29:40 open("./script_1", O_RDONLY|O_LARGEFILE) = 3
11:29:40 write(1, "Hello world!\n", 13Hello world!
) = 13
11:29:40 +++ exited with 0 +++
6. Trace the process with relative execution time
terminal:
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ strace -r -e trace=open,write ./script_1
0.000000 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
0.003371 open("/lib/i386-linux-gnu/libtinfo.so.5", O_RDONLY|O_CLOEXEC) = 3
0.015814 open("/lib/i386-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
0.001950 open("/lib/i386-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
0.020927 open("/dev/tty", O_RDWR|O_NONBLOCK|O_LARGEFILE) = 3
0.001489 open("/usr/lib/locale/locale-archive", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
0.011242 open("/proc/meminfo", O_RDONLY|O_CLOEXEC) = 3
0.009761 open("/usr/lib/i386-linux-gnu/gconv/gconv-modules.cache", O_RDONLY) = 3
0.021213 open("./script_1", O_RDONLY|O_LARGEFILE) = 3
0.005412 write(1, "Hello world!\n", 13Hello world!
) = 13
0.008233 +++ exited with 0 +++
7. Trace the process with system calls report
terminal:
-c option will make strace command to generate a statistics report for all system calls. In this case, it indicates that open has been launched 9 times, write has been launched 1 time.
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ strace -c -e trace=open,write ./script_1
Hello world!
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
100.00 0.000319 35 9 open
0.00 0.000000 0 1 write
------ ----------- ----------- --------- --------- ----------------
100.00 0.000319 10 total
8. Process Accounting
Whenever we run a process, it would generate the accounting information at system files. We can output the these accounting information, to know what kind of processes have been launched from the very beginning.
terminal:
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ sa | head -n 10
1553 516.40re 1.17cp 0avio 1344k
65 101.18re 0.26cp 0avio 2446k ***other*
2 0.44re 0.21cp 0avio 22785k update-apt-xapi
908 81.84re 0.16cp 0avio 1055k sleep
5 0.19re 0.09cp 0avio 5012k command-not-fou
2 0.27re 0.08cp 0avio 1680k apt-get
4 62.64re 0.06cp 0avio 35264k unity-panel-ser
2 0.18re 0.06cp 0avio 994k mandb
27 2.73re 0.04cp 0avio 603k strace
2 0.39re 0.02cp 0avio 13126k ubuntu-sso-logi
9. /proc File system
Unix will save the process related information into files.
Location is /proc
terminal:
1) Run ps command to list current running process
2) List the folder /proc/5293, 5293 is the process id of script_2, that folder contains all process running information, which are organized as files.
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ ps
PID TTY TIME CMD
2833 pts/1 00:00:02 bash
5293 pts/1 00:00:10 script_2
7907 pts/1 00:00:07 emacs
8532 pts/1 00:00:00 sleep
8533 pts/1 00:00:00 ps
aubinxia@aubinxia-fastdev:~/Desktop/xxdev$ ls /proc/5293
attr comm fd loginuid mountstats pagemap sessionid syscall
autogroup coredump_filter fdinfo map_files net personality smaps task
auxv cpuset gid_map maps ns projid_map stack timers
cgroup cwd io mem oom_adj root stat uid_map
clear_refs environ latency mountinfo oom_score sched statm wchan
cmdline exe limits mounts oom_score_adj schedstat status
