Vous n'êtes pas identifié(e).

#2 Re : Général » FATAL: database does not exist » 16/02/2018 13:27:48

masterpastek a écrit :

Où dois-je marquer mon pb comme étant résolu dans le forum ?

Sur votre premier message, il y a un lien "modifier". En cliquant dessus, vous pouvez modifier le sujet de la discussion pour ajouter "[Résolu]"

#3 Re : Général » [Résolu] Volume des journaux de transactions pendant la restauration » 16/02/2018 13:18:25

Désolée pour la trace incomplète, mais je ne sais pas comment annexer un fichier à un message de forum, et le fichier fait près de 5000 lignes (514 Ko), donc je ne peux pas copier tout le contenu. J'ai éliminé des lignes qui étaient du même type que celles déjà citées dans cette discussion, en essayant de garder les messages significatifs.


Pour finir, ce que je conclus de nos tests et de cette discussion :

   -*- le nombre de fichiers présents dans pg_xlog pendant une restauration, et juste après, peut être bien supérieur à ce qu'il est pendant un fonctionnement normal

   -*- le paramètre 'checkpoint_timeout' permet de limiter le nombre de fichiers, puisqu'il provoque l'exécution des "restartpoint"

   -*- le nombre maximal de fichiers dans le répertoire n'est pas calculable aisément à partir des paramètres de configuration : il dépend du nombre de fichiers WAL d'archives traités pendant la durée entre deux "restartpoint", et du nombre de fichiers supprimés lors de chacune de ces opérations, qui relève du mécanisme interne de postgreSQL, sans doute assez complexe (et le premier restartpoint ne fait rien sur ce point).

Au final, il vaut mieux prévoir un espace assez conséquent pour les fichiers de journaux de transactions actifs pendant la restauration, car le rejeu des fichiers récupérés dans l'archive est très rapide (beaucoup de fichiers sont "consommés" entre deux "restartpoint").

#4 Re : Général » [Résolu] Volume des journaux de transactions pendant la restauration » 15/02/2018 17:45:44

Nouveaux tests avec valeurs plus petites des deux paramètres : plusieurs "restartpoint" sont indiqués dans les traces pendant la restauration.
Le premier restartpoint ne fait rien sur le fichiers WAL, les suivants opère des suppressions et recyclages.
Mais avec mes données, le nombre de fichiers dans pg_xlog reste bien supérieur à celui que l'on observe lors de l'activité "normale" de la base :
avec le couple de paramètres (2,2min), le nombre de fichiers évolue entre 657 (max observé) et 201 (en fin de restauration).

Les traces avec DEBUG2 sont assez volumineuses, je ne copie que des (gros) extraits ci-dessous. A noter : mon instance est sur une ligne de temps de 2, alors que la sauvegarde est sur une ligne de temps de 1, d'où des messages supplémentaire "cp: cannot stat" dans la trace.
Les lignes vides ont été ajoutées pour la lecture.

[...]
cp: cannot stat `/rep_archives/000000020000003E000000FD': No such file or directory
user=,db=,time=2018-02-15 14:21:57 CET DEBUG:  could not restore file "000000020000003E000000FD" from archive: child process exited with exit code 1
user=,db=,time=2018-02-15 14:21:57 CET LOG:  restored log file "000000010000003E000000FD" from archive
user=,db=,time=2018-02-15 14:21:57 CET DEBUG:  got WAL segment from archive
cp: cannot stat `/rep_archives/000000020000003E000000FE': No such file or directory
user=,db=,time=2018-02-15 14:21:58 CET DEBUG:  could not restore file "000000020000003E000000FE" from archive: child process exited with exit code 1
user=,db=,time=2018-02-15 14:21:58 CET LOG:  restored log file "000000010000003E000000FE" from archive
user=,db=,time=2018-02-15 14:21:58 CET DEBUG:  got WAL segment from archive

user=,db=,time=2018-02-15 14:21:58 CET LOG:  restartpoint starting: time
user=,db=,time=2018-02-15 14:21:58 CET DEBUG:  performing replication slot checkpoint
user=,db=,time=2018-02-15 14:21:58 CET DEBUG:  updated min recovery point to 3E/FEE99610 on timeline 1
user=,db=,time=2018-02-15 14:21:58 CET CONTEXT:  writing block 43418 of relation base/26764/26777
cp: cannot stat `/rep_archives/000000020000003E000000FF': No such file or directory
user=,db=,time=2018-02-15 14:21:58 CET DEBUG:  could not restore file "000000020000003E000000FF" from arc
hive: child process exited with exit code 1
user=,db=,time=2018-02-15 14:21:58 CET LOG:  restored log file "000000010000003E000000FF" from archive
user=,db=,time=2018-02-15 14:21:58 CET DEBUG:  got WAL segment from archive
cp: cannot stat `/rep_archives/000000020000003F00000000': No such file or directory
user=,db=,time=2018-02-15 14:21:58 CET DEBUG:  could not restore file "000000020000003F00000000" from archive: child process exited with exit code 1
user=,db=,time=2018-02-15 14:21:58 CET LOG:  restored log file "000000010000003F00000000" from archive
user=,db=,time=2018-02-15 14:21:58 CET DEBUG:  got WAL segment from archive
user=,db=,time=2018-02-15 14:21:58 CET DEBUG:  updated min recovery point to 3F/9E8668 on timeline 1
user=,db=,time=2018-02-15 14:21:58 CET CONTEXT:  writing block 39106 of relation base/26764/26777
[...]
user=,db=,time=2018-02-15 14:22:38 CET LOG:  restored log file "000000010000003F0000006B" from archive
user=,db=,time=2018-02-15 14:22:38 CET DEBUG:  checkpoint sync: number=1 file=base/26764/12753 time=86.241 msec
user=,db=,time=2018-02-15 14:22:38 CET DEBUG:  checkpoint sync: number=2 file=base/26764/12753_fsm time=37.491 msec
user=,db=,time=2018-02-15 14:22:38 CET DEBUG:  checkpoint sync: number=3 file=base/26764/26815 time=8.021 msec
user=,db=,time=2018-02-15 14:22:38 CET DEBUG:  checkpoint sync: number=4 file=base/17259/26789.2 time=0.106 msec
[...]
user=,db=,time=2018-02-15 14:22:39 CET DEBUG:  checkpoint sync: number=59 file=base/26764/12755 time=0.057 msec
user=,db=,time=2018-02-15 14:22:39 CET DEBUG:  attempting to remove WAL segments older than log file 000000000000003D000000FD
user=,db=,time=2018-02-15 14:22:39 CET DEBUG:  SlruScanDirectory invoking callback on pg_multixact/offsets/0000
user=,db=,time=2018-02-15 14:22:39 CET DEBUG:  SlruScanDirectory invoking callback on pg_multixact/members/0000
user=,db=,time=2018-02-15 14:22:39 CET DEBUG:  SlruScanDirectory invoking callback on pg_multixact/offsets/0000

user=,db=,time=2018-02-15 14:22:39 CET LOG:  restartpoint complete: wrote 42981 buffers (42.0%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=40.107 s, 

sync=0.727 s, total=40.892 s; sync files=59, longest=0.478 s, average=0.011 s
user=,db=,time=2018-02-15 14:22:39 CET LOG:  recovery restart point at 3E/F90157D8
user=,db=,time=2018-02-15 14:22:39 CET DETAIL:  last completed transaction was at log time 2018-02-14 20:44:22.884051+01
cp: cannot stat `/rep_archives/000000020000003F0000006C': No such file or directory
user=,db=,time=2018-02-15 14:22:39 CET DEBUG:  could not restore file "000000020000003F0000006C" from archive: child process exited with exit code 1
user=,db=,time=2018-02-15 14:22:39 CET LOG:  restored log file "000000010000003F0000006C" from archive
user=,db=,time=2018-02-15 14:22:39 CET DEBUG:  got WAL segment from archive
[...]
user=,db=,time=2018-02-15 14:22:53 CET LOG:  restored log file "000000010000003F00000090" from archive
user=,db=,time=2018-02-15 14:22:54 CET DEBUG:  got WAL segment from archive
user=,db=,time=2018-02-15 14:22:54 CET DEBUG:  updated min recovery point to 3F/90617B48 on timeline 1
user=,db=,time=2018-02-15 14:22:54 CET CONTEXT:  writing block 20660 of relation base/26764/26777
        xlog redo insert(init): rel 1663/26764/26818; tid 43344/1
cp: cannot stat `/rep_archives/000000020000003F00000091': No such file or directory
user=,db=,time=2018-02-15 14:22:54 CET DEBUG:  could not restore file "000000020000003F00000091" from archive: child process exited with exit code 1
user=,db=,time=2018-02-15 14:22:54 CET LOG:  restored log file "000000010000003F00000091" from archive
user=,db=,time=2018-02-15 14:22:54 CET DEBUG:  got WAL segment from archive
user=,db=,time=2018-02-15 14:22:54 CET DEBUG:  updated min recovery point to 3F/912A5410 on timeline 1
user=,db=,time=2018-02-15 14:22:54 CET CONTEXT:  xlog redo file truncate: base/26764/26774 to 271 blocks
user=,db=,time=2018-02-15 14:22:54 CET DEBUG:  updated min recovery point to 3F/912BC110 on timeline 1
user=,db=,time=2018-02-15 14:22:54 CET CONTEXT:  xlog redo file truncate: base/26764/26768 to 325 blocks
user=,db=,time=2018-02-15 14:22:54 CET DEBUG:  updated min recovery point to 3F/912C1ED8 on timeline 1
user=,db=,time=2018-02-15 14:22:54 CET CONTEXT:  xlog redo commit: 2018-02-14 20:45:14.433772+01; rels: base/26764/26822
cp: cannot stat `/rep_archives/000000020000003F00000092': No such file or directory
user=,db=,time=2018-02-15 14:22:54 CET DEBUG:  could not restore file "000000020000003F00000092" from archive: child process exited with exit code 1
user=,db=,time=2018-02-15 14:22:55 CET LOG:  restored log file "000000010000003F00000092" from archive
[...]
user=,db=,time=2018-02-15 14:23:15 CET LOG:  restored log file "000000010000003F000000C6" from archive
user=,db=,time=2018-02-15 14:23:15 CET DEBUG:  got WAL segment from archive
user=,db=,time=2018-02-15 14:23:16 CET DEBUG:  updated min recovery point to 3F/C6F9C870 on timeline 1
user=,db=,time=2018-02-15 14:23:16 CET CONTEXT:  writing block 978 of relation base/26764/26777
[...]
user=,db=,time=2018-02-15 14:23:26 CET DEBUG:  got WAL segment from archive
user=,db=,time=2018-02-15 14:23:26 CET DEBUG:  updated min recovery point to 3F/E0D5B720 on timeline 1
user=,db=,time=2018-02-15 14:23:26 CET CONTEXT:  writing block 55064 of relation base/26764/26777
        xlog redo visible: rel 1663/17259/26789; blk 661991
cp: cannot stat `/rep_archives/000000020000003F000000E1': No such file or directory
user=,db=,time=2018-02-15 14:23:26 CET DEBUG:  could not restore file "000000020000003F000000E1" from archive: child process exited with exit code 1
user=,db=,time=2018-02-15 14:23:26 CET LOG:  restored log file "000000010000003F000000E1" from archive
user=,db=,time=2018-02-15 14:23:26 CET DEBUG:  got WAL segment from archive
[...]
user=,db=,time=2018-02-15 14:23:31 CET DEBUG:  updated min recovery point to 3F/ED452BE0 on timeline 1
user=,db=,time=2018-02-15 14:23:31 CET CONTEXT:  writing block 13717 of relation base/26764/26777
        xlog redo insert(init): rel 1663/26764/26818; tid 56460/1
[...]
user=,db=,time=2018-02-15 14:23:36 CET DEBUG:  updated min recovery point to 3F/F80D9890 on timeline 1
user=,db=,time=2018-02-15 14:23:36 CET CONTEXT:  writing block 60428 of relation base/26764/26777
[...]
user=,db=,time=2018-02-15 14:23:51 CET DEBUG:  updated min recovery point to 40/19776070 on timeline 1
user=,db=,time=2018-02-15 14:23:51 CET CONTEXT:  writing block 27822 of relation base/26764/26777
        xlog redo visible: rel 1663/17259/26789; blk 673963
[...]
user=,db=,time=2018-02-15 14:23:58 CET LOG:  restartpoint starting: time
user=,db=,time=2018-02-15 14:23:58 CET DEBUG:  performing replication slot checkpoint
user=,db=,time=2018-02-15 14:23:58 CET DEBUG:  updated min recovery point to 40/2B540F60 on timeline 1
user=,db=,time=2018-02-15 14:23:58 CET CONTEXT:  writing block 79343 of relation base/26764/26777
cp: cannot stat `/rep_archives/00000002000000400000002C': No such file or directory
user=,db=,time=2018-02-15 14:23:58 CET DEBUG:  could not restore file "00000002000000400000002C" from archive: child process exited with exit code 1
user=,db=,time=2018-02-15 14:23:59 CET LOG:  restored log file "00000001000000400000002C" from archive
user=,db=,time=2018-02-15 14:23:59 CET DEBUG:  got WAL segment from archive
ser=,db=,time=2018-02-15 14:23:59 CET DEBUG:  updated min recovery point to 40/2CBDE180 on timeline 1
user=,db=,time=2018-02-15 14:23:59 CET CONTEXT:  writing block 63680 of relation base/26764/26777
[...]
user=,db=,time=2018-02-15 14:24:01 CET LOG:  restored log file "000000010000004000000030" from archive
user=,db=,time=2018-02-15 14:24:01 CET DEBUG:  got WAL segment from archive
user=,db=,time=2018-02-15 14:24:01 CET DEBUG:  updated min recovery point to 40/305125C0 on timeline 1
user=,db=,time=2018-02-15 14:24:01 CET CONTEXT:  writing block 10 of relation base/26764/26778
[...]
user=,db=,time=2018-02-15 14:24:02 CET DEBUG:  updated min recovery point to 40/34000000 on timeline 1
user=,db=,time=2018-02-15 14:24:02 CET CONTEXT:  writing block 11001 of relation base/26764/26777
[...]
user=,db=,time=2018-02-15 14:24:03 CET DEBUG:  updated min recovery point to 40/35FFFFE8 on timeline 1
user=,db=,time=2018-02-15 14:24:03 CET CONTEXT:  writing block 69080 of relation base/26764/26777
[...]
user=,db=,time=2018-02-15 14:24:53 CET LOG:  restored log file "0000000100000040000000A8" from archive
user=,db=,time=2018-02-15 14:24:53 CET DEBUG:  checkpoint sync: number=1 file=base/26764/12753 time=42.457 msec
user=,db=,time=2018-02-15 14:24:53 CET DEBUG:  checkpoint sync: number=2 file=base/26764/12753_fsm time=1.696 msec
[...]
user=,db=,time=2018-02-15 14:24:53 CET DEBUG:  checkpoint sync: number=31 file=base/26764/12755 time=0.062 msec
user=,db=,time=2018-02-15 14:24:53 CET DEBUG:  attempting to remove WAL segments older than log file 000000000000003E000000F8
user=,db=,time=2018-02-15 14:24:53 CET DEBUG:  recycled transaction log file "000000010000003E00000071"
user=,db=,time=2018-02-15 14:24:53 CET DEBUG:  recycled transaction log file "000000010000003E00000086"
user=,db=,time=2018-02-15 14:24:53 CET DEBUG:  recycled transaction log file "000000010000003E00000049"
[...]
user=,db=,time=2018-02-15 14:24:53 CET DEBUG:  recycled transaction log file "000000010000003E00000056"
user=,db=,time=2018-02-15 14:24:53 CET DEBUG:  removing transaction log file "000000010000003E000000F4"
user=,db=,time=2018-02-15 14:24:53 CET DEBUG:  removing transaction log file "000000010000003E0000005D"
[...]
user=,db=,time=2018-02-15 14:24:54 CET DEBUG:  removing transaction log file "000000010000003E000000A0"
user=,db=,time=2018-02-15 14:24:54 CET DEBUG:  SlruScanDirectory invoking callback on pg_multixact/offsets/0000
user=,db=,time=2018-02-15 14:24:54 CET DEBUG:  SlruScanDirectory invoking callback on pg_multixact/members/0000
user=,db=,time=2018-02-15 14:24:54 CET DEBUG:  SlruScanDirectory invoking callback on pg_multixact/offsets/0000
user=,db=,time=2018-02-15 14:24:54 CET LOG:  restartpoint complete: wrote 58941 buffers (57.6%); 0 transaction log file(s) added, 245 removed, 6 recycled; write=54.597 s, 

sync=0.158 s, t
otal=55.257 s; sync files=31, longest=0.078 s, average=0.004 s
user=,db=,time=2018-02-15 14:24:54 CET LOG:  recovery restart point at 40/2407EB88
user=,db=,time=2018-02-15 14:24:54 CET DETAIL:  last completed transaction was at log time 2018-02-14 20:47:35.815539+01
[...]
user=,db=,time=2018-02-15 14:25:01 CET DEBUG:  transaction ID wrap limit is 2147485445, limited by database with OID 1
user=,db=,time=2018-02-15 14:25:01 CET CONTEXT:  xlog redo checkpoint: redo 40/BC000028; tli 2; prev tli 1; fpw true; xid 0/624391; oid 34984; multi 1; offset 0; oldest xid 

1798 in DB 1;
 oldest multi 1 in DB 17259; oldest running xid 0; shutdown
user=,db=,time=2018-02-15 14:25:01 CET DEBUG:  MultiXactId wrap limit is 2147483648, limited by database with OID 17259
user=,db=,time=2018-02-15 14:25:01 CET CONTEXT:  xlog redo checkpoint: redo 40/BC000028; tli 2; prev tli 1; fpw true; xid 0/624391; oid 34984; multi 1; offset 0; oldest xid 

1798 in DB 1;
 oldest multi 1 in DB 17259; oldest running xid 0; shutdown
user=,db=,time=2018-02-15 14:25:01 CET DEBUG:  attempting to remove WAL segments newer than log file 0000000200000040000000BC
user=,db=,time=2018-02-15 14:25:01 CET LOG:  restored log file "0000000200000040000000BD" from archive
user=,db=,time=2018-02-15 14:25:01 CET DEBUG:  got WAL segment from archive
[...]
user=,db=,time=2018-02-15 14:25:58 CET LOG:  restartpoint starting: time
user=,db=,time=2018-02-15 14:25:58 CET DEBUG:  performing replication slot checkpoint
user=,db=,time=2018-02-15 14:25:58 CET LOG:  restored log file "00000002000000410000002A" from archive
user=,db=,time=2018-02-15 14:25:58 CET DEBUG:  updated min recovery point to 41/29FFE3A0 on timeline 2
user=,db=,time=2018-02-15 14:25:58 CET CONTEXT:  writing block 99174 of relation base/26764/26818
[...]
user=,db=,time=2018-02-15 14:26:21 CET DEBUG:  checkpoint sync: number=1 file=base/26764/26815 time=166.765 msec
user=,db=,time=2018-02-15 14:26:21 CET DEBUG:  checkpoint sync: number=2 file=base/17259/26789.5 time=4.183 msec
[...]
user=,db=,time=2018-02-15 14:26:21 CET DEBUG:  checkpoint sync: number=30 file=base/26764/26804_vm time=0.818 msec
user=,db=,time=2018-02-15 14:26:21 CET DEBUG:  attempting to remove WAL segments older than log file 000000000000004000000023
user=,db=,time=2018-02-15 14:26:21 CET DEBUG:  recycled transaction log file "000000010000003F000000A0"
[...]
user=,db=,time=2018-02-15 14:26:21 CET DEBUG:  recycled transaction log file "000000010000003F00000056"
user=,db=,time=2018-02-15 14:26:21 CET DEBUG:  removing transaction log file "000000010000003F000000BB"
[...]
user=,db=,time=2018-02-15 14:26:24 CET DEBUG:  removing transaction log file "000000010000003F00000097"
user=,db=,time=2018-02-15 14:26:24 CET DEBUG:  SlruScanDirectory invoking callback on pg_multixact/offsets/0000
user=,db=,time=2018-02-15 14:26:24 CET DEBUG:  SlruScanDirectory invoking callback on pg_multixact/members/0000
user=,db=,time=2018-02-15 14:26:24 CET DEBUG:  SlruScanDirectory invoking callback on pg_multixact/offsets/0000
user=,db=,time=2018-02-15 14:26:24 CET LOG:  restartpoint complete: wrote 24641 buffers (24.1%); 0 transaction log file(s) added, 291 removed, 8 recycled; write=23.032 s, 

sync=0.429 s, t
otal=26.524 s; sync files=30, longest=0.169 s, average=0.014 s
user=,db=,time=2018-02-15 14:26:24 CET LOG:  recovery restart point at 41/24613220
user=,db=,time=2018-02-15 14:26:24 CET DETAIL:  last completed transaction was at log time 2018-02-14 21:13:29.676208+01
user=,db=,time=2018-02-15 14:26:24 CET LOG:  restored log file "000000020000004100000071" from archive
[...]
user=,db=,time=2018-02-15 14:27:04 CET LOG:  selected new timeline ID: 3
user=,db=,time=2018-02-15 14:27:04 CET LOG:  restored log file "00000002.history" from archive
user=,db=,time=2018-02-15 14:27:04 CET DEBUG:  updated min recovery point to 41/E3FFFEA0 on timeline 2
user=,db=,time=2018-02-15 14:27:04 CET LOG:  archive recovery complete
user=,db=,time=2018-02-15 14:27:04 CET LOG:  checkpoint starting: end-of-recovery immediate wait
[...]
user=,db=,time=2018-02-15 14:27:10 CET DEBUG:  attempting to remove WAL segments older than log file 000000000000004100000023
[...]
user=,db=,time=2018-02-15 14:27:11 CET DEBUG:  removing transaction log file "000000020000004100000004"
user=,db=,time=2018-02-15 14:27:11 CET DEBUG:  SlruScanDirectory invoking callback on pg_multixact/offsets/0000
user=,db=,time=2018-02-15 14:27:11 CET DEBUG:  SlruScanDirectory invoking callback on pg_multixact/members/0000
user=,db=,time=2018-02-15 14:27:11 CET DEBUG:  SlruScanDirectory invoking callback on pg_multixact/offsets/0000
user=,db=,time=2018-02-15 14:27:11 CET LOG:  checkpoint complete: wrote 102088 buffers (99.7%); 0 transaction log file(s) added, 251 removed, 5 recycled; write=1.901 s, 

sync=4.649 s, tot
al=7.294 s; sync files=39, longest=1.909 s, average=0.115 s
user=,db=,time=2018-02-15 14:27:11 CET DEBUG:  attempting to remove WAL segments newer than log file 0000000300000041000000E3
user=,db=,time=2018-02-15 14:27:11 CET DEBUG:  oldest MultiXactId member is at offset 0
user=,db=,time=2018-02-15 14:27:11 CET LOG:  MultiXact member wraparound protections are now enabled
user=,db=,time=2018-02-15 14:27:11 CET DEBUG:  MultiXact member stop limit is now 4294914944 based on MultiXact 1
user=,db=,time=2018-02-15 14:27:11 CET LOG:  database system is ready to accept connections

#5 Re : Général » [Résolu] Volume des journaux de transactions pendant la restauration » 15/02/2018 11:46:03

Je ne peux pas vous donner la trace, il s'agit d'un environnement de pré-production.
Les paramètres utilisés devaient être ceux par défaut pour nous : checkpoint_segments = 10, checkpoint_timeout = 5min.

Nous faisons des essais de reproduction sur nos serveurs de tests, avec plusieurs valeurs du couple

(checkpoint_segments, checkpoint_timeout).
Tests effectués : (5, 5min), (4, 4min),
Tests en cours  : (3,30s), (3, 3min)
Procédure de test : 1°)sauvegarde à chaud avec pg_base_backup, 2°) création d'activité sur une base pout une génération d'une grande quantité de WAL 3°) restauration. Surveillance du répertoire 'pg_xlog' pendant les deux dernières phases.


Premiers constats :
- pendant la phase 2, les fichiers WAL ne sont jamais plus de 25 dans le répertoire 'pg_xlog', ils sont archivés au fur et à mesure, les "checkpoints" sont très nombreux (messages dans la trace)
- pendant la phase 3, les fichiers WAL utilisés pour la restauration sont copiés un à un du répertoire d'archives vers 'pg_xlog', comme l'a écrit très justement gleu,
- les fichiers s'accumulent dans le répertoire 'pg_xlog', jusqu'à être plus de 730. Leur nombre redescend à 130-150 lorsque la restauration se termine,
- les "restartpoint", d'après la trace, sont déclenchés exactement au bout d'un délai égal à checkpoint_timeout, le paramètre checkpoint_segments semeble ne pas intervenir (valeurs mal choisies ?)
- lors d'un "restartpoint", aucun fichier ne semble être supprimé de 'pg_xlog'.


Extrait d'une trace :
---------------------------

user=,db=,time=2018-02-14 19:21:44 CET LOG:  database system was interrupted; last known up at 2018-02-14 18:17:54 CET
user=,db=,time=2018-02-14 19:21:44 CET LOG:  starting point-in-time recovery to 2018-02-14 18:10:00+01
user=,db=,time=2018-02-14 19:21:45 CET LOG:  restored log file "00000001000000360000005F" from archive
user=,db=,time=2018-02-14 19:21:45 CET LOG:  restored log file "00000001000000360000005B" from archive
user=,db=,time=2018-02-14 19:21:45 CET LOG:  redo starts at 36/5B3FC8C8
user=,db=,time=2018-02-14 19:21:45 CET LOG:  restored log file "00000001000000360000005C" from archive

[...]
user=,db=,time=2018-02-14 19:25:45 CET LOG:  restored log file "00000001000000380000003B" from archive
user=,db=,time=2018-02-14 19:25:45 CET LOG:  restartpoint starting: time
user=,db=,time=2018-02-14 19:25:45 CET LOG:  restored log file "00000001000000380000003C" from archive
[...]
user=,db=,time=2018-02-14 19:26:20 CET LOG:  restored log file "00000001000000380000009B" from archive
user=,db=,time=2018-02-14 19:26:21 CET LOG:  could not link file "pg_xlog/xlogtemp.14917" to "pg_xlog/00000001000000380000009B
": File exists
user=,db=,time=2018-02-14 19:26:21 CET LOG:  restartpoint complete: wrote 19053 buffers (18.6%); 1 transaction log file(s) added, 0 removed, 0 recycled; write=35.288 s, sync=0.099 s, total=35.549 s; sync files=8, longest=0.038 s, average=0.012 s
user=,db=,time=2018-02-14 19:26:21 CET LOG:  recovery restart point at 38/351459D0
user=,db=,time=2018-02-14 19:26:21 CET LOG:  restored log file "00000001000000380000009C" from archive
user=,db=,time=2018-02-14 19:26:21 CET LOG:  restored log file "00000001000000380000009C" from archive
user=,db=,time=2018-02-14 19:26:21 CET LOG:  restored log file "00000001000000380000009D" from archive
user=,db=,time=2018-02-14 19:26:22 CET LOG:  restored log file "00000001000000380000009E" from archive
[...]

----------------------------

#6 Général » [Résolu] Volume des journaux de transactions pendant la restauration » 14/02/2018 12:50:11

comaco
Réponses : 11

Bonjour,
lors d'une restauration du type PITR, avec un volume assez important de fichiers WAL d'archive à restaurer, le système de fichiers des fichiers WAL actifs (pg_xlog) a été saturé.
Les archives et les WAL actifs sont sur deux systèmes de fichiers différents, celui des archives a été taillé pour contenir le volume adéquat entre deux sauvegardes, mais pas celui des WAL actifs (respectivement 100 Go et 8 Go).

J'ai donc deux questions à ce propos :
1) il semblerait que la procédure de restauration de postgreSQL (lancement de l'instance avec un fichier recovery.conf contenant le paramètre restore_command = 'cp ${Repertoire_archives}/%f  %p') commence par copier tous les fichiers WAL du répertoire d'archive vers le répertoire des fichiers actifs, et ne les recycle ni supprime avant la fin de la restauration. Pouvez-vous me confirmer ce mécanisme par défaut ?

2) Y a-t-il moyen de limiter la taille de l'espace occupé par les fichiers journaux de transaction pendant la restauration, sachant que l'espace disponible pour pg_xlog suffit pour un fonctionnement ordinaire ?

Précision : la version utilisée lors de l'incident  est une 9.4, mais il semblerait que le fonctionnement ne soit pas différent sur une v9.6.


Merci par avance,
comaco

#7 Re : Général » CTE + PREPARE = Syntax error » 07/02/2018 12:01:35

Les deux requêtes ne sont pas identiques :
après VALUES, dans la première, il y a 3 valeurs, alors que dans la deuxième, il y en a 2.

Cela explique probablement la différence de résultat.

Pied de page des forums

Propulsé par FluxBB