Linux,  Programming

[Linux] uftrace 설치 및 사용법

C/C++ 프로그램 tracing을 위한 유용한 프로그램으로 김남형 님이 개발하셨다. 자세한 것은 reference 1번 github 주소를 참고 바란다.

1. Install

1.1 Source code download

$ git clone https://github.com/namhyung/uftrace.git

1.2 Dependent library install

$ apt-get install libelf-dev pandoc libpython2.7-dev libncursesw5-dev libcapstone-dev libdw-dev

1.3 Source code build

$ cd uftrace
$ make
$ make install

위와 같이 수행을 했는데 error가 발생했다.

  LINK     libmcount/libmcount.so
/home/uftrace/libmcount/mcount.op: In function `mcount_guard_recursion':
/home/uftrace/libmcount/mcount.c:283: undefined reference to `__asan_report_load1'
/home/uftrace/libmcount/mcount.c:295: undefined reference to `__asan_report_store1'
/home/uftrace/libmcount/mcount.op: In function `mcount_trace_finish':
/home/uftrace/libmcount/mcount.c:270: undefined reference to `__asan_report_load8'
/home/uftrace/libmcount/mcount.c:271: undefined reference to `__asan_report_load8'
.....
/home/uftrace/arch/x86_64/symbol.c:116: undefined reference to `__asan_version_mismatch_check_v8'
/home/uftrace/arch/x86_64/symbol.c:116: undefined reference to `__asan_register_globals'
/home/uftrace/arch/x86_64/mcount-entry.op: In function `asan.module_dtor':
/home/uftrace/arch/x86_64/symbol.c:116: undefined reference to `__asan_unregister_globals'
clang: error: linker command failed with exit code 1 (use -v to see invocation)
Makefile:213: recipe for target '/home/uftrace/libmcount/libmcount.so' failed
make: *** [/home/uftrace/libmcount/libmcount.so] Error 1

구글링 해보니 다음과 같이 특정 기능을 꺼보라고 개발자가 comment를 달아 놓은 것을 봤다.

$ cd uftrace
$ ./configure --without-capstone --prefix=[path]
$ make
$ make install

2. 사용법

$ gcc -pg
$ uftrace [command] [options] [program] [arguments]

위와 같은 방식으로 실행하게 되면 해당 프로그램을 실행하고 결과를 데이터로 저장하고 저장된 데이터를 분석한다. 사용 전에 코드를 build 할 때 반드시 -pg option을 넣어줘야 한다.

2.1 Record

만약 우리가 일반적으로 수행하는 ls같은 명령어를 분석하고자 할 때 사용할 수 있다.

$ which ls
/bin/ls
$ uftrace record --force /bin/ls # ls binary is not compiled with -pg option, so it requires --force option
$ ls
uftrace.data

2.2 Replay

이제 record로 저장한 uftrace data를 재수행해서 결과를 볼 수 있다.

$ uftrace replay
# DURATION     TID     FUNCTION
   1.231 us [  6296] | strrchr();
  13.084 us [  6296] | setlocale();
   1.084 us [  6296] | bindtextdomain();
   0.844 us [  6296] | textdomain();
   0.175 us [  6296] | __cxa_atexit();
   4.833 us [  6296] | isatty();
   0.167 us [  6296] | getenv();
   0.129 us [  6296] | getenv();
   0.520 us [  6296] | ioctl();
   0.136 us [  6296] | getenv();
   6.351 us [  6296] | getopt_long();
   0.356 us [  6296] | getenv();
   0.134 us [  6296] | getenv();
   0.231 us [  6296] | getenv();
   0.117 us [  6296] | getenv();
   0.132 us [  6296] | getenv();
   0.077 us [  6296] | __errno_location();
   0.128 us [  6296] | memcpy();
   0.077 us [  6296] | __errno_location();
   0.084 us [  6296] | memcpy();
   0.262 us [  6296] | getenv();
   0.244 us [  6296] | strlen();
   0.120 us [  6296] | memcpy();
   0.084 us [  6296] | __errno_location();
  10.874 us [  6296] | opendir();
  24.833 us [  6296] | readdir();
   0.157 us [  6296] | readdir();
   ...

2.3 Filter

특정 함수들부터 출력하거나, 빼는 기능들도 존재한다. 추가로 regular expression 기능도 제공한다.

OptionDescription
-F foofoo 함수부터 profile 결과를 출력한다. 즉 foo 함수 위에 수행된 결과는 출력하지 않는다.
-N foofoo 함수를 분석되는 함수에서 제외한다.
-N ^foofoo로 시작하는 함수를 제외하고 출력하는 기능이다.
-D 2Depth가 2인 함수까지 출력하는 기능이다.
$ uftrace -D 2 a.out
6310
# DURATION     TID     FUNCTION
   1.746 us [  6310] | __monstartup();
   0.237 us [  6310] | __cxa_atexit();
            [  6310] | main() {
   0.355 us [  6310] |   getpid();
            [  6310] |   printf() {
  14.040 us [  6310] |     /* linux:schedule */
  43.082 us [  6310] |   } /* printf */
   1.009 us [  6310] |   a();
  46.056 us [  6310] | } /* main */

2.4 Function return 확인

특정 함수의 return 값을 확인 할 수 있다.

$ uftrace -R [function]@retval [executable file] [arguments]
# Example
# uftrace -R foo@retval a.out

2.5 Trigger 기능

특정 함수 기준으로 특정 depth만큼을 보여 줄 수 있다.

$ uftrace -T [function]@depth=[depth number] [executable file] [arguments]
# Example
# uftrace -T foo@depth=1 a.out

추가적으로 특정 함수 시작 기준으로 어느시간 지난 뒤 함수들에 대해 출력하는 기능도 지원한다. 수행시간이 긴 function들에 대해 찾을 때 확인 가능할 것이다.

$ uftrace -T [function]@time=[time] [executable file] [arguments]
# Example
# uftrace -T foo@time=0.5us a.out

특정 함수에 대해서 색깔로 하이라이트를 할 수 있다.

$ uftrace -T [function]@color=[color] [executable file] [arguments]
# Example
# uftrace -T foo@color=red a.out

2.6 Kernel mode 진입

프로그램의 kernel mode쪽에 대해서도 확인 가능하다. 아래와 같이 수행하면 depth 2까지 kernel mode에 대해서 write 관련 함수들에 대해 포함해서 분석해준다. 참고로 kernel mode에 대해서 사용하려면 root 권한이 필요하다.

$ uftrace -K [depth] [executable file] [arguments]
# Example
# uftrace -K 2 -F *write@kernel a.out

2.7 Multi thread

Multi-threaded program에 대해 profiling 할 때 특정 thread만을 볼 수 있다.

$ uftrace replay --tid 6369
# DURATION     TID     FUNCTION
            [  6369] | foo() {
   0.275 us [  6369] |   bar();
   2.012 us [  6369] | } /* foo */

2.8 Report

우리가 수행한 프로그램을 분석해서 각 함수별 시간을 출력시켜준다. 반드시 수행 전 uftrace record를 통해 raw data를 추출해야한다.

$ uftrace report
  Total time   Self time       Calls  Function
  ==========  ==========  ==========  ====================
  539.646 us    1.777 us           1  main
  470.010 us   16.176 us           1  pthread_join
  453.834 us  453.834 us           1  linux:schedule
   67.291 us   67.291 us           1  pthread_create
    2.580 us    2.192 us           2  foo
    1.085 us    1.085 us           1  __monstartup
    0.388 us    0.388 us           2  bar
    0.208 us    0.208 us           1  __cxa_atexit

Report를 할 때 정렬하는 방식을 변경 할 수 있다.

OptionDescription
-s self기본적으론 total time을 기준으로 정렬해주지만 self time별로 정렬
–avg-total함수의 평균 시간을 출력

2.9 Information

시스템에 대한 정보를 출력한다.

$ uftrace info
# system information
# ==================
# program version     : v0.10-51-g5e60 ( x86_64 dwarf python perf sched )
# recorded on         : Sun Aug 22 10:31:02 2021
# cmdline             : uftrace record foobar
# cpu info            : Intel(R) Celeron(R) CPU J3355 @ 2.00GHz
# number of cpus      : 2 / 2 (online / possible)
# memory info         : 0.1 / 5.6 GB (free / total)
# system load         : 0.00 / 0.05 / 0.08 (1 / 5 / 15 min)
# kernel version      : Linux 4.4.59+
# hostname            : mercury
# distro              : "Ubuntu 18.04.5 LTS"
#
# process information
# ===================
# number of tasks     : 2
# task list           : 6367(foobar), 6369(foobar)
# exe image           : /home/shumin/workspace
# build id            : 72a8679cfaed31261df8eedea6ce691dee62fc54
# pattern             : regex
# exit status         : exited with code: 0
# elapsed time        : 0.006165801 sec
# cpu time            : 0.002 / 0.003 sec (sys / user)
# context switch      : 3 / 9 (voluntary / involuntary)
# max rss             : 4076 KB
# page fault          : 0 / 256 (major / minor)
# disk iops           : 0 / 8 (read / write)

Reference

  1. https://github.com/namhyung/uftrace

Leave a Reply

Your email address will not be published. Required fields are marked *