Profileringsværktøjet perf som leveres med Linux-kernen er ekstremt nyttigt til at undersøge system-omfattende og multi-proces adfærd - men det gør meget mere end den CPU-profilering, det ofte bruges til. Du har sikkert set på perf top -az eller perf top -u postgres output, men det er kun den mindste smule af, hvad den kan. (Hvis du vil have TL/DR-versionen, skal du hoppe ned til "User space dynamic probes").
En af de store fordele ved perf er, at det er ikke-påtrængende. Du behøver ikke at vedhæfte en debugger og afbryde eksekveringen. Du behøver ikke at køre kommandoer direkte under en profiler i et særligt miljø. Der er ingen grund til at genstarte serveren for at fejlsøge en problematisk arbejdsbyrde, og ofte ingen grund til at genkompilere med debug-indstillinger. Dette er ekstremt nyttigt, når du forsøger at spore ydeevneproblemer i et live-system, da det lader dig teste teorier om, hvad der kan foregå hurtigt og med minimal indvirkning.
perf er ikke kun en profiler, den har også sporingsunderstøttelse. Profilering er baseret på sampling af systemets tilstand, når den udløses af hardware- eller softwareydelsestællere; det giver en statistisk stikprøve af punkter, hvor systemet bruger mest tid. Sporing tager i stedet prøver, når en bestemt sporingshændelse opstår, så det er meget mere nyttigt til sjældne, men vigtige hændelser.
Når du arbejder med PostgreSQL en af de mest spændende funktioner i perf er evnen til at spore processer i brugerrum . Vil du vide, hvor ofte din PostgreSQL udskifter WAL-segmenter, hvor ofte foretager den udenlandske nøgleopslag osv.? For én PostgreSQL-backend eller på tværs af hele klyngen? perf kan hjælpe med det.
User-space og kernel-space sporpunkter kan blandes og kan bruges samtidig med performance counter profilering for at hjælpe dig med at få et godt billede af systemet. perf kan fange stakspor fra både kerne og brugerrum, og kan også lave statistiske visualiseringer. Brugerplads-sporingspunkter oprettes med dynamiske sonder; kernel-space dem kan være foruddefinerede eller kan være dynamiske sonder.
Så hvordan bruger du nogle af disse funktioner?
Installer værktøjerne
Først skal du sikre dig, at du bruger en aktuel perf . Denne artikel blev skrevet på Fedora 19 med perf 3.11.6 på x86_64, og nogle af funktionerne er relativt nye.
Hvis du ønsker stakresultater med brugerplads, vil du have, at den kode, du ser på, skal bygges med -Og -ggdb -fno-omit-frame-pointer . Hvis du bruger en perf bygget med libunwind du behøver ikke frame-pointers; se dette Stack Overflow-indlæg og RH Bugzilla #1025603. Intet af dette er nødvendigt, hvis du kun er interesseret i kernesidedata. Hvis du bruger distro-pakker, skal du muligvis installere -debuginfo pakker også.
Alle følgende tests blev kørt med lager PGDG PostgreSQL 9.2 pakker fra http://yum.postgresql.org/ ved hjælp af en perf genopbygget med libunwind support i henhold til ovenstående instruktioner.
Kernesporingspunkter og sonder
perf kan fange data fra foruddefinerede kernesporingspunkter, hvoraf nogle er informative, når man ser på problemer med hukommelsesfragmentering, disk I/O osv. Du kan få en liste over sporingspunkter med sudo perf list . Sporpunktslister kan angives, og jokertegn understøttes. For eksempel, hvis vi ønsker at få skrive- og diskflush-statistik på en kørende PostgreSQL-instans, kan vi køre:
sudo perf record -g dwarf -e block:block_rq_issue,syscalls:sys_enter_fsync -u postgres sleep 10
at fange dataene. I stedet for en dvale kan du ikke bruge nogen kommando og trykke på kontrol-C, når du er færdig med at fange, eller du kan bruge en anden kommando som en psql -c for at udløse den arbejdsbyrde, du vil måle.
-u postgres profilerer alle processer, der kører som bruger postgres . Du kan i stedet bruge -a til profilering af hele systemet på tværs af alle CPU'er. Det er også muligt at spore kun én backend. Start psql , kør select pg_backend_pid() , kør perf med -p $the_pid , og start derefter arbejdsbyrden i den samme psql session.
Når du arbejder med PostgreSQL standardmålprocessen, som er kommandoen, der køres under kontrol af perf , er normalt ikke særlig nyttig, fordi backend'en udfører det meste af arbejdet, ikke psql . Det er stadig nyttigt at bruge underkommandoen til at kontrollere testarbejdsbelastningen og timingen.
Når du har fanget dataene, kan du bruge perf report at undersøge det. Der er for mange muligheder til at diskutere her – til at kontrollere resultatsammenlægning og forenkling, stacksporingsvisning, interaktive forbandelser vs tekstrapportoutput og mere.
Tag denne session som et eksempel, hvor der er en shell-session (terminal “T2”) og en postgres-session forbundet til databasen “regress” (terminal “T1”):
T1| regress=> vælg pg_backend_pid();T1| pg_backend_pid T1| ------------------T1| 4495T1|(1 række)
T2| $ sudo perf record -g dwarf -e blok:block_rq_*,syscalls:sys_enter_write,syscalls:sys_enter_fsync -p 4495
T1| regress=> opret tabel x som vælg en FROM generere_serie(1,1000000) a;T1| regress=>
T2| $ ^CT2| [perf record:Vågnet 332 gange for at skrive data ]T2| [perf record:Fangede og skrev 86.404 MB perf.data (~3775041 prøver) ]T2|T2| $ sudo perf rapport -g
Du kan bruge perf report 's forbandelser gui at grave ned i sporet, eller du kan bruge perf-rapporten --stdio mulighed for at få den til at streame data til stdout. For eksempel, hvis du vil have stakspor, kan du køre:
$ sudo perf report -g --stdio... blah blah ...# Eksempler:1 af hændelsen 'syscalls:sys_enter_fsync'# Hændelsesantal (ca.):1## Overhead Command Shared Object Symbol# .. ...... ........ ............. .....................# 100,00 % postgres libc-2.17.so [.] __GI___libc_fsync | --- __GI___libc_fsync mdimedsync heap_sync intorel_shutdown standard_ExecutorRun ExecCreateTableAs PortalRunUtility PortalRunMulti PortalRun PostgresMain ServerLoop PostmasterMain main __libc_start_main _start (nul)... blah blah blahviser det for begivenheden syscalls:sys_enter_fsync der var én hændelse med ovenstående stak, en fsync fremkaldt via ExecCreateTableAs .
(Af en grund har jeg endnu ikke været i stand til at fastgøre den endelige fsync() synes ikke at være fanget af perf når psql køres direkte under kontrol af perf . Dette er ikke et problem med perf stat , kun perf record . Det er derfor, jeg hopper gennem bøjler for at forhåndsvælge backend ved pid ovenfor.)
Dynamiske prober for brugerrum
Nogle gange er du mere interesseret i, at noget sker i PostgreSQL sig selv, end begivenheder i kernen, der udløses af PostgreSQL. Nyere versioner af perf kan hjælpe med dette ved at indsætte dynamiske sporpunkter, der udløser opkald i user-space-programmer.
Lad os sige, at du er interesseret i at se WAL-aktivitet og vil se, hvornår XLogFlush , XLogFileInit eller XLogFileOpen hedder. Du kan indsætte dynamiske sporpunkter for disse opkald med perf :
sudo perf probe -x `which postgres` XLogFileInitsudo perf probe -x `which postgres` XLogFileOpensudo perf probe -x `which postgres` XLogFlushDu kan kun undersøge eksterne symboler (ikke-statiske, ikke skjult af -fvisibility flag), medmindre du har bygget med -ggdb . perf vil klage over ingen symboler fundet hvis du prøver at bruge et symbol, der ikke eksisterer. I skrivende stund perf understøtter ikke brug af ekstern debuginfo til at finde symboler for prober, selvom den kan bruge den til stakanalyse. Generelt, hvis det er en ekstern i src/include du kan bruge det med perf .
Hvert sporingspunkt udskriver navnet på det oprettede sporingspunkt, og du kan bruge perf probe -l for at liste dem alle alligevel:
$ sudo perf probe -l probe_postgres:XLogFileInit (på 0x000000000009a360) probe_postgres:XLogFileOpen (på 0x000000000009a860) probe_postgres:XLogpres:XLogpre>07 (på 000000) Disse sonder kan nu bruges som perf-begivenheder. Lad os tage et kig på xlog-aktivitet under en prøvearbejdsbelastning, overvågning på tværs af hele klyngen, mens jeg laver en pgbench-kørsel:sudo perf record -g dwarf -u postgres -e probe_postgres:XLogFileInit,probe_postgres:XLogFileOpen,probe_postgres:XLogFlushPrøv det selv med perf report -g . Sådan ser resultaterne ud. Du kan bruge muligheder som -g fractal,0 at kontrollere detaljer. Du vil være i stand til at se procentdelen af en given tællers hits, der kom fra en eller anden stackgren, pid og proces osv. --sort muligheder giver dig mere kontrol over aggregering og gruppering.
Men vent, der er mere
Du bør også tjekke perf stat og perf top kommandoer. De kan tage de samme begivenhedslister som perf record , selvom deres procesfilterunderstøttelse af en eller anden underlig grund er anderledes.
Her er et eksempel, der kører en dummy-arbejdsbelastning og ser på I/O-kernens sporingspunkter under kørslen:
$ sudo perf stat -e blok:blok_rq_*,syscalls:sys_enter_write,syscalls:sys_enter_fsync -a -r 5 -- psql -q -U postgres craig -c "slip tabel hvis der findes x; opret tabel x som vælg en FROM generere_serie(1,1000000) a;"; Ydeevnetællerstatistik for 'psql -U postgres craig -c drop table, hvis der findes x; opret tabel x som vælg en FROM generere_serie(1,1000000) a;' (5 kørsler):0 block:block_rq_abort [100.00%] 0 block:block_rq_requeue [100.00%] 97 blok:blok_rq_complete ( +- 14.82% ) [100.00%] 96 blok:blok_rq_requeue [100.00%] 97 blok:blok_rq_complete ( +- 14.82% ) [100.00%] 96 blok:blok_rq_indsæt ( +- 0% 0.] 1.0 % blok:blok_rq_issue ( +- 14.67% ) [100.00%] 0 blok:blok_rq_remap [100.00%]10.607 syscalls:sys_enter_write ( +- 0.17% ) [100.00%] 1 syscalls:5_fsys 8. 8. 8. 8. sek. /pre>Du kan se, at den laver et gennemsnit på omkring 100 bloklags I/O-anmodninger over 10k skrive()s og laver en enkelt fsync(). Noget af det er systembaggrundsstøj, da vi laver al systemprofilering (-a ), men da systemet er temmelig inaktivt, er det ikke meget, og det er gennemsnittet over fem kørsler.
På samme måde kan du ved at bruge de dynamiske prober, vi tilføjede tidligere, holde øje med xlog-aktivitet under en pgbench-kørsel:
$ 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. transaktionstype:TPC-B (sort for) skaleringsfaktor:100forespørgselstilstand:simpelt antal klienter:2antal tråde:1antal transaktioner pr. klient:10000antal transaktioner, der faktisk er behandlet:20000/20000tps =715.854663 (inklusive 13029 koblinger) ekskl. oprettelse af forbindelser) Ydeevnetællerstatistik for '/usr/pgsql-9.2/bin/pgbench -U postgres craig -c 2 -t 10000':64 probe_postgres:XLogFileInit [100.00%] 0 probe_postgres:XLogFileOpen [%40] probe_postgres:XLogFileInit [100.00%] XLogFlush 27.987364469 sekunder forløbet tidDer er meget mere du kan gøre, herunder at fange tilstanden af lokale variabler med perf probe . Jeg vil skrive nogle nyttige eksempler på det senere. I mellemtiden kan du lege, udforske og have det sjovt med et nyt diagnoseværktøj.
Opdatering: Michael Paquier skrev for nylig en relateret artikel om sporing af PostgreSQL med systemtap, som kan være interessant for læsere af denne. Du skal omkompilere Pg for at bruge den tilgang, men syntaksen er pænere, og den giver nogle andre fordele.