uftrace를 이용하여 postgreSQL을 분석해보았다

• uftrace라는 도구를 사용하여 postgreSQL을 분석해보았다.

• uftrace는 함수의 흐름을 추적하거나, 시간을 측정할 수 있는 프로파일링 도구이다.

• 이름의 유래는 리눅스 커널 함수를 트레이싱 할 수 있는 ftrace 라는 도구에서 앞에 유저 스페이스 함수도 추적할 수 있다는 user의 줄일말인 u가 붙은 것이다.

(cd "$BUILD" && \
 CFLAGS="-fpatchable-function-entry=5 -I/usr/include/mit-krb5 -I/usr/include/python3.8/ -fuse-ld=gold -ggdb -Og -g3 -fno-omit-frame-pointer -U HAVE_POSIX_FADVISE" LDFLAGS=-L/usr/lib/x86_64-linux-gnu/mit-krb5 "$SOURCE"/configure --silent --prefix="$INSTALL" --with-openssl --with-tcl --with-tclconfig=/usr/lib/tcl8.6 --with-perl --with-libxml --with-libxslt --with-python --with-gssapi --with-systemd --with-ldap --enable-nls --enable-debug --enable-cassert --enable-tap-tests --enable-depend && \
 # CFLAGS="-I/usr/include/mit-krb5 -fuse-ld=gold -ggdb -Og -g3 -fno-omit-frame-pointer -U HAVE_POSIX_FADVISE" LDFLAGS=-L/usr/lib/x86_64-linux-gnu/mit-krb5 "$SOURCE"/configure --silent --prefix="$INSTALL" --with-ssl=nss --with-tcl --with-tclconfig=/usr/lib/tcl8.6 --with-perl --with-libxml --with-libxslt --with-python --with-gssapi --with-systemd --with-ldap --enable-nls --enable-debug --enable-cassert --enable-tap-tests --enable-depend && \
 make -s -j4 PG_TEST_EXTRA='kerberos ssl' && \
 make -s -j4 install PG_TEST_EXTRA='kerberos ssl' && \
 make -s -j4 check PG_TEST_EXTRA='kerberos ssl' && \
 make -s -j4 world PG_TEST_EXTRA='kerberos ssl' && \
 make -s -j4 install-world PG_TEST_EXTRA='kerberos ssl' && \
 make -s -j4 check-world PG_TEST_EXTRA='kerberos ssl' -O PROVE_FLAGS=-j4 \
)

• 이건 내가 postgres를 빌드할 때 사용하는 configure 옵션인데, CFLAGS 옵션중에 -fpatchable-function-entry=5 를 추가하거나, -pg를 추가하면 함수 진입점을 내부적으로 표시를 하여 uftrace를 이용하여 분석 할 수 있다.

• 참고로, -fpatchable-function-entry=5 를 추가하는 방식은 최신 버전에서 사용할 수 있는 방법인데 -pg 방식에 비해서 오버헤드가 적은 방식이라고 알고 있다.

분석

• 참고로 현재 postgres를 uftrace로 분석하면 오류가 발생한다. 그 이유는 postgres에서 사용하는 라이브러리와 uftrace 사이의 문제가 있어서 그런데, 곧 해결될 예정이다.

• 하지만 우선은 --no-libcal 이라는 옵션을 통해서 이러한 문제를 우회할 수 있다.

uftace record -no-libcal --srcline ./postmaster -D ../data

• postgres의 서버를 uftrace를 통해서 분석함과 동시에 실행을 해보자.

• 해당 명령어를 실행하면 평상시와 다른게 없이 실행이 될 것이다.

• psql을 이용하여 서버에 접속을 하고 쿼리를 날리면 postmaster 서버에 수행되는 함수들이 기록이 된다.

• 서버를 종료하고 디렉터리를 확인하면 uftrace.data, uftrace.data.old 라는 파일이 생성되어 있을 것이다.

• uftrace replay 명령어를 통해서 트레이싱 된 함수들을 확인할 수 있다.

• main 함수부터 실행된 함수들이 기록이 된다.

• 만약 tui 모드로 확인하고 싶다면 uftrace tui 라는 명령어를 입력하면 tui 모드로 확인할 수 있다.

• tui 모드에서는 함수 목록을 접었다가 펼수 있으며, 가장 오래걸린 함수를 빠르게 찾을 수 있다.

• 그리고 함수에 커서를 가지고 간 상태에서 O 키를 누른다면 해당 소스로 넘어갈 수도 있다.

• 정말 유용하게 사용할 수 있을 것 같고, 좀 더 사용이 익숙해지면 쿼리에 따라서 postgres 내부가 어떻게 동작하고 분석할 수 있을 것 같다.

참고 문헌

• uftrace