Sådan får du det bedste ud af PostgreSQL-logfiler

Som et moderne RDBMS kommer PostgreSQL med mange parametre til finjustering. Et af de områder, der skal overvejes, er, hvordan PostgreSQL skal logge sine aktiviteter. Logning overses ofte i Postgres databasestyring, og hvis den ikke ignoreres, er den normalt forkert indstillet. Dette sker, fordi formålet med logning det meste af tiden er uklart. Selvfølgelig er den grundlæggende årsag til logning velkendt, men det, der nogle gange mangler, er en forståelse af, hvordan logfilerne vil blive brugt.

Hver organisations logningskrav er unikke, og derfor vil også hvordan PostgreSQL-logning skal konfigureres være forskellig. Hvad en finansiel servicevirksomhed skal registrere i sine databaselogfiler, vil være anderledes end hvad en virksomhed, der beskæftiger sig med kritiske helbredsoplysninger, skal registrere. Og i nogle tilfælde kan de også ligne hinanden.

I denne artikel vil jeg dække nogle grundlæggende fremgangsmåder for at få det bedste ud af PostgreSQL-logfiler. Denne blog er ikke en hård og hurtig regelbog; læsere er mere end velkomne til at dele deres tanker i kommentarfeltet. For at få den bedste værdi ud af det, beder jeg dog læseren om at tænke over, hvordan de vil bruge deres PostgreSQL-databaseserverlogfiler:

Årsag til lovlig overholdelse, hvor specifikke oplysninger skal indhentes
Sikkerhedsrevision, hvor specifikke begivenhedsdetaljer skal være til stede
Ydeevnefejlfinding, hvor forespørgsler og deres parametre skal registreres
Dag-til-dag driftsstøtte, hvor et bestemt antal målinger skal overvåges

Med det sagt, lad os starte.

Foretag ikke manuelle ændringer af postgresql.conf

Eventuelle ændringer i postgresql.conf-filen skal foretages ved hjælp af et konfigurationsstyringssystem som Puppet, Ansible eller Chef. Dette sikrer, at ændringer er sporbare og sikkert kan rulles tilbage til en tidligere version, hvis det er nødvendigt. Dette gælder, når du foretager ændringer i logningsparametrene.

DBA'er opretter ofte flere kopier af postgresql.conf-filen, hver med lidt forskellige parametre, hver til et andet formål. Manuel styring af forskellige konfigurationsfiler er en besværlig opgave, hvis den ikke er tilbøjelig til fejl. På den anden side kan et konfigurationsstyringssystem fås til at omdøbe og bruge forskellige versioner af postgresql.conf-filen baseret på en parameter, der er sendt til den. Denne parameter vil diktere formålet med den aktuelle version. Når behovet er fuldført, kan den gamle konfigurationsfil sættes tilbage ved at ændre den samme inputparameter.

For eksempel, hvis du ønsker at logge alle sætninger, der kører på din PostgreSQL-instans, kan en config-fil med parameterværdien "log_statement=all" bruges. Når der ikke er behov for at registrere alle udsagn – måske efter en fejlfindingsøvelse – kunne den tidligere konfigurationsfil genindsættes.

Brug separate logfiler til PostgreSQL

Jeg anbefaler, at du aktiverer PostgreSQL's indfødte logindsamler under normale operationer. For at aktivere PostgreSQL native-logning skal du indstille følgende parameter til On:

logging_collector = on

Der er to grunde til det:

Først og fremmest, i travle systemer, optager operativsystemet muligvis ikke konsekvent PostgreSQL-meddelelser i syslog (forudsat en nix-baseret installation) og slipper ofte beskeder. Med indbygget PostgreSQL-logning sørger en separat dæmon for at optage begivenhederne. Når PostgreSQL er optaget, vil denne proces udskyde skrivningen til logfilerne for at lade forespørgselstråde afslutte. Dette kan blokere hele systemet, indtil loghændelsen er skrevet. Det er derfor nyttigt at optage mindre udførlige beskeder i loggen (som vi vil se senere) og bruge forkortede loglinjepræfikser.

For det andet – og som vi vil se senere – skal logs indsamles, parses, indekseres og analyseres med et Log Management-værktøj. At lade PostgreSQL optage sine hændelser i syslog vil betyde, at der oprettes et ekstra lag af filtrering og mønstertilpasning i Log Management-delen for at bortfiltrere alle "støjmeddelelser". Dedikerede logfiler kan let parses og indekseres til begivenheder med de fleste værktøjer.

Sæt logdestination til stderr

Lad os overveje parameteren "log_destination". Den kan have fire værdier:

log_destination = stderr | syslog | csv | eventlog

Medmindre der er en god grund til at gemme loghændelser i kommasepareret format eller hændelseslog i Windows, anbefaler jeg at indstille denne parameter til stderr. Dette skyldes, at med en CSV-fildestination, vil en tilpasset "log_line_prefix" parameterværdi ikke have nogen effekt, og alligevel kan præfikset gøres til at indeholde værdifuld information.

På bagsiden kan en CSV-log dog nemt importeres til en databasetabel og senere forespørges ved hjælp af standard SQL. Nogle PostgreSQL-brugere finder det mere bekvemt end at håndtere rå logfiler. Som vi vil se senere, kan moderne Log Management-løsninger indbygget parse PostgreSQL-logfiler og automatisk skabe meningsfuld indsigt fra dem. Med CSV skal rapporteringen og visualiseringen udføres manuelt af brugeren.

I sidste ende kommer det ned til dit valg. Hvis du er tryg ved at oprette din egen dataindtagelsespipeline for at indlæse CSV-logfilerne i databasetabeller, rense og transformere dataene og oprette tilpassede rapporter, der passer til dine forretningsbehov, så sørg for, at "log_destination" er indstillet til CSV.

Brug meningsfulde logfilnavne

Når PostgreSQL-logfiler gemmes lokalt, synes det måske ikke nødvendigt at følge en navngivningsstil. Standardfilnavnestilen er "postgresql-%Y-%m-%d_%H%M%S.log" for ikke-CSV-formaterede logfiler, hvilket er tilstrækkeligt i de fleste tilfælde.

Navngivning bliver vigtigt, når du gemmer logfiler fra flere servere til en central placering som en dedikeret logserver, en monteret NFS-diskenhed eller en S3-bøtte. Jeg anbefaler at bruge to parametre i sådanne tilfælde:

log_directory
log_filename

For at gemme logfiler fra flere forekomster på ét sted skal du først oprette et separat mappehierarki for hver forekomst. Dette kan være noget i stil med følgende:

/<Application_Name>/<Environment_Name>/<Instance_Name>

Hver PostgreSQL-instanss "log_directory" kan derefter peges på dens udpegede mappe.

Hver forekomst kan derefter bruge den samme "log_filename" parameterværdi. Standardværdien vil oprette en fil som

postgresql_2020-08-25_2359.log

For at bruge et mere meningsfuldt navn skal du indstille "log_filename" til noget som dette:

log_filename = "postgresql_%A-%d-%B_%H%M"

Logfilerne vil derefter blive navngivet som:

postgresql_Saturday-23-August_2230

Brug meningsfuldt loglinjepræfiks

PostgreSQL loglinjepræfikser kan indeholde den mest værdifulde information udover selve meddelelsen. Postgres-dokumentationen viser flere escape-tegn til konfiguration af loghændelsespræfiks. Disse escape-sekvenser erstattes med forskellige statusværdier under kørsel. Nogle programmer som pgBadger forventer et specifikt loglinjepræfiks.

Jeg anbefaler at inkludere følgende oplysninger i præfikset:

Tidspunktet for hændelsen (uden millisekunder):%t
Fjernklientnavn eller IP-adresse:%h
Brugernavn:%u
Database tilgået:%d
Applikationsnavn:%a
Proces-id:%p
Afslutter ikke-sessionsprocesoutput:%q
Loglinjenummeret for hver session eller proces, startende ved 1:%l

For at forstå, hvad hvert felt i præfikset handler om, kan vi tilføje en lille bogstavelig streng før feltet. Så proces-id-værdien kan indledes med det bogstavelige "PID=", databasenavnet kan foranstilles med "db=" osv. Her er et eksempel:

log_line_prefix = 'time=%t, pid=%p %q db=%d, usr=%u, client=%h , app=%a, line=%l '

Afhængigt af hvor hændelsen kommer fra, vil loglinjepræfikset vise forskellige værdier. Både baggrundsprocesser og brugerprocesser vil registrere deres beskeder i logfilen. For systemprocesser har jeg angivet %q, som vil undertrykke enhver tekst efter proces-id'et (%p). Enhver anden session vil vise databasenavnet, brugernavnet, klientadressen, applikationsnavnet og en nummereret linje for hver begivenhed.

Jeg inkluderede også et enkelt mellemrum efter loglinjepræfikset. Dette mellemrum adskiller loghændelsespræfikset fra den faktiske hændelsesmeddelelse. Det behøver ikke at være et mellemrum – noget som et dobbelt kolon (::), bindestreg (-) eller en anden meningsfuld separator kan bruges.

Indstil også parameteren "log_hostname" til 1:

log_hostname = 1

Uden dette vil kun klientens IP-adresse blive vist. I produktionssystemer vil dette typisk være adressen på proxy, load balancer eller forbindelsespooleren. Medmindre du kender disse systemers IP-adresser udenad, kan det være umagen værd at logge deres værtsnavne. DNS-opslaget vil dog også tilføje ekstra tid for logning-dæmonen til at skrive til filen.

En anden parameter, der bør indstilles sammen med "log_line_prefix" er "log_timezone". Indstilling af dette til serverens lokale tidszone sikrer, at loggede hændelser er nemme at følge fra deres tidsstempel i stedet for først at konvertere til lokal tid. I kodestykket nedenfor indstiller vi log_timzeone til australsk østlig standardtidszone:

log_timezone = 'Australia/Sydney'

Kun logforbindelser

To parametre styrer, hvordan PostgreSQL registrerer klientforbindelser og afbrydelser. Begge parametre er deaktiveret som standard. Baseret på din organisations sikkerhedskrav vil du måske indstille en af disse til 1 og den anden til 0 (medmindre du bruger et værktøj som pgBadger – mere om det senere).

log_connections = 1
log_disconnections = 0

Indstilling af log_connections til 1 vil registrere alle autoriserede forbindelser såvel som forsøgte forbindelser. Dette er naturligvis godt til sikkerhedsrevision:et brute force-angreb kan nemt identificeres fra logfilerne. Men med denne indstilling aktiveret, kunne et travlt PostgreSQL-miljø med tusindvis eller endda hundredvis af kortvarige gyldige forbindelser se logfilen blive oversvømmet.

Ikke desto mindre kan den også identificere applikationsproblemer, som måske ellers ikke er indlysende. Et stort antal forbindelsesforsøg fra mange forskellige gyldige klientadresser kan indikere, at forekomsten har brug for en load balancer eller forbindelsespooling-tjeneste foran sig. Et stort antal forbindelsesforsøg fra en enkelt klientadresse kan afsløre et program med for mange tråde, der kræver en eller anden form for regulering.

Log kun DDL- og DML-operationer

Der er en del debat omkring, hvad der skal registreres i Postgres-loggen - dvs. hvad der skal være værdien af parameteren "log_statement". Det kan have tre værdier:

log_statement = 'off' | 'ddl' | 'mod' | 'all'

Det kan være fristende at indstille dette til "alle" for at fange alle SQL-sætninger, der kører på serveren, men det er måske ikke altid en god idé i virkeligheden.

Travle produktionssystemer kører for det meste SELECT-sætninger, nogle gange tusindvis af dem i timen. Forekomsten kører muligvis perfekt uden problemer med ydeevnen. At sætte denne parameter til "alle" i sådanne tilfælde ville unødigt belaste logningsdæmonen, da den skal skrive alle disse udsagn til filen.

Det, du dog vil fange, er enhver datakorruption eller ændringer i databasestrukturen, der forårsagede en eller anden form for problemer. Uønskede eller uautoriserede databaseændringer forårsager flere applikationsproblemer end at vælge data; det er derfor, jeg anbefaler at indstille denne parameter til "mod". Med denne indstilling vil PostgreSQL registrere alle DDL- og DML-ændringer til logfilen.

Hvis din PostgreSQL-instans er moderat optaget (snesevis af forespørgsler i timen), er du velkommen til at indstille denne parameter til "alle". Når du fejlfinder langsomt kørende SELECT-forespørgsler eller leder efter uautoriseret dataadgang, kan du også indstille dette til "alle" midlertidigt. Nogle programmer som pgBadger forventer også, at du indstiller dette til "alle".

Log "advarsels"-meddelelser og op

Hvis parameteren "log_statement" bestemmer, hvilken type udsagn der skal optages, dikterer følgende to parametre, hvor detaljeret beskeden vil være:

log_min_messages
log_min_error_statement

Hver PostgreSQL-begivenhed har et tilknyttet meddelelsesniveau. Beskedniveauet kan være alt fra verbose DEBUG til kortfattet PANIK. Jo lavere niveau, jo mere udførligt er beskeden. Standardværdien for parameteren "log_min_messages" er "ADVARSEL". Jeg anbefaler, at du holder det på dette niveau, medmindre du også ønsker, at informationsmeddelelser skal logges.

Parameteren "log_min_error_statement" styrer, hvilke SQL-sætninger, der sender fejl, der bliver logget. Ligesom "log_min_message", vil enhver SQL-sætning, der har et fejlsværhedsniveau, der er lig med eller over værdien angivet i "log_min_error_statement", blive optaget. Standardværdien er "ERROR", og jeg anbefaler at beholde standardværdien.

Behold logvarighedsparametre til standard

Så har vi følgende to parametre:

log_duration
log_min_duration_statement

Parameteren "log_duration" har en boolesk værdi. Når den er sat til 1, vil varigheden af hver afsluttet erklæring blive logget. Hvis den er sat til 0, logges erklæringsvarigheden ikke. Dette er standardværdien, og jeg anbefaler at holde den til 0, medmindre du fejlfinder problemer med ydeevnen. Beregning og registrering af erklæringsvarigheder får databasemotoren til at udføre ekstra arbejde (uanset hvor lille den er), og når den ekstrapoleres til hundredvis eller tusindvis af forespørgsler, kan besparelserne være betydelige.

Til sidst har vi parameteren "log_min_duration_statement". Når denne parameter er indstillet (uden nogen enheder, det tages som millisekunder), vil varigheden af en sætning, der er lig med eller længere end parameterværdien, blive logget. Indstilling af denne parameterværdi til 0 vil registrere varigheden af alle afsluttede udsagn. Indstilling af denne til -1 vil deaktivere logning af erklæringsvarighed. Dette er standardværdien, og jeg anbefaler at beholde den.

Den eneste gang, du vil indstille denne parameter til 0, er, når du vil oprette en præstationsbaseline for hyppigt kørte forespørgsler. Husk dog, at hvis parameteren "log_statement" er indstillet, vil de sætninger, der logges, ikke blive gentaget i logmeddelelserne, der viser varigheder. Så du bliver nødt til at indlæse logfilerne i en databasetabel og derefter forbinde proces-id- og sessions-id-værdierne fra loglinjepræfikserne for at identificere relaterede udsagn og deres varighed.

Uanset hvad betyder det, når du har en basislinje for hver hyppigt kørte forespørgsel, kan du indstille parameteren "log_min_duration_statement" til den højeste af basislinjeværdierne. Nu vil enhver forespørgsel, der løber længere end den højeste basislinjeværdi, være en kandidat til finjustering.

Behold fejlmeddelelsens omfang til standard

Parameteren "log_error_verbosity" kan have tre mulige værdier:

log_error_verbosity = terse | standard | verbose

Denne parameter styrer mængden af information, som PostgreSQL optager for hver hændelse, der er registreret i logfilen. Medmindre fejlfinding af en databaseapplikation, er denne parameter bedst at holde til "standard". Den verbose tilstand vil være nyttig, når du skal fange filen eller funktionsnavnet og linjenummeret der, der genererede fejlen. Indstilling af dette til "terse" vil undertrykke logning af forespørgslen, hvilket måske heller ikke er nyttigt.

Find en logrotationspolitik, der virker for din Use Case

Jeg anbefaler at oprette en logrotationspolitik baseret på enten størrelsen eller alderen af logfilen, men ikke begge dele. To PostgreSQL-konfigurationsparametre dikterer, hvordan gamle logfiler arkiveres, og nye logfiler oprettes:

log_rotation_age = <number of minutes>
log_rotation_size = <number of kilobytes>

Standardværdien for "log_rotration_age" er 24 timer, og standardværdien for "log_rotation_size" er 10 megabyte.

I de fleste tilfælde garanterer en politik for størrelsesrotation ikke altid, at den sidste logmeddelelse i den arkiverede logfil kun er fuldstændig indeholdt i denne fil.

Hvis "log_rotation_age" holdes til sin standardværdi på 24 timer, kan hver fil let identificeres og undersøges individuelt, da hver fil vil indeholde en dags begivenheder. Dette garanterer dog heller ikke, at hver fil vil være en selvstændig enhed af logfiler fra de sidste 24 timer. Nogle gange kan en langsomt udførende forespørgsel tage mere end 24 timer at afslutte; begivenheder kan ske, når den gamle fil lukkes, og den nye er genereret. Dette kan være tilfældet under et batchjob om natten, hvilket resulterer i, at nogle dele af forespørgslerne registreres i én fil og resten i en anden.

Vores anbefaling er at finde en logrotationsperiode, der fungerer for din use case. Tjek tidsforskellen mellem to på hinanden følgende perioder med lavest aktivitet (f.eks. mellem en lørdag til den næste). Du kan derefter indstille "log_rotation_age"-værdien til den tidsforskel, og i en af disse perioder genstarte PostgreSQL-tjenesten. På den måde vil PostgreSQL rotere den aktuelle logfil, når den næste pauseperiode indtræffer. Men hvis du skal genstarte tjenesten mellem disse perioder, vil logrotationen igen blive skæv. Du skal derefter gentage denne proces. Men som mange andre ting i PostgreSQL, vil forsøg og fejl diktere den bedste værdi. Hvis du bruger et logstyringsværktøj, vil alderen eller størrelsen på logrotationen også være ligegyldig, fordi logmanageragenten indtager hver hændelse fra filen, efterhånden som den tilføjes.

Brug værktøjer som pgBadger

pgBadger er en kraftfuld PostgreSQL-loganalysator, der kan skabe meget nyttig indsigt fra Postgres-logfiler. Det er et open source-værktøj skrevet i Perl med et meget lille fodaftryk i den maskine, hvor det kører. Værktøjet køres fra kommandolinjen og kommer med et stort antal muligheder. Det vil tage en eller flere logfiler som input og kan producere en HTML-rapport med detaljerede statistikker om:

De oftest ventende forespørgsler.
Forespørgsler, der genererer de fleste midlertidige filer eller de største midlertidige filer
Langsomst kørende forespørgsler
Gennemsnitlig forespørgselsvarighed
De oftest kørende forespørgsler
De hyppigste fejl i forespørgsler
Brugere og applikationer, der kører forespørgsler
Statistik for kontrolpunkter.
Autostøvsug og autoanalyser statistik.
Låsestatistikker
Fejlhændelser (panik, fatal, fejl og advarsel).
Forbindelses- og sessionsprofiler (efter database, bruger, applikation)
Sessionsprofiler
Forespørgselsprofiler (forespørgselstyper, forespørgsler efter database/applikation)
I/O-statistik
osv.

Som jeg nævnte før, skal nogle af de log-relaterede konfigurationsparametre aktiveres for at fange alle loghændelser, så pgBadger effektivt kan analysere disse logfiler. Da dette kan producere store logfiler med mange hændelser, bør pgBadger kun bruges til at oprette benchmarks eller fejlfinde problemer med ydeevnen. Når de detaljerede logfiler er blevet genereret, kan konfigurationsparametrene ændres tilbage til deres oprindelige værdier. Til kontinuerlig loganalyse er det bedst at bruge en dedikeret logstyringsapplikation.

Hvis du er mere komfortabel med at gøre ting i kommandoprompten og bruge systemvisninger, vil du gerne bruge pg_stat_statements. Faktisk burde dette være aktiveret i enhver PostgreSQL-produktionsinstallation.

pg_stat_statements er en PostgreSQL-udvidelse og med standardinstallationen nu. For at aktivere det skal konfigurationsparameteren "shared_preload_libraries" have pg_stat_statements som en af dens værdier. Det kan derefter installeres som enhver anden udvidelse ved at bruge kommandoen "CREATE EXTENSION". Udvidelsen opretter visningen pg_stat_statement, som giver værdifuld forespørgselsrelateret information.

Brug en logstyringsapplikation til at få indsigt

Der er mange logstyringsværktøjer på markedet, og de fleste organisationer bruger en eller flere i disse dage. Uanset hvilket værktøj der er på plads, anbefaler jeg at bruge det til at indsamle og administrere PostgreSQL-logfiler.

Der er et par grunde til det:

Det er meget nemmere at parse, analysere og filtrere støj fra logfiler med et automatiseret værktøj. Nogle gange kan en hændelse strække sig over flere logfiler baseret på hændelsens varighed og logrotationsalderen eller størrelsen. At have en logmanager gør det meget nemmere at få disse oplysninger præsenteret som en helhed.

Loghåndteringsløsninger i dag kommer typisk med indbygget mulighed for at parse PostgreSQL-logfiler. Nogle kommer også med dashboards, der kan vise de mest almindelige metrics udtrukket fra disse logfiler.

De fleste moderne logadministrationsapplikationer tilbyder også kraftfulde funktioner til søgning, filter, mønstertilpasning, hændelseskorrelation og AI-aktiverede trendanalysefunktioner. Hvad der ikke er synligt for almindelige øjne, kan nemt gøres tydeligt med disse værktøjer.

Endelig vil brug af en logmanager til at gemme PostgreSQL-logfiler også betyde, at begivenhederne gemmes for eftertiden, selvom de originale filer slettes ved et uheld eller ondsindet.

Selvom der er indlysende fordele ved at bruge et logstyringsprogram, har mange organisationer begrænsninger med hensyn til hvor deres træstammer kan leve. Dette er et typisk tilfælde med SaaS-baserede løsninger, hvor logfiler ofte gemmes uden for en organisations geografiske grænse – noget, der måske ikke er i overensstemmelse med lovmæssige krav.

I sådanne tilfælde anbefaler jeg at vælge en leverandør med en lokal datacentertilstedeværelse – hvis det er muligt – eller at bruge en selvadministreret logmanager hostet i organisationens netværk, såsom en ELK-stak.

Afsluttende ord

PostgreSQL-serverlogfiler kan være en guldgrube af information, når de er konfigureret korrekt. Tricket er at bestemme, hvad der skal logges, og hvor meget der skal logges, og endnu vigtigere, teste, om logfilerne kan levere den rigtige information, når det er nødvendigt. Det vil være et spørgsmål om at prøve og fejle, men det, jeg har diskuteret her i dag, burde give en ganske anstændig start. Som jeg sagde i begyndelsen, ville jeg være mere end glad for at høre om din oplevelse med at konfigurere PostgreSQL-logning til optimale resultater.