Het profileringshulpprogramma perf die bij de Linux-kernel wordt geleverd, is buitengewoon handig voor het onderzoeken van systeembreed en multi-procesgedrag, maar het doet veel meer dan de CPU-profilering waarvoor het vaak wordt gebruikt. Je hebt waarschijnlijk gekeken naar perf top -az of perf top -u postgres output, maar dat is slechts het kleinste beetje van wat het kan doen. (Als je de TL/DR-versie wilt, spring dan naar beneden naar "Gebruikersruimte dynamische sondes").
Een van de grote voordelen van perf is dat het niet opdringerig is. U hoeft geen debugger toe te voegen en de uitvoering te onderbreken. U hoeft geen opdrachten direct onder een profiler in een speciale omgeving uit te voeren. Het is niet nodig om de server opnieuw te starten om een problematische werklast te debuggen, en vaak is het niet nodig om opnieuw te compileren met debug-opties. Dit is uitermate handig wanneer u prestatieproblemen in een live systeem probeert op te sporen, omdat u hiermee snel en met minimale impact theorieën kunt testen over wat er aan de hand kan zijn.
perf is niet alleen een profiler, het heeft ook ondersteuning voor tracering. Profilering is gebaseerd op steekproeven van de toestand van het systeem wanneer deze worden geactiveerd door prestatiemeters voor hardware of software; het geeft een statistische steekproef van punten waar het systeem de meeste tijd doorbrengt. Tracering neemt in plaats daarvan monsters wanneer een bepaalde traceergebeurtenis plaatsvindt, dus het is veel nuttiger voor zeldzame maar belangrijke gebeurtenissen.
Bij het werken met PostgreSQL is een van de meest opwindende functies van perf is de mogelijkheid om processen in de gebruikersruimte te traceren . Wilt u weten hoe vaak uw PostgreSQL WAL-segmenten verwisselt, hoe vaak buitenlandse sleutels worden opgezocht, enz.? Voor één PostgreSQL-backend of voor het hele cluster? perf kan daarbij helpen.
Tracepoints van gebruikersruimte en kernelruimte kunnen worden gecombineerd en kunnen tegelijkertijd worden gebruikt met prestatietellerprofilering om u te helpen een goed beeld van het systeem te krijgen. perf kan stacktraces van zowel de kernel als de gebruikersruimte vastleggen en kan ook statistische visualisaties doen. Tracepoints in de gebruikersruimte worden gemaakt met dynamische sondes; kernel-space kunnen vooraf gedefinieerd zijn of kunnen dynamische probes zijn.
Dus, hoe gebruik je sommige van deze functies?
Installeer de tools
Zorg er eerst voor dat je een huidige perf . gebruikt . Dit artikel is geschreven op Fedora 19 met perf 3.11.6 op x86_64, en sommige functies zijn relatief nieuw.
Als u resultaten van de gebruikersruimtestapel wilt, wilt u dat de code die u bekijkt, wordt gebouwd met -Og -ggdb -fno-omit-frame-pointer . Als je een perf . gebruikt gebouwd met libunwind je hebt geen frame-pointers nodig; zie deze Stack Overflow-post en RH Bugzilla #1025603. Dit is allemaal niet nodig als je alleen geïnteresseerd bent in kernel-side data. Als u distro-pakketten gebruikt, moet u mogelijk -debuginfo . installeren pakketten ook.
Alle volgende tests zijn uitgevoerd met standaard PGDG PostgreSQL 9.2-pakketten van http://yum.postgresql.org/ met een perf herbouwd met libunwind ondersteuning volgens de bovenstaande instructies.
Kernel-traceringspunten en sondes
perf kan gegevens vastleggen van vooraf gedefinieerde kernel-tracepoints, waarvan sommige informatief zijn bij het bekijken van problemen met geheugenfragmentatie, schijf-I/O, enz. U kunt een lijst met tracepoints krijgen met sudo perf list . Tracepoint-lijsten kunnen worden opgegeven en jokertekens worden ondersteund. Als we bijvoorbeeld schrijf- en schijfflush-statistieken willen krijgen voor een actieve PostgreSQL-instantie, kunnen we het volgende uitvoeren:
sudo perf record -g dwarf -e block:block_rq_issue,syscalls:sys_enter_fsync -u postgres sleep 10
om de gegevens vast te leggen. In plaats van een slaapstand kun je geen commando gebruiken en op control-C drukken als je klaar bent met vastleggen, of je kunt een ander commando gebruiken, zoals een psql -c om de werklast te activeren die u wilt meten.
-u postgres profielen van alle processen die worden uitgevoerd als gebruiker postgres . U kunt in plaats daarvan -a . gebruiken voor volledige systeemprofilering over alle CPU's. Het is ook mogelijk om slechts één backend te traceren. Start psql , voer select pg_backend_pid() uit , voer perf . uit met -p $the_pid , start dan de werklast in dezelfde psql sessie.
Wanneer u met PostgreSQL werkt, is het standaard doelproces, de opdracht die wordt uitgevoerd onder de besturing van perf , is meestal niet erg handig omdat de backend het meeste werk doet, niet psql . Het is nog steeds handig om het subcommando te gebruiken om de testwerklast en timing te regelen.
Zodra u de gegevens heeft verzameld, kunt u perf-rapport . gebruiken om het te onderzoeken. Er zijn te veel opties om hier te bespreken - om de aggregatie en vereenvoudiging van resultaten te regelen, de weergave van stapeltraceringen, interactieve vloeken versus de uitvoer van tekstrapporten en meer.
Neem deze sessie als voorbeeld, waar een shell-sessie (terminal "T2") en een postgres-sessie verbonden zijn met database "regress" (terminal "T1"):
T1| regress=> selecteer pg_backend_pid();T1| pg_backend_pid T1| ----------------T1| 4495T1|(1 rij)
T2| $ sudo perf record -g dwarf -e block:block_rq_*,syscalls:sys_enter_write,syscalls:sys_enter_fsync -p 4495
T1| regress=> maak tabel x als selecteer een FROM generation_series(1,1000000) a;T1| regressie=>
T2| $ ^CT2| [ perf record:332 keer wakker geworden om gegevens te schrijven ]T2| [ perf record:vastgelegd en geschreven 86.404 MB perf.data (~3775041 samples) ]T2|T2| $ sudo perf-rapport -g
U kunt perf-rapport . gebruiken 's curses gui om in het spoor te graven, of je kunt het perf report --stdio gebruiken optie om het gegevens naar stdout te laten streamen. Als u bijvoorbeeld stacktraceringen wilt, kunt u het volgende uitvoeren:
$ sudo perf report -g --stdio... blah blah ...# Voorbeelden:1 van gebeurtenis 'syscalls:sys_enter_fsync'# Aantal gebeurtenissen (ongeveer):1## Overhead-opdracht Symbool gedeeld object# .. ...... ........ ............. .....................# 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 (nihil)... blah blah...
laat zien dat voor de gebeurtenis syscalls:sys_enter_fsync er was één gebeurtenis met de bovenstaande stapel, een fsync die werd aangeroepen via ExecCreateTableAs .
(Om de een of andere reden ben ik er nog niet in geslaagd de definitieve fsync() vast te pinnen lijkt niet te worden vastgelegd door perf wanneer psql wordt uitgevoerd direct onder de controle van perf . Dit is geen probleem met perf stat , alleen perfecte record . Daarom spring ik door hoepels om de backend vooraf te selecteren door pid hierboven.)
Dynamische sondes in de gebruikersruimte
Soms ben je meer geïnteresseerd in iets dat binnen PostgreSQL zelf gebeurt dan in gebeurtenissen binnen de kernel die door PostgreSQL worden geactiveerd. Nieuwere versies van perf kan hierbij helpen door dynamische traceerpunten in te voegen die worden geactiveerd bij oproepen in gebruikersruimteprogramma's.
Stel dat u geïnteresseerd bent in het bekijken van WAL-activiteit en wilt zien wanneer XLogFlush , XLogFileInit of XLogFileOpen worden genoemd. U kunt dynamische traceerpunten voor deze oproepen invoegen met perf :
sudo perf probe -x `welke postgres` XLogFileInitsudo perf probe -x `welke postgres` XLogFileOpensudo perf probe -x `welke postgres` XLogFlush
U kunt alleen externe symbolen onderzoeken (niet-statisch, niet verborgen door -fvisibility-vlaggen) tenzij u hebt gebouwd met -ggdb . perf zal klagen geen symbolen gevonden als u een symbool probeert te gebruiken dat niet bestaat. Op het moment van schrijven perf ondersteunt het gebruik van externe debuginfo niet om symbolen voor sondes op te zoeken, hoewel het deze wel kan gebruiken voor stapelanalyse. In het algemeen, als het een extern is in src/include je kunt het gebruiken met perf .
Elk traceerpunt zal de naam van het gecreëerde traceerpunt afdrukken en u kunt perf probe -l gebruiken om ze toch allemaal op te sommen:
$ sudo perf probe -l probe_postgres:XLogFileInit (op 0x000000000009a360) probe_postgres:XLogFileOpen (op 0x000000000009a860) probe_postgres:XLogFlush (op 0x00000000000a0670)
Deze probes zijn nu bruikbaar als perf events. Laten we eens kijken naar xlog-activiteit tijdens een voorbeeldwerkbelasting, waarbij het hele cluster wordt bewaakt terwijl ik een pgbench-run doe:
sudo perf record -g dwarf -u postgres -e probe_postgres:XLogFileInit,probe_postgres:XLogFileOpen,probe_postgres:XLogFlush
Probeer het zelf met perf report -g . Zo zien de resultaten eruit. U kunt opties gebruiken zoals -g fractal,0 details te controleren. U kunt het percentage van de treffers van een bepaalde teller zien die afkomstig zijn van de ene stapeltak of een andere, de pid en het proces, enz. De --sort opties geven u meer controle over aggregatie en groepering.
Maar wacht, er is meer
Bekijk ook de perf stat en perf top commando's. Ze kunnen dezelfde gebeurtenislijsten gebruiken als perf record , hoewel om de een of andere vreemde reden hun ondersteuning voor procesfilters anders is.
Hier is een voorbeeld dat een dummy-workload uitvoert en tijdens de run naar I/O-kerneltraceerpunten kijkt:
$ sudo perf stat -e block:block_rq_*,syscalls:sys_enter_write,syscalls:sys_enter_fsync -a -r 5 -- psql -q -U postgres craig -c "laat tabel vallen als deze bestaat x; maak tabel x als selecteer een VAN gene_series(1,1000000) a;"; Prestatietellerstatistieken voor 'psql -U postgres craig -c drop table indien aanwezig x; maak tabel x als selecteer een FROM Genereer_serie (1,1000000) a;' (5 runs):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 seconden verstreken tijd (+- 18,31% /pre>Je kunt zien dat het gemiddeld ongeveer 100 bloklaag-I/O-verzoeken doet over 10k write()s en een enkele fsync() doet. Een deel daarvan is achtergrondgeluid van het systeem, aangezien we alle systeemprofilering uitvoeren (-a ), maar aangezien het systeem redelijk inactief is, is het niet veel, en het is gemiddeld over vijf runs.
Evenzo, met behulp van de dynamische sondes die we eerder hebben toegevoegd, houdt u de xlog-activiteit in de gaten tijdens een pgbench-run:
$ 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 10000start vacuüm...end. transactietype:TPC-B (soort van)schalingsfactor:100query-modus:enkelvoudig aantal klanten:2 aantal threads:1 aantal transacties per klant:10000 aantal daadwerkelijk verwerkte transacties:20000/20000tps =715.854663 (inclusief tot stand brengen van verbindingen)tps =716.092133 ( exclusief verbindingen tot stand brengen) Prestatietellerstatistieken voor '/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%] 55.440 probe_postgres:XLogFlush 27.987364469 seconden verstreken tijdU kunt nog veel meer doen, waaronder het vastleggen van de status van lokale variabelen met perf probe . Ik zal daar later een aantal bruikbare voorbeelden van opschrijven. Ondertussen kun je spelen, ontdekken en plezier hebben met een nieuw diagnostisch hulpmiddel.
Bijwerken: Michael Paquier schreef onlangs een gerelateerd artikel over het traceren van PostgreSQL met systemtap dat interessant kan zijn voor lezers van dit artikel. Je moet Pg opnieuw compileren om die benadering te gebruiken, maar de syntaxis is mooier en biedt een aantal andere voordelen.