WAL-Shipping

Ich teste seit einigen Tagen eine Replikationslösung über WAL-Shipping und pg_standby. Die Einrichtung ist m. E. auch fertig, der Origin kopiert die WAL-Files anständig durch die Gegend, der Slave-Server startet aber nicht, um sie per pg_standby im Recovery-Modus einzulesen. Hier ein Auszug aus dem pg-log: [font=&quot]2009-10-21 21:37:07 CEST LOG: database system was interrupted; last known up at 2009-10-21 21:09:03 CEST
2009-10-21 21:37:07 CEST LOG: starting archive recovery
2009-10-21 21:37:07 CEST LOG: restore_command = 'C:\Programme\PostgreSQL\8.3\bin\pg_standby.exe -d -s 5 -t C:\pgsql.trigger.5442 [url=file://///test1/wal-archive/]\test1\wal-archive[/url] %f %p %r 2>>pg_log\pg_standby.log’
2009-10-21 21:37:07 CEST LOG: loaded library “$libdir/plugins/plugin_debugger.dll”
2009-10-21 21:37:07 CEST FATAL: the database system is starting up
2009-10-21 21:37:07 CEST FATAL: could not restore file “00000001.history” from archive: return code -1073741811

2009-10-21 21:37:07 CEST LOG: startup process (PID 848) exited with exit code 1
2009-10-21 21:37:07 CEST LOG: aborting startup due to startup process failure[/font]
2009-10-21 22:43:34 CEST LOG: aborting startup due to startup process failure
2009-10-21 22:43:34 CEST LOG: startup process (PID 184) exited with exit code 1
2009-10-21 22:43:34 CEST LOG: aborting startup due to startup process failure

Ich denke, dass die recovery.conf richtig konfiguriert ist (restore_command s.o.), in der postgresql.conf steht auch nichts besonderes mehr drin. Der Server startet normal durch, wenn er nicht recovern soll.
Also meine Frage, was ist das für eine Datei, diese 00000001.history? Sicher ein umbenanntes WAL-File, oder? Fehlen dort Permissions? Was sagt der Error-Code?

Danke für eure Hilfe,

murphy
[font=&quot][/font]

Ja, und, wo ist die Datei, die er sucht?
Gibt es die? Normal müsste der Master die weggeschrieben haben.

Zumindest nicht dort, wo sie sein sollte. In der recovery.conf ist ein UNC-Pfad angegeben, dort liegen Files der üblichen Nomenklatur xxxxxxxxyyyyyyyy, z.B. 00000000000000F. Es gibt nichts von wegen *.history. Woher der Slave die nehmen will… keine Ahnung…?
pg_standby kopiert die Files ja auch selbständig weg und darf sie auch umbenennen/löschen, ich bin davon ausgegangen, das ein reguläres WAL-File in *.history umbenennt wurde…

Nein, die .history Dateien sind recht klein, nur einige Hundert Bytes. Verfolg doch mal mit, was dein Backup so alles an Dateien generiert und wegsichert.

Wenn du damit meinst, was im WAL-Archiv ankommt, dann ist die Antwort recht simpel. Die üblichen 16MB-Dateien und zu jedem “select pg_start_backup(‘xxx’)” und “select pg_stop_backup()” halt ein *.backup-File. Wenn es sonst noch etwas gibt, ist es nicht dokumentiert und/oder kommt nicht an.

Heißt dieser return-code denn, dass das File nicht da ist. Ich habe beim googlen auch Fehler nach dem Motto “no such file or directory” gefunden…

Moment mal, zurück auf Anfang.

Wieso kann der Datenbankserver normal durchstarten, wenn er nicht recovern soll? Wie genau ziehst du das Base Backup vom Datenverzeichnis? Und wenn du das im Online Backup Modus (PITR) kopierst, musst du doch in jedem Fall den Slave im Recovery-Modus hochfahren, anders kann der gar nicht starten.


Oh, und noch eine Frage: wie kamst du zu der Portnummer 5442?

Ich wollte damit nur gesagt haben, dass es kein grundlegendes Konfigurationsproblem gibt… Wenn ich das Basebackup einspiele und den Server normal starte, funktioniert es.

Richtig.
Das Base-Backup erstelle ich, indem ich den Master in den Backupmodus schalte (select pg_start_backup(‘xxx’)), dann erfolgt eine Filesystemkopie des gesamten data-Dictionary, dann Backupmodus wieder aus (select pg_stop_backup()). Der Slave-Server ist zu diesem Zeitpunkt down, also kann ich das Basebackup einspielen. In der Zwischenzeit hat der Master neue WAL-Files produziert, diese sind unter dem UNC-Pfad abgelegt und für den Slave erreichbar. Nun fahre ich den Slave im Recovery-Modus hoch und sehe, dass er gleich einen Heldentod stirbt… :wink:

Oh, und noch eine Frage: wie kamst du zu der Portnummer 5442?

Ähm, das ist falsch… Muss 5432 sein.

Das sollte es nicht. Das Backup ist inkomplett und ggf. fehlen wichtige Dateien, je nachdem, in welcher Reihenfolge die Dateien kopiert wurden. Wenn du mittels pg_start_backup() ein Base Backup ziehst, brauchst du zwingend ein Recovery und die WAL Dateien, die in der “.backup” Datei als START und STOP angegeben sind.

Alles andere funktioniert vielleicht - aber auch nur vielleicht.



Nun fahre ich den Slave im Recovery-Modus hoch und sehe, dass er gleich einen Heldentod stirbt… :wink:

Kannst du das Debugging mal etwas hochdrehen?
Und kannst du mal in das Log schauen, das pg_standby produziert? Oder ev. pg_standby gegen ein einfaches Kopieren austauschen, welches die angefragten Dateien irgendwo ausgibt?


Würde mich interessieren, ob die .history Datei die einzige/erste/letzte angefragte Datei ist.



Ähm, das ist falsch… Muss 5432 sein.

Gut.

Da kann dich eigentilch nichts fehlen. Ich kopiere das ganze Datenverzeichnis, einschließlich pg_xlog usw. Gibt es etwas überhalb data, was modifiziert wird…?



Kannst du das Debugging mal etwas hochdrehen?
Und kannst du mal in das Log schauen, das pg_standby produziert?

Das pg_standby.log ist leer, wird nur angelegt.

Oder ev. pg_standby gegen ein einfaches Kopieren austauschen, welches die angefragten Dateien irgendwo ausgibt?

Würde mich interessieren, ob die .history Datei die einzige/erste/letzte angefragte Datei ist.

Wie jetzt??? Ich kann das pg_standby gegen ein freies Kommando austauschen??? Das Ding macht nichts außer einem Copy? Kann ich dem restore_command ein Batchfile unterjubeln?

Nun, stell dir mal folgendes Szenario vor:

  • du startest dein Backup

  • als erstes wird pg_xlog kopiert

  • danach die Daten

  • währenddessen werden die Daten geändert

  • die Änderungen stehen in pg_xlog

  • das ist aber schon kopiert, dein Backup ist hier veraltet

  • du beendest dein Backup

  • du startest die Kopie mit veralteten - und möglicherweise inkonsistenten - Transaktionslogs
    Bummer


    Darum brauchst du a) die nach extern kopierten Transaktionslogs und b) den Recovery Modus.




Wie jetzt??? Ich kann das pg_standby gegen ein freies Kommando austauschen??? Das Ding macht nichts außer einem Copy? Kann ich dem restore_command ein Batchfile unterjubeln?

Ja. Ja. Ja.

Ok, macht Sinn. So ist es ja aber auch geplant… Der Slave soll ja permanent im warm-standby laufen. Ich werde mal das pg_standby-Kommando austauschen (heute Abend) und mal sehen, was das Recovery alles so holen will. Melde mich wieder… schon mal VIELEN Dank!

HOT-Standby kommt erst noch. Irgendwann.

Andreas

Soll doch in 8.5 von 2nd-quadrant gebaut werden, oder???

Das ist die Hoffnung, ja.

Andreas

Nun, dafür brauchst du ja zwingend den Recovery-Modus plus die archivierten WAL-Dateien.

Aber jetzt interessiert mich erst mal, was das Restore alles anfragt.

…mich auch. Ich habe hier stundenlang herumgebastelt und kein Ergebnis in puncto File-Liste bekommen. Egal was ich als pg_standby eingetragen habe, nix hat funktioniert. Ich weiß immernoch nicht, welche Files das Restore haben will. Ich hier für jede Hilfe dankbar.

Noch einige Rahmenparameter:

a. Wie gewünscht höheres Debuglevel (5):

2009-10-22 21:23:40 CEST DEBUG:  00000: forked new backend, pid=1524 socket=1312
2009-10-22 21:23:40 CEST LOCATION:  BackendStartup, .\src\backend\postmaster\postmaster.c:2861
2009-10-22 21:23:40 CEST LOG:  00000: database system was interrupted; last known up at 2009-10-22 21:16:52 CEST
2009-10-22 21:23:40 CEST LOCATION:  StartupXLOG, .\src\backend\access\transam\xlog.c:4839
2009-10-22 21:23:40 CEST LOG:  00000: starting archive recovery
2009-10-22 21:23:40 CEST LOCATION:  readRecoveryCommandFile, .\src\backend\access\transam\xlog.c:4377
2009-10-22 21:23:40 CEST LOG:  00000: restore_command = 'pg_standby -c -d -s 5 -t C:\pgsql.trigger.5442 C:\Programme\PostgreSQL\8.3\wal-archive\ %f %p %r 2>>pg_log\pg_standby.log'
2009-10-22 21:23:40 CEST LOCATION:  readRecoveryCommandFile, .\src\backend\access\transam\xlog.c:4423
2009-10-22 21:23:40 CEST DEBUG:  00000: executing restore command "pg_standby -c -d -s 5 -t C:\pgsql.trigger.5442 C:\Programme\PostgreSQL\8.3\wal-archive\ 00000001.history pg_xlog\RECOVERYHISTORY 000000000000000000000000 2>>pg_log\pg_standby.log"
2009-10-22 21:23:40 CEST LOCATION:  RestoreArchivedFile, .\src\backend\access\transam\xlog.c:2569
2009-10-22 21:23:40 CEST LOG:  00000: loaded library "$libdir/plugins/plugin_debugger.dll"
2009-10-22 21:23:40 CEST LOCATION:  load_libraries, .\src\backend\utils\init\miscinit.c:1187
2009-10-22 21:23:40 CEST FATAL:  57P03: the database system is starting up
2009-10-22 21:23:40 CEST LOCATION:  ProcessStartupPacket, .\src\backend\postmaster\postmaster.c:1648
2009-10-22 21:23:40 CEST DEBUG:  00000: proc_exit(1)
2009-10-22 21:23:40 CEST LOCATION:  proc_exit, .\src\backend\storage\ipc\ipc.c:98
2009-10-22 21:23:40 CEST DEBUG:  00000: shmem_exit(1)
2009-10-22 21:23:40 CEST LOCATION:  shmem_exit, .\src\backend\storage\ipc\ipc.c:164
2009-10-22 21:23:40 CEST DEBUG:  00000: exit(1)
2009-10-22 21:23:40 CEST LOCATION:  proc_exit, .\src\backend\storage\ipc\ipc.c:116
2009-10-22 21:23:40 CEST DEBUG:  00000: reaping dead processes
2009-10-22 21:23:40 CEST LOCATION:  reaper, .\src\backend\postmaster\postmaster.c:2093
2009-10-22 21:23:40 CEST DEBUG:  00000: server process (PID 1524) exited with exit code 1
2009-10-22 21:23:40 CEST LOCATION:  LogChildExit, .\src\backend\postmaster\postmaster.c:2520
2009-10-22 21:23:40 CEST FATAL:  XX000: could not restore file "00000001.history" from archive: return code -1073741811
2009-10-22 21:23:40 CEST LOCATION:  RestoreArchivedFile, .\src\backend\access\transam\xlog.c:2639
2009-10-22 21:23:40 CEST DEBUG:  00000: proc_exit(1)
2009-10-22 21:23:40 CEST LOCATION:  proc_exit, .\src\backend\storage\ipc\ipc.c:98
2009-10-22 21:23:40 CEST DEBUG:  00000: shmem_exit(1)
2009-10-22 21:23:40 CEST LOCATION:  shmem_exit, .\src\backend\storage\ipc\ipc.c:164
2009-10-22 21:23:40 CEST DEBUG:  00000: exit(1)
2009-10-22 21:23:40 CEST LOCATION:  proc_exit, .\src\backend\storage\ipc\ipc.c:116
2009-10-22 21:23:40 CEST DEBUG:  00000: reaping dead processes
2009-10-22 21:23:40 CEST LOCATION:  reaper, .\src\backend\postmaster\postmaster.c:2093
2009-10-22 21:23:40 CEST LOG:  00000: startup process (PID 3404) exited with exit code 1
2009-10-22 21:23:40 CEST LOCATION:  LogChildExit, .\src\backend\postmaster\postmaster.c:2520
2009-10-22 21:23:40 CEST LOG:  00000: aborting startup due to startup process failure
2009-10-22 21:23:40 CEST LOCATION:  reaper, .\src\backend\postmaster\postmaster.c:2113
2009-10-22 21:23:40 CEST DEBUG:  00000: proc_exit(1)
2009-10-22 21:23:40 CEST LOCATION:  proc_exit, .\src\backend\storage\ipc\ipc.c:98
2009-10-22 21:23:40 CEST DEBUG:  00000: shmem_exit(1)
2009-10-22 21:23:40 CEST LOCATION:  shmem_exit, .\src\backend\storage\ipc\ipc.c:164
2009-10-22 21:23:40 CEST DEBUG:  00000: exit(1)
2009-10-22 21:23:40 CEST LOCATION:  proc_exit, .\src\backend\storage\ipc\ipc.c:116
2009-10-22 21:23:41 CEST DEBUG:  00000: logger shutting down
2009-10-22 21:23:41 CEST LOCATION:  SysLoggerMain, .\src\backend\postmaster\syslogger.c:435
2009-10-22 21:23:41 CEST DEBUG:  00000: proc_exit(0)
2009-10-22 21:23:41 CEST LOCATION:  proc_exit, .\src\backend\storage\ipc\ipc.c:98
2009-10-22 21:23:41 CEST DEBUG:  00000: shmem_exit(0)
2009-10-22 21:23:41 CEST LOCATION:  shmem_exit, .\src\backend\storage\ipc\ipc.c:164
2009-10-22 21:23:41 CEST DEBUG:  00000: exit(0)
2009-10-22 21:23:41 CEST LOCATION:  proc_exit, .\src\backend\storage\ipc\ipc.c:116

Meiner Meinung nach, ist dies interessant:

2009-10-22 21:23:40 CEST DEBUG:  00000: executing restore command "pg_standby -c -d -s 5 -t C:\pgsql.trigger.5442 C:\Programme\PostgreSQL\8.3\wal-archive\ 00000001.history pg_xlog\RECOVERYHISTORY 000000000000000000000000 2>>pg_log\pg_standby.log"

Das ist die recovery.conf :

restore_command = 'pg_standby -c -d -s 5 -t C:\pgsql.trigger.5442 C:\Programme\PostgreSQL\8.3\wal-archive\ %f %p %r 2>>pg_log\pg_standby.log'

Das ist backup_label:

START WAL LOCATION: 0/75000020 (file 000000010000000000000075)
CHECKPOINT LOCATION: 0/75000020
START TIME: 2009-10-22 21:16:53 CEST
LABEL: basebackup3

Ich habe organistorisch nun auch die WAL-Files direkt/phyikalisch auf dem Slave-Server liegen, schreib/lese-Rechte für postgres.

Diese Datei 00000001.history, das ist doch die Timeline-Datei, oder? Was will denn das recovern damit? Davon steht nix in der backup_label…

Schönen Abend noch, danke,

murphy

Ja, das frage ich mich auch. Außerdem frage ich mich, wieso die Datenbank meint, dass sie unterbrochen wurde. Da stimmt irgendwas nicht.

Btw, in der Dokumentation zu Point in Time Recovery steht gut beschrieben, welche Parameter archive_command und restore_command erwarten. Damit kann man sich dann auch gut ein eigenes Skript erstellen.


Bist du dir sicher, dass du das Backup richtig gezogen hast? PITR klappt ohne Probleme, wenn man nach der Dokumentation vorgeht.

Ich habe noch einmal alles rauf und runter geprüft und sehe keinen Fehler. Zum Procedere:

Auf dem Master:

  1. postgres=# select pg_start_backup(‘basebackup5’);
    pg_start_backup

0/85000020
(1 row)
2. bsdtar -cvzf w:\DATA.tgz data (wobei w:\ ein share auf dem Slave-Server ist und das Kommando im PG-Programverzeichnis augeführt wird)
3. postgres=# select pg_stop_backup();
pg_stop_backup

0/87000000
(1 row)

Auf dem Slave:

  1. DB-Server ist gestoppt (grummel)
  2. bsdtar -xvzf wal-archive\DATA.tgz
  3. Löschen von postmaster.pid aus dem gerade entpackten data-Verzeichnis
  4. Erstellen der recovery.conf (restore_command = ‘pg_standby -c -d -s 5 -t C:\pgsql.trigger.5442 C:\Programme\PostgreSQL\8.3\wal-archive\ %f %p %r 2>>pg_log\pg_standby.log’)
  5. Starten der DB

Ergebnis ist: log\pg_standby.log wird angelegt, steht aber nix drin. PG-Protokoll wird gefüllt, siehe oben.

Wo ist der Fehler…? Das kann doch nicht so schwer sein…

Du solltest als erste Maßnahme mal pg_xlog auch noch leer machen. Die notwendigen Dateien befinden sich ja im WAL Backup.

Habe ich schon versucht, hat nichts geholfen.