Śledzenie PostgreSQL z perf

Narzędzie do profilowania perf dostarczany z jądrem Linuksa jest niezwykle przydatny do badania zachowania całego systemu i zachowania wieloprocesowego – ale robi o wiele więcej niż profilowanie procesora, do którego jest często używany. Prawdopodobnie spojrzałeś na perf top -az lub perf top -u postgres wyjście, ale to tylko niewielka część tego, co może zrobić. (Jeśli chcesz wersję TL/DR, przejdź do „Dynamicznych sond przestrzeni użytkownika”).

Jedna z największych zalet perf jest to, że nie jest inwazyjny. Nie musisz dołączać debugera i przerywać wykonywania. Nie musisz uruchamiać poleceń bezpośrednio pod profilerem w specjalnym środowisku. Nie ma potrzeby ponownego uruchamiania serwera w celu debugowania problematycznego obciążenia, a często nie ma potrzeby ponownej kompilacji z opcjami debugowania. Jest to niezwykle przydatne, gdy próbujesz wyśledzić problemy z wydajnością w systemie na żywo, ponieważ pozwala testować teorie dotyczące tego, co może się dziać szybko i przy minimalnym wpływie.

perf jest nie tylko profilerem, ale także obsługuje śledzenie. Profilowanie opiera się na próbkowaniu stanu systemu, gdy jest wyzwalany przez liczniki wydajności sprzętu lub oprogramowania; daje statystyczne próbkowanie punktów, w których system spędza najwięcej czasu. Śledzenie zamiast tego pobiera próbki za każdym razem, gdy wystąpi określone zdarzenie śledzenia, więc jest znacznie bardziej przydatne w przypadku rzadkich, ale ważnych zdarzeń.

Podczas pracy z PostgreSQL jedna z najbardziej ekscytujących funkcji perf to możliwość śledzenia procesów w przestrzeni użytkownika . Chcesz wiedzieć, jak często Twój PostgreSQL wymienia segmenty WAL, jak często sprawdza klucze obce itp.? Dla jednego backendu PostgreSQL czy całego klastra? perf może w tym pomóc.

Punkty śledzenia w przestrzeni użytkownika i w przestrzeni jądra można mieszać i można ich używać jednocześnie z profilowaniem liczników wydajności, aby uzyskać dobry obraz systemu. perf może przechwytywać ślady stosu zarówno z jądra, jak i przestrzeni użytkownika, a także może wykonywać wizualizacje statystyczne. Punkty śledzenia w przestrzeni użytkownika są tworzone za pomocą sond dynamicznych; te w przestrzeni jądra mogą być predefiniowane lub mogą być sondami dynamicznymi.

Jak więc korzystasz z niektórych z tych funkcji?

Zainstaluj narzędzia

Najpierw upewnij się, że używasz aktualnego perf . Ten artykuł został napisany w Fedorze 19 z perf 3.11.6 na x86_64, a niektóre funkcje są stosunkowo nowe.

Jeśli chcesz uzyskać wyniki stosu w przestrzeni użytkownika, będziesz chciał, aby kod, na który patrzysz, został zbudowany za pomocą -Og -ggdb -fno-omit-frame-pointer . Jeśli używasz perf zbudowany z libunwind nie potrzebujesz wskaźników ramek; zobacz ten post Stack Overflow i RH Bugzilla #1025603. Nic z tego nie jest potrzebne, jeśli interesują Cię tylko dane po stronie jądra. Jeśli używasz pakietów dystrybucyjnych, być może będziesz musiał zainstalować -debuginfo pakiety też.

Wszystkie poniższe testy zostały przeprowadzone z podstawowymi pakietami PGDG PostgreSQL 9.2 z http://yum.postgresql.org/ przy użyciu perf przebudowany za pomocą libunwind wsparcie zgodnie z powyższymi instrukcjami.

Punkty śledzenia jądra i sondy

perf może przechwytywać dane z predefiniowanych punktów śledzenia jądra, z których niektóre są przydatne podczas analizowania problemów z fragmentacją pamięci, dyskowymi operacjami we/wy itp. Listę punktów śledzenia można uzyskać za pomocą sudo perf list . Można określić listy punktów śledzenia i obsługiwane są symbole wieloznaczne. Na przykład, jeśli chcemy uzyskać statystyki zapisu i opróżniania dysku w działającej instancji PostgreSQL, możemy uruchomić:

rekord sudo perf -g karzeł -e blok:block_rq_issue,syscalls:sys_enter_fsync -u postgres sleep 10

do przechwytywania danych. Zamiast uśpienia możesz nie używać żadnego polecenia i nacisnąć Ctrl-C, gdy skończysz przechwytywanie, lub możesz użyć innego polecenia, takiego jak psql -c aby uruchomić obciążenie, które chcesz zmierzyć.

-u postgres profiluje wszystkie procesy działające jako użytkownik postgres . Zamiast tego możesz użyć -a do profilowania całego systemu na wszystkich procesorach. Możliwe jest również śledzenie tylko jednego zaplecza. Uruchom psql , uruchom wybierz pg_backend_pid() , uruchom perf z -p $the_pid , a następnie uruchom obciążenie w tym samym psql sesja.

Podczas pracy z PostgreSQL domyślnym procesem docelowym jest polecenie uruchamiane pod kontrolą perf , zwykle nie jest zbyt przydatne, ponieważ backend wykonuje większość pracy, a nie psql . Nadal przydatne jest używanie podkomendy do kontrolowania obciążenia testowego i czasu.

Po zebraniu danych możesz użyć raportu wydajności zbadać to. Jest tu zbyt wiele opcji do omówienia – kontrolowanie agregacji i uproszczenia wyników, wyświetlanie śladu stosu, interaktywnych curses vs wyjście raportu tekstowego i nie tylko.

Weźmy tę sesję jako przykład, gdzie jest sesja powłoki (terminal „T2”) i sesja postgres połączona z bazą danych „regress” (terminal „T1”):

T1| regress=> wybierz pg_backend_pid();T1| pg_backend_pid T1| ----------------T1| 4495T1|(1 wiersz)

T2| $ rekord sudo perf -g karzeł -e blok:block_rq_*,syscalls:sys_enter_write,syscalls:sys_enter_fsync -p 4495

T1| regress=> utwórz tabelę x jak wybierz Z generatora_serii(1,1000000) a;T1| regres=>

T2| $ ^CT2| [ rekord perf:obudzony 332 razy, aby zapisać dane ]T2| [ rekord perf:przechwycono i zapisano 86.404 MB perf.data (~3775041 próbek) ]T2|T2| $ raport o wydajności sudo -g

Możesz użyć raportu wydajności curses gui, aby zagłębić się w ślad, lub możesz użyć raport perf --stdio możliwość strumieniowego przesyłania danych na standardowe wyjście. Na przykład, jeśli chcesz śledzić stosy, możesz uruchomić:

$ sudo perf report -g --stdio... bla bla ...# Próbki:1 zdarzenia 'syscalls:sys_enter_fsync'# Liczba zdarzeń (w przybliżeniu):1## Ogólny symbol obiektu współdzielonego polecenia # .. ...... ........ ............. .....................# 100,00 % postgres libc-2.17.so [.] __GI___libc_fsync | --- __GI___libc_fsync mdimmedsync heap_sync intorel_shutdown standard_ExecutorRun ExecCreateTableAs PortalRunUtility PortalRunMulti PortalRun PostgresMain ServerLoop PostmasterMain main __libc_start_main _start (nil)... bla bla...

(Z jakiegoś powodu nie udało mi się jeszcze określić ostatecznej fsync() nie wydaje się być uchwycony przez perf kiedy psql jest uruchamiany bezpośrednio pod kontrolą perf . To nie jest problem ze statystykami wydajności , tylko rekord wydajności . Dlatego przeskakuję przez obręcze, aby wstępnie wybrać backend przez pid powyżej).

Dynamiczne sondy przestrzeni użytkownika

Czasami bardziej interesuje Cię coś, co dzieje się w samym PostgreSQL niż zdarzenia w jądrze, które są wyzwalane przez PostgreSQL. Nowsze wersje perf może w tym pomóc, wstawiając dynamiczne punkty śledzenia, które wyzwalają wywołania w programach w przestrzeni użytkownika.

Załóżmy, że jesteś zainteresowany oglądaniem aktywności WAL i chcesz zobaczyć, kiedy XLogFlush , XLogFileInit lub XLogFileOpen są nazywane. Możesz wstawić dynamiczne punkty śledzenia dla tych wywołań za pomocą perf :

sudo sonda perf -x `which postgres` XLogFileInitsudo perf sonda -x `that postgres` XLogFileOpensudo perf sonda -x `which postgres` XLogFlush

Możesz sondować tylko zewnętrzne symbole (niestatyczne, nie ukryte przez flagi -fvisibility), chyba że skompilowałeś za pomocą -ggdb . perf narzeka nie znaleziono symboli jeśli spróbujesz użyć symbolu, który nie istnieje. W momencie pisania perf nie obsługuje używania zewnętrznych informacji debugowania do wyszukiwania symboli dla sond, chociaż może używać ich do analizy stosu. Ogólnie, jeśli jest to extern w src/include możesz go używać z perf .

Każdy punkt śledzenia wyświetli nazwę utworzonego punktu śledzenia i możesz użyć perf probe -l aby mimo to je wszystkie wymienić:

$ sudo perf probe -l probe_postgres:XLogFileInit (na 0x000000000009a360) probe_postgres:XLogFileOpen (na 0x000000000009a860) probe_postgres:XLogFlush (na 0x00000000000a0670)

Te sondy są teraz używane jako zdarzenia perf. Przyjrzyjmy się aktywności xlog podczas przykładowego obciążenia, monitorując cały klaster podczas uruchamiania pgbench:

rekord wydajności sudo -g karzeł -u postgres -e probe_postgres:XLogFileInit,probe_postgres:XLogFileOpen,probe_postgres:XLogFlush

Wypróbuj sam z raportem perf -g . Oto jak wyglądają wyniki. Możesz użyć opcji takich jak -g fractal,0 kontrolować szczegóły. Będziesz mógł zobaczyć procent trafień danego licznika, które pochodziły z jednej lub innej gałęzi stosu, pid i proces itp. --sort opcje zapewniają większą kontrolę nad agregacją i grupowaniem.

Ale czekaj, jest więcej

Powinieneś również sprawdzić statystyki wydajności i perf top polecenia. Mogą wziąć te same listy zdarzeń, co rekord wydajności , chociaż z jakiegoś dziwnego powodu ich obsługa filtrów procesów jest inna.

Oto przykład, który uruchamia fikcyjne obciążenie i sprawdza punkty śledzenia jądra we/wy podczas wykonywania:

$ sudo perf stat -e block:block_rq_*,syscalls:sys_enter_write,syscalls:sys_enter_fsync -a -r 5 -- psql -q -U postgres craig -c "upuść tabelę, jeśli istnieje x; utwórz tabelę x jako wybierz a Z generate_series(1,1000000) a;"; Statystyki licznika wydajności dla 'psql -U postgres craig -c upuść tabelę, jeśli istnieje x; utwórz tabelę x as wybierz Z generate_series(1,1000000) a;' (5 przebiegów):0 block:block_rq_abort [100,00%] 0 block:block_rq_requeue [100,00%] 97 block:block_rq_complete ( +- 14,82% ) [100,00%] 96 block:block_rq_insert ( +- 14,97% ) [100,00%] 98 block:block_rq_issue ( +- 14,67% ) [100,00%] 0 block:block_rq_remap [100,00%]10 607 syscalls:sys_enter_write ( +- 0,17% ) [100,00%] 1 syscalls:sys_enter_fsync 0.908835058 sekund upłynęło (<- 18,31%) /pre> 

 Widać, że wykonuje średnio około 100 żądań we/wy w warstwie blokowej przez 10 000 operacji write() i wykonuje jedną operację fsync(). Niektóre z nich to szum w tle systemu, ponieważ robimy całe profilowanie systemu (-a ), ale ponieważ system jest dość bezczynny, to niewiele i jest uśredniony z pięciu przebiegów.
 

 Podobnie, korzystając z dynamicznych sond, które dodaliśmy wcześniej, obserwuj aktywność xlog podczas uruchamiania pgbench:
 
$ sudo perf stat -e probe_postgres:XLogFileInit,probe_postgres:XLogFileOpen,probe_postgres:XLogFlush -a -- /usr/pgsql-9.2/bin/pgbench -U postgres craig -c 2 -t 10000starting vacuum...end. typ transakcji:TPC-B (rodzaj)współczynnik skalowania:100tryb zapytania:prostyliczba klientów:2liczba wątków:1liczba transakcji na klienta:10000liczba faktycznie przetworzonych transakcji:20000/20000tps =715,854663 (w tym zestawianie połączeń)tps =716.092133 ( z wyłączeniem nawiązywania połączeń) Statystyki licznika wydajności dla '/usr/pgsql-9.2/bin/pgbench -U postgres craig -c 2 -t 10000':64 probe_postgres:XLogFileInit [100.00%] 0 probe_postgres:XLogFileOpen [100,00%] 55440 probe_postgres:XLogFlush 27.987364469 sekund, które upłynęły
 

 Możesz zrobić o wiele więcej, w tym przechwytywanie stanu zmiennych lokalnych za pomocą perf probe . Kilka przydatnych przykładów napiszę później. W międzyczasie baw się, eksploruj i baw się z nowym narzędziem diagnostycznym.
 

 Aktualizacja: Michael Paquier niedawno napisał powiązany artykuł o śledzeniu PostgreSQL za pomocą systemtap, który może zainteresować czytelników tego. Aby użyć tego podejścia, musisz ponownie skompilować Pg, ale składnia jest ładniejsza i oferuje inne zalety.