[LINUX] User program tracing with SystemTap Part 1

First of all, what is SystemTap?

A tool for investigating the behavior of the Linux kernel. It is also available for user programs in the RHEL7 (CentOS7) kernel and Systemtap.

The official web page and Red Hat have clear and detailed documentation. SystemTap Documentation (Official English) SystemTap Examples. SystemTap Beginner's Guide (Red Hat Japanese) SystemTap Tapset Reference (Red Hat Japanese)

Very helpful article on Qiita How to use SystemTap (User-Space Probing) How to use SystemTap

I want to trace the program with as little effort as possible

Before reading the source, when investigating how the target program works Have you ever wanted to see how a function is called by displaying a list of function arguments and their values and return values? I have This is especially true when class inheritance is used in C ++ or when reading the source of an unfamiliar paradigm.

This time, I will show you how to trace when it was compiled with the -g option or when it is recompiled with the "-g -O0" option but the source code is not changed. (Next time, I will show you the case of editing the source code to trace the movement when developing your own program.)

Examples with sample code

I will describe the implementation procedure as a memorandum. Shows the SystemTap script, C ++ source code, systemtap execution method and execution result.

Suppose you have two files under the / home / TestProgs / tr1 / directory, "tr1.cpp" and "ttr2.stp" shown below.

System Tap script for tracing

/home/TestProgs/tr1/ttr2.stp


#!/usr/bin/stap
//Execution method example> stap -v ttr2.stp 'process("/home/TestProgs/tr1/tr1")' 
// $1 indicates the first argument at startup. In the above example process("/home/TestProgs/tr1/tr1")But$Enter 1.

//Probe to process start
probe $1.begin
{
	printf("[proc begin] pid=%d,procname=%s\n", 
		pid(), 		//Process number
		execname()	//Executable file name
	);
}

//Probe to end of process
probe $1.end
{
	printf("[proc end] pid=%d,procname=%s\n", pid(), execname());
}


//Probe on system call
probe $1.syscall
{
	# open systemcall
	if( $syscall == 2) {
		printf("%s open(%s)\n",thread_indent(0),kernel_string($arg1))
	}
	# close systemcall
	else if ( $syscall == 3) {
		printf("%s close(%d)\n",thread_indent(0), $arg1)
	}
	//system call number is"ausyscall --dump"It can be obtained with the command of.
}

//Probe to the start of a function
probe $1.function("*").call
{
	printf("%s-->%s(%s) @%s %s\n",
		thread_indent(0),	
		ppfunc(),					//Function name(Class name and namespace are not displayed)
		$$parms, 					//Argument list
		usymfileline(addr()),		//File name and line number
		probefunc() 				//Function name(Not demangled)
	);
	thread_indent(1);	//
} 

//Probe to the end of the function
probe $1.function("*").return
{
	thread_indent(-1);
	printf("%s<--%s,%s\n",
		thread_indent(0),
		ppfunc(),
		$$return				//Return value
	);
}

-The SystemTap script is similar to C and awk.

Sample C ++ source code

/home/TestProgs/tr1/tr1.cpp


#include <stdio.h>
#include <unistd.h>
#include <fcntl.h>
#include <sys/stat.h>
#include <assert.h>

class classSample1{
	public:
		classSample1(){};
		~classSample1(){};
		int func_C1()  
		{
			printf("classSample1::func_C1()\n");
			return 0;
		}
		int func_C2();
		int cnt_func_C2 = 0;
};

int classSample1::func_C2(){
	printf("classSample2::func_C2()\n");
	cnt_func_C2++;
	int l= cnt_func_C2 % 2;
	printf("cnt_func_C2 %d, l:%d\n",cnt_func_C2,l);
	assert(cnt_func_C2<5);	//Suspended as an example.
	return 0;
}


int funcSub1()
{
	printf("funcSub1\n");
	return 1;
}

int func1(int x)
{
	int fd;

	fd = open("/tmp/test1.txt", O_WRONLY|O_CREAT|O_TRUNC, 0666);
	printf("func1\n");
	close(fd);
	funcSub1();
	return 1;
}

int func2(int x)
{
	int fd;

	fd = open("/tmp/test2.txt", O_WRONLY|O_CREAT|O_TRUNC, 0666);
	printf("func2\n");
	close(fd);
	return 2;
}

int main(int argc, char *argv[])
{
	int ret=0;

	classSample1 c1; 

	for(;;) {
		ret = func1(10);
		sleep(2);

		ret = func2(20);
		sleep(2);

		ret = c1.func_C1();
		sleep(2);

		ret = c1.func_C2();
		sleep(2);
	}
	return ret;
}

Compile C ++ source code

> cd /home/TestProgs/tr1/
> gcc -Wall -g3 -O0 -std=c++11 tr1.cpp -o tr1 -lstdc++

Run Systap script

> stap -v ttr2.stp 'process("/home/TestProgs/tr1/tr1")'

Give the argument a string containing the full path to the executable. The parser result as shown below is output.

stdout


Pass 1: parsed user script and 491 library scripts using 243892virt/56392res/3316shr/53784data kb, in 790usr/30sys/826real ms.
WARNING: function _start return probe is blacklisted: keyword at ttr2.stp:45:1
 source: probe $1.function("*").return
         ^
Pass 2: analyzed script: 36 probes, 27 functions, 6 embeds, 2 globals using 246148virt/60044res/4600shr/56040data kb, in 100usr/100sys/195real ms.
Pass 3: translated to C into "/tmp/stapa1Sf5u/stap_174029a96504ce3d524d3ac8b34d4f54_38391_src.c" using 246296virt/60520res/4968shr/56188data kb, in 50usr/100sys/149real ms.
Pass 4: compiled C into "stap_174029a96504ce3d524d3ac8b34d4f54_38391.ko" in 3590usr/540sys/3979real ms.
Pass 5: starting run.

-Waiting for execution of the target program.

Open another shell and execute the target program

> cd /home/TestProgs/tr1/
> ./tr1

Output of SystemTap script ttr2.stp

stdout


[proc begin] pid=20693,procname=tr1
     0 tr1(20693): open(/etc/ld.so.cache)
     0 tr1(20693): close(3)
     0 tr1(20693): open(/lib64/libstdc++.so.6)
     0 tr1(20693): close(3)
     0 tr1(20693): open(/lib64/libgcc_s.so.1)
     0 tr1(20693): close(3)
     0 tr1(20693): open(/lib64/libc.so.6)
     0 tr1(20693): close(3)
     0 tr1(20693): open(/lib64/libm.so.6)
     0 tr1(20693): close(3)
     0 tr1(20693):-->_start() @0x400770 _start
    19 tr1(20693):-->__libc_csu_init() @0x400a60 __libc_csu_init
    46 tr1(20693): -->_init() @0x400698 _init
    57 tr1(20693): <--_init,
    60 tr1(20693): -->frame_dummy() @0x400830 frame_dummy
    68 tr1(20693):  -->register_tm_clones() @0x4007d0 register_tm_clones
    78 tr1(20693):  <--register_tm_clones,
    80 tr1(20693): <--frame_dummy,
    83 tr1(20693):<--__libc_csu_init,
    96 tr1(20693):-->main(argc=0x1 argv=0x7ffd32486188) @/home/TestProgs/tr1/tr1.cpp:59 main
   113 tr1(20693): -->classSample1(this=0x7ffd32486080) @/home/TestProgs/tr1/tr1.cpp:9 _ZN12classSample1C2Ev
   123 tr1(20693): <--classSample1,
   131 tr1(20693): -->func1(x=0xa) @/home/TestProgs/tr1/tr1.cpp:40 _Z5func1i
   144 tr1(20693):   open(/tmp/test1.txt)
   215 tr1(20693):   close(3)
   229 tr1(20693):  -->funcSub1() @/home/TestProgs/tr1/tr1.cpp:32 _Z8funcSub1v
   246 tr1(20693):  <--funcSub1,return=0x1
   250 tr1(20693): <--func1,return=0x1
2000657 tr1(20693): -->func2(x=0x14) @/home/TestProgs/tr1/tr1.cpp:51 _Z5func2i
2000684 tr1(20693):   open(/tmp/test2.txt)
2000762 tr1(20693):   close(3)
2000826 tr1(20693): <--func2,return=0x2
4002721 tr1(20693): -->func_C1(this=0x400770) @/home/TestProgs/tr1/tr1.cpp:11 _ZN12classSample17func_C1Ev
4002778 tr1(20693): <--func_C1,return=0x0
6002907 tr1(20693): -->func_C2(this=0x7ffd32486080) @/home/TestProgs/tr1/tr1.cpp:21 _ZN12classSample17func_C2Ev
6002994 tr1(20693): <--func_C2,return=0x0
8003121 tr1(20693): -->func1(x=0xa) @/home/TestProgs/tr1/tr1.cpp:40 _Z5func1i
8003149 tr1(20693):   open(/tmp/test1.txt)
8003228 tr1(20693):   close(3)
8003279 tr1(20693):  -->funcSub1() @/home/TestProgs/tr1/tr1.cpp:32 _Z8funcSub1v
8003310 tr1(20693):  <--funcSub1,return=0x1
8003317 tr1(20693): <--func1,return=0x1
10004527 tr1(20693): -->func2(x=0x14) @/home/TestProgs/tr1/tr1.cpp:51 _Z5func2i
10004555 tr1(20693):   open(/tmp/test2.txt)
10004633 tr1(20693):   close(3)
10004698 tr1(20693): <--func2,return=0x2
12004785 tr1(20693): -->func_C1(this=0x400770) @/home/TestProgs/tr1/tr1.cpp:11 _ZN12classSample17func_C1Ev
12004839 tr1(20693): <--func_C1,return=0x0
14005308 tr1(20693): -->func_C2(this=0x7ffd32486080) @/home/TestProgs/tr1/tr1.cpp:21 _ZN12classSample17func_C2Ev
14005365 tr1(20693): <--func_C2,return=0x0
16006063 tr1(20693): -->func1(x=0xa) @/home/TestProgs/tr1/tr1.cpp:40 _Z5func1i
16006091 tr1(20693):   open(/tmp/test1.txt)
16006169 tr1(20693):   close(3)
16006191 tr1(20693):  -->funcSub1() @/home/TestProgs/tr1/tr1.cpp:32 _Z8funcSub1v
16006220 tr1(20693):  <--funcSub1,return=0x1
16006227 tr1(20693): <--func1,return=0x1
18009385 tr1(20693): -->func2(x=0x14) @/home/TestProgs/tr1/tr1.cpp:51 _Z5func2i
18009412 tr1(20693):   open(/tmp/test2.txt)
18009488 tr1(20693):   close(3)
18009503 tr1(20693): <--func2,return=0x2
20010037 tr1(20693): -->func_C1(this=0x400770) @/home/TestProgs/tr1/tr1.cpp:11 _ZN12classSample17func_C1Ev
20010093 tr1(20693): <--func_C1,return=0x0
22011732 tr1(20693): -->func_C2(this=0x7ffd32486080) @/home/TestProgs/tr1/tr1.cpp:21 _ZN12classSample17func_C2Ev
22011789 tr1(20693): <--func_C2,return=0x0
24012358 tr1(20693): -->func1(x=0xa) @/home/TestProgs/tr1/tr1.cpp:40 _Z5func1i
24012385 tr1(20693):   open(/tmp/test1.txt)
24012460 tr1(20693):   close(3)
24012599 tr1(20693):  -->funcSub1() @/home/TestProgs/tr1/tr1.cpp:32 _Z8funcSub1v
24012750 tr1(20693):  <--funcSub1,return=0x1
24012757 tr1(20693): <--func1,return=0x1
26012971 tr1(20693): -->func2(x=0x14) @/home/TestProgs/tr1/tr1.cpp:51 _Z5func2i
26012999 tr1(20693):   open(/tmp/test2.txt)
26013074 tr1(20693):   close(3)
26013089 tr1(20693): <--func2,return=0x2
28013574 tr1(20693): -->func_C1(this=0x400770) @/home/TestProgs/tr1/tr1.cpp:11 _ZN12classSample17func_C1Ev
28013630 tr1(20693): <--func_C1,return=0x0
30015263 tr1(20693): -->func_C2(this=0x7ffd32486080) @/home/TestProgs/tr1/tr1.cpp:21 _ZN12classSample17func_C2Ev
30015319 tr1(20693): <--func_C2,return=0x0
32015746 tr1(20693): -->func1(x=0xa) @/home/TestProgs/tr1/tr1.cpp:40 _Z5func1i
32015773 tr1(20693):   open(/tmp/test1.txt)
32015848 tr1(20693):   close(3)
32015871 tr1(20693):  -->funcSub1() @/home/TestProgs/tr1/tr1.cpp:32 _Z8funcSub1v
32015900 tr1(20693):  <--funcSub1,return=0x1
32015907 tr1(20693): <--func1,return=0x1
34017409 tr1(20693): -->func2(x=0x14) @/home/TestProgs/tr1/tr1.cpp:51 _Z5func2i
34017436 tr1(20693):   open(/tmp/test2.txt)
34017515 tr1(20693):   close(3)
34017592 tr1(20693): <--func2,return=0x2
36018061 tr1(20693): -->func_C1(this=0x400770) @/home/TestProgs/tr1/tr1.cpp:11 _ZN12classSample17func_C1Ev
36018218 tr1(20693): <--func_C1,return=0x0
38020672 tr1(20693): -->func_C2(this=0x7ffd32486080) @/home/TestProgs/tr1/tr1.cpp:21 _ZN12classSample17func_C2Ev
[proc end] pid=20693,procname=tr1

A trace with the following characteristics is performed. -Indentation by function depth -List of function arguments and their values -Return value from the function -Detecting file open and close

I think there is enough information to see how the program works.

I wanted to do it, but I didn't know if it was possible

-I want to display the member function name of the class as demangled. -I want to display which return was exited in a function that has multiple returns. -I want to detect a core dump and display a backtrace.

If anyone knows, I would appreciate it if you could teach me.

Thank you for reading this far.

Recommended Posts

User program tracing with SystemTap Part 1
User program tracing with SystemTap Part 2
sandbox with neo4j part 10
Image processing with Python (Part 2)
Studying Python with freeCodeCamp part1
Bordering images with python Part 1
Scraping with Selenium + Python Part 1
Studying Python with freeCodeCamp part2
Image processing with Python (Part 1)
Solving Sudoku with Python (Part 2)
Image processing with Python (Part 3)
Scraping with Selenium + Python Part 2