====== Korrupt lett az adatbázis? ====== A PostgreSQL megállt és nem hajlandó elindulni. A szervernaplóban az alábbi mondat tölti el aggodalommal a DBA-t: ''HINT: This probably means that some data is corrupted and you will have to use the last backup for recovery.'' Mit jelent ez, mikor történhet ilyen, és mi a teendő ilyenkor? Vizsgáljunk meg két esetet. Az lesz bennük a közös, hogy mindkét esetben összeomlik az adatbázis-szerver. Az első esetben a szerver automatikusan helyreállítja magát, a második esetben viszont nem. ===== 1. Sikeres helyreállítás összeomlás után ===== Az első eset egy összeomlás utáni sikeres helyreállítás lesz. Vizsgáljuk meg először az PostgreSQL szervert még az összeomlás előtt, futó állapotban. A PostgreSQL szerver fontos része az ún. kontrollfájl, ami a szerver állapotáról szolgál információkkal. A ''pg_controldata'' parancssoros eszközzel tudunk belenézni a kontrollfájlba. A parancs paramétereként az adatkönyvtár helyét kell megadni, amit általában a ''$PGDATA'' környezeti változó tartalmaz. ''postgres@test ~]$ pg_controldata $PGDATA | grep REDO\\ Latest checkpoint's REDO location: 0/9000110\\ Latest checkpoint's REDO WAL file: 000000010000000000000009'' A fenti kimenetben csak a REDO-val kapcsolatos sorokat szűrtük ki.t A ''REDO location'' az pozíció WAL-ban, ahol a legutolsó checkpoint kezdődött, és ahonnan egy összeomlást követően a helyreállítást (recovery) kezdeni kell. Esetünkben ez a pozíció a 0/9000110. A második sorban pedig azt látjuk, hogy a 9-es WAL-szegmensben található ez a bizonyos pozíció. A checkpoint egy olyan művelet, amely során minden adatváltoztatás kiíródik a memóriából az adatfájlokba. Tehát egy checkpoint azt jelenti, hogy addig a pontig biztos minden változtatást tartalmaznak az adatfájlok, ezért a helyreállítást elég ez után a pont után végrehajtani. A pg_controldata kimenetében láthatjuk azt is, hogy a szerver milyen módbaban fut. ''[postgres@test ~]$ pg_controldata $PGDATA | grep state\\ Database cluster state: in production'' A state az adatbázis-szerver működési módját mutatja. Az ''in production'' a normál működés. A fenti állapotban összeomlik a szerver valamilyen okból (crash). A következő indításkor az adatbázis-szerver automatikusan helyreállítja magát, ez az ún. automatic recovery vagy crash recovery. Hogyan történik ez? Amikor az összeomlást követően elindítjuk a PostgreSQL szervert, akkor a szerver a kontroll fájlban azt látja magáról, hogy ''in production'' módban fut, ami lehetetlen, mert nem fut, hiszen épp most indul. Ebből jön rá a szerver, hogy nem lett szabályosan leállítva, automatikus helyreállítást kell indítani. A sikeres crash recovery így néz ki a szervernaplóban: ''2023-05-11 19:38:04.015 CEST [35300] LOG: database system was not properly shut down; automatic recovery in progress\\ 2023-05-11 19:38:04.029 CEST [32894] LOG: redo starts at 0/9000110\\ 2023-05-11 19:38:04.029 CEST [32894] LOG: invalid record length at 0/90001F8: wanted 24, got 0\\ 2023-05-11 19:38:04.029 CEST [32894] LOG: redo done at 0/90001C0 system usage: ...\\ 2023-05-11 19:38:04.047 CEST [32892] LOG: checkpoint starting: end-of-recovery immediate wait\\ 2023-05-11 19:38:04.079 CEST [32892] LOG: checkpoint complete: wrote 3 buffers (0.0%) ...\\ 2023-05-11 19:38:04.091 CEST [32889] LOG: database system is ready to accept connections'' A szervernaplóban látszik, hogy nem lett szabályosan, konzisztens módon leállítva a szerver (''not properly shut down''), ezért automatikus helyreállítás fut (''automatic recovery in progress''). Látszi a naplóban az is, hogy a helyreállítás a fent már látott ponton kezdődik a WAL-ból (''redo starts at 0/9000110''). Az ''invalid record length''... üzenet ignorálható. A naplórészlet utolsó három sorában pedig azt látjuk, hogy történik egy checkpoint, és utána elindul a szerver normál módban. Checkpoint többféle okból és többféle módon történhet. Esetünkben a WAL-ból történt recovery befejezéseként (''end-of-recovery''), a lehető leggyorsabb (''immediate'') checkpoint történik, és a szerver vár, amíg az be nem fejeződik (''wait''). Ez a checkpoint lényegében ugyanolyan, mint ami akkor történik, ha szabályosan állítjuk le az PostgreSQL-szervert. (A szervernapló tartalmához egy megjegyzés: a ''log_checkpoints'' nevű szerverparaméter beállítása dönti el, hogy a checkpoint-eseményeket naplózza-e a szerver. Ez a paraméter a PostgreSQL 14-es verziójáig alapértelmezetten ''off'' értékre volt állítva, a 15-ös verziótól kezdve viszont ez megváltozott, és most már ''on'' az alapértelmezett értéke. Tehát csak a 15-ös verziótól kezdve naplózza automatikusan a szerver a checkpoint-eseményeket.) A checkpoint adatait a szerver bejegyzi a kontrollfájlba és a WAL-ba is. A WAL-fájlokba a ''pg_waldump'' nevű, parancssoros eszközzel tudunk bepillantani: ''[postgres@test ~]$ pg_waldump $PGDATA/pg_wal/000000010000000000000009 | tail -n2\\ ...\\ CHECKPOINT_SHUTDOWN redo 0/90001F8; ...'' A parancs kimenetében látható, hogy a fájl végén ott a bejegyzés egy olyan checkpointról, ami a szerver leállítása során is történik. A kontrollfájlban is ugyanezt az információt látjuk: ''[postgres@test ~]$ pg_controldata $PGDATA | grep REDO\\ Latest checkpoint's REDO location: 0/90001F8\\ Latest checkpoint's REDO WAL file: 000000010000000000000009'' A checkpoint után a szerver elindul, mintha mi sem történt volna, és most indulna normálisan. ===== 2. Sikertelen helyreállítás összeomlás után ===== A második esetben szintén összeomlik az adatbázis-szerver, ám az automatikus helyreállítás nem sikerül. A kontrollfájlban, közvetlenül az összeomlás előtt, az alábbi adatok voltak: ''[postgres@test ~]$ pg_controldata $PGDATA | grep REDO\\ Latest checkpoint's REDO location: 0/1F0012D0\\ Latest checkpoint's REDO WAL file: 00000001000000000000001F'' ''[postgres@test ~]$ pg_controldata $PGDATA | grep state\\ Database cluster state: in production'' Ebben az állapotban történt az összeomlás. A szervernaplót megvizgálva láthatjuk, hogy az előző esethet hasonlóan ugyanúgy indul egy crash recovery az utolsó checkpointtól (''REDO location: 0/1F0012D0''). ''2023-05-11 21:15:36.786 CEST [35300] LOG: database system was not properly shut down; automatic recovery in progress 2023-05-11 21:15:36.792 CEST [35300] LOG: redo starts at 0/1F0012D0\\ 2023-05-11 21:15:36.793 CEST [35300] LOG: redo done at 0/25000110 ...\\ 2023-05-11 21:15:36.805 CEST [35300] FATAL: could not write to file "pg_wal/xlogtemp.35300": No space left on device\\ 2023-05-11 21:15:36.807 CEST [35052] LOG: startup process (PID 35300) exited with exit code 1\\ 2023-05-11 21:15:36.808 CEST [35052] LOG: terminating any other active server processes\\ 2023-05-11 21:15:36.809 CEST [35052] LOG: shutting down due to startup process failure\\ 2023-05-11 21:15:36.813 CEST [35052] LOG: database system is shut down'' A recovery ebben az esetben is befejeződik (''redo done'') a WAL 0/25000110 pontján, ami a WAL vége. A legutolsó WAL-fájl a 25-ös szegmens: ''[postgres@test ~]$ ls -lrt $PGDATA/pg_wal/ total 114688\\ -rw-------. 1 postgres postgres 16777216 May 11 21:14 000000010000000000000021\\ -rw-------. 1 postgres postgres 16777216 May 11 21:15 000000010000000000000022\\ -rw-------. 1 postgres postgres 16777216 May 11 21:15 000000010000000000000023\\ -rw-------. 1 postgres postgres 16777216 May 11 21:15 000000010000000000000024\\ -rw-------. 1 postgres postgres 16777216 May 11 21:15 000000010000000000000025\\ drwx------. 2 postgres postgres 180 May 11 21:15 archive_status'' Ebben a WAL-szegmensfáljban a legutolsó bejegyzés a 0/25000110: ''[postgres@test ~]$ pg_waldump $PGDATA/pg_wal/000000010000000000000025 | tail -n1\\ rmgr: XLOG len (rec/tot): 24/ 24, tx: 0, lsn: 0/25000110, prev 0/250000E8, desc: SWITCH'' Tehát tényleg végigment a recovery, de csak a memóriában. Hiszen a recovery folyamat végén nem történt checkpoint. Ennek pedig az oka az, hogy a checkpoint tényét a WAL-ba is be kell jegyeznie a szervernek, de ezt nem tudja megtenni, mert a WAL-t nem tudja írni (''could not write to file "pg_wal/xlogtemp.35300''"), mivel nincs több hely a lemezen (''No space left on device''). (Egy új WAL-fájl írása úgy történik, hogy először egy ideiglenes xlogtemp fájlba íródnak az adatok, és ha ez sikerül, akkor nevezi át a szegmensnek megfelelő névre a fájlt a szerver.) A szerver tehát a crash recovery folyamatot záró checkpoint előtt, helyhiány miatt megint összeomlik, mielőtt még el tudna indulni. Checkpoint hiányában viszont sajnos nem lehetünk benne biztosak, hogy minden változtatás kiíródott-e az adatfájlokba. Mivel nincs új checkpoint, a kontrollfájlban is ugyanaz checkpoint információ maradt, mint ami az előző indításkor volt: ''[postgres@test ~]$ pg_controldata $PGDATA | grep REDO\\ Latest checkpoint's REDO location: 0/1F0012D0\\ Latest checkpoint's REDO WAL file: 00000001000000000000001F'' Viszont a szerver most más módban van: ''[postgres@test ~]$ pg_controldata $PGDATA | grep state\\ Database cluster state: in crash recovery'' Ez érthető, hiszen crash recovery volt folyamatban legutoljára. Ha a fenti állapotban megint elindítjuk az adatbázis-szervert, akkor most azt látja magáról a szerver, hogy ''in crash recovery'' módban fut. Ez megint csak lehetetlen, hiszen épp most indul a szerver. Ez tehát azt jelenti, hogy crash recovery közben volt egy újabb crash. Ezt a tényt be is jegyzi a szervernaplóba a szerver. Beleír továbbá egy általános megjegyzést is, hogy ez esetleg korrupciót is jelenthet: ''2023-05-11 21:23:48.065 CEST [35401] LOG: database system was interrupted while in recovery at 2023-05-11 21:15:36 CEST\\ 2023-05-11 21:23:48.065 CEST [35401] HINT: This probably means that some data is corrupted and you will have to use the last backup for recovery.\\ 2023-05-11 21:23:48.073 CEST [35300] LOG: redo starts at 0/1F0012D0\\ 2023-05-11 21:23:48.083 CEST [35300] LOG: redo done at 0/25000110 ...'' Az esetleges korrupcióra vonatkozó megjegyzés egy általános megjegyzés, mert a crash recovery többféle okból is félbeszakadhat. Esetünkben egyszerűen a helyhiány volt az oka, de lehetett volna az is, hogy ténylegesen korrupt adatok vannak a WAL-ban. A szerver az okot nem jegyzi föl magának, csak a kontrollfájlban lévő információ áll a rendelkezésére. Esetünkben tehát a DBA megnyugodhat, nincs gond. A recovery pontosan ugyanonnan elindul, mint az előbb, és ha a crash recovery végén a checkpoint is meg tud történni, azzal a helyreállítás teljes. Ezután el fog indulni a szerver (''in production''), és az adatok konzisztensek lesznek. Csak biztosítanunk kell, hogy legyen elegendő hely a WAL-fájloknak. A PostgreSQL-szever összeomlásának nagyon gyakori oka a WAL-terület betelése, de ez már egy következő bejegyzés témája.