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

#1 Re : Général » [ABANDONNE] [9.6] Plus de checkpoint » 03/01/2020 01:13:34

Après quelques jours de congés, première chose regardé à ma reprise et j'ai la réponse... action humaine "in"volontaire avec un beau kill du process retrouvé dans l'historique des commandes.
Depuis, le moteur ne semble pas avoir bronché.

Merci pour vos contributions bien qu'elles n'aient pas eu le temps de conduire à une résolution non violente.

#2 Re : Général » [ABANDONNE] [9.6] Plus de checkpoint » 25/12/2019 01:33:43

Je suis dépité... horreur en me connectant ce mardi matin pour faire l'état des lieux...


Bien que ce soit certainement sans mauvaises intentions, je n'ai pas pu faire avouer, je pense qu'un lutin venait à l'instant de me planter le moteur en tuant le process checkpointer ! sad
Le process père a résisté et, comme sur l'environnement de test, tous les process fils ont été recyclés..


Magie de l'ambiance de Noël, checkpoint et sauvegardes refonctionnent smile
Le dossier pg_xlog a repris un cycle de vie et de purge normal.


Je n'ai eu aucun écho d'un dysfonctionnement de l'application ou même d'incohérences de données.
J'ai contrôlé la réplication et elle était toujours fonctionnelles.
Je reste dubitatif sur l'état réel du moteur et je pense qu'une reconstruction à court terme est à envisager.


Je rechercherai s'il s'agit bien d'une action humaine ou finalement d'une véritable défaillance du moteur telle qu'elle aurait pu/dû de produire initialement.

#3 Re : Général » [ABANDONNE] [9.6] Plus de checkpoint » 23/12/2019 17:24:58

(gdb) backtrace
#0  0x00007fb2781583e7 in semop () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007fb27a05f202 in PGSemaphoreLock ()
#2  0x00007fb27a0c4f0c in LWLockAcquire ()
#3  0x00007fb27a097c47 in ?? ()
#4  0x00007fb27a099657 in CheckPointReplicationSlots ()
#5  0x00007fb279eb818a in ?? ()
#6  0x00007fb279ec00c0 in CreateCheckPoint ()
#7  0x00007fb27a065ae9 in CheckpointerMain ()
#8  0x00007fb279ed15c9 in AuxiliaryProcessMain ()
#9  0x00007fb27a06ee27 in ?? ()
#10 0x00007fb27a07001a in ?? ()
#11 <signal handler called>
#12 0x00007fb27814f613 in select () from /lib/x86_64-linux-gnu/libc.so.6
#13 0x00007fb27a07149a in PostmasterMain ()
#14 0x00007fb279e480e2 in main ()

#4 Re : Général » [ABANDONNE] [9.6] Plus de checkpoint » 23/12/2019 17:08:01

La stack est très parlante...

# pstack 9471

9471: postgres: checkpointer process
(No symbols found)
0x7fb2781583e7: ???? (1007ffdeb7b9270, 7fb2729798f8, 0, 7fb2739c4400, 7ffdeb7b9420, 7ffdeb7b9520) + 10
0x7fb27a0c4f0c: ???? (7ffdeb7b9398, f7a334613, 7ffdeb7b9290, 7ffdeb7b9280, 7ffdeb7b9468, 7fb27a2349cd) + 8d0
0x7fb27a097c47: ???? (736c7065725f6770, 657361622f746f6c, 5f70756b6361625f, 34353a00746f6c73, 7ffdeb7b9620, 7fb2781a4b60) + 410
0x7fb27a099657: ???? (7fb27a61f1b8, 7fb27a637d58)
0x7fb279eb818a: ???? (3, cfe52b00, 1192c7000060, 200000002, 1, 1162b5906845a2f) + 70
0x7fb279ec00c0: ???? (7ffdeb7b9a70, 7fb27bdd0290, 7fb27a60f680, 8d01f7267e7cf438, 2, 7fb27a22b520) + e0
0x7fb27a065ae9: ???? (4, 0, 0, 7fb27a1f8d9c, 7ffdeb7b9bb0, 7fb27a638550) + 20
0x7fb279ed15c9: ???? (7fb27a318cd0, 7ffdeb7b9c10, 0, 5, 7ffdeb7b9b40, 10) + 60
0x7fb27a06ee27: ???? (7ffdeb7b9c90, 7fb2781646b9, 0, 7841a720, 7ffdeb7b9f20, 0) + 20
0x7fb27a07001a: ???? (1, 0, 0, 7fb200000002, 0, 7ffdeb7ba3c0) + 730
0x7fb2780960b0: ???? (7ffdeb7ba578, 0, 7fb279e48114, 7ffdeb7ba540, 0, 0)
0x7fb279e480e2: ???? (7ffdeb7ba578, 7ffdeb7ba548, 500000000, 7fb279e478c0, 0, 72fa21d148dcf438) + ffff800214845b60

#5 Re : Général » [ABANDONNE] [9.6] Plus de checkpoint » 17/12/2019 01:17:50

Le fichier pg_control reste bien en date du dernier CHECKPOINT.
Mon sentiment est donc que ce qui a été restauré sur l'environnement de test est basé sur à une sauvegarde qui n'aurait pas été lancée depuis ce CHECKPOINT... à noter qu'en temps normal la sauvegarde est loi d'être instantanée, mais autour de 30min.
Toutefois, je précise que l'objectif n'est pas de faire une restauration sur l'environnement principal, il s'agissait de vérifier en test que les fichiers sur disque n'étaient pas corrompus.

Ce dont je reste preneur, ce serait une solution indolore pour "réveiller" le process checkpointer.

#6 Re : Général » [ABANDONNE] [9.6] Plus de checkpoint » 14/12/2019 12:46:51

Je ne suis pas certain quant à la corruption puisque ce qui a été restauré selon procédure correspond à ce qui aurait été embarqué dans une sauvegarde qui n'aurait pas tourné depuis plusieurs jours.

Dilemme avec la saturation du FS sur l'environnement de test où le contexte n'est pas reproduit... le moteur a fait un shutdown brutal... contrairement à l'environnement principal qui lui tourne toujours.

#7 Re : Général » [ABANDONNE] [9.6] Plus de checkpoint » 13/12/2019 00:03:39

Pas eu le temps d'analyser plus avant le problème aujourd'hui.
Toutefois, une sauvegarde de la base selon son mode habituel, en shuntant le pg_start_backup, a pu être rechargée sur un serveur de test.
Avec la mise en ligne des quelque 30Go de fichiers WAL générés depuis le dernier checkpoint valide, la base a démarré sans anomalie et les checkpoints passent normalement, y compris la sauvegarde.

Sur cette environnement de test, petite expérience qui ne coûtait rien, un "kill -9" du process checkpointer.
Le moteur n'a pas planté, juste une refresh de l'ensemble de tous les process fils de PostgresSQL (writer, vaccum, etc)

A dire que c'est ce quipourrait être joué sur l'environnement principal...

Test de saturation du FS à venir en espérant reproduite le même phénomène.

#8 Re : Général » [ABANDONNE] [9.6] Plus de checkpoint » 11/12/2019 13:00:34

Pour la libération d'espace, par chance un gros fichier trainait sur le FS... qui n'avait rien à y faire.
Aucun fichier lié au moteur n'a été supprimé.

#9 Re : Général » [ABANDONNE] [9.6] Plus de checkpoint » 11/12/2019 11:58:10

Un strace d'un checkpoint sur un moteur fonctionnel neutral

epoll_wait(6,

7f99e19a1160, 1, 37688)   = -1 EINTR (Interrupted system call)
--- SIGINT (Interrupt) @ 0 (0) ---
write(12, "\0", 1)                      = 1
rt_sigreturn(0xc)                       = -1 EINTR (Interrupted system call)
close(6)                                = 0
write(2, "2019-12-11 09:34:07 GMT @ () [58"..., 85) = 85
open("pg_replslot/base_backup_slot/state.tmp", O_WRONLY|O_CREAT|O_EXCL, 0600) = 6
write(6, "\241\34\5\1G\315\361\r\2\0\0\0\240\0\0\0base_backup_slot"..., 176) = 176
fsync(6)                                = 0
close(6)                                = 0
rename("pg_replslot/base_backup_slot/state.tmp", "pg_replslot/base_backup_slot/state") = 0
open("pg_replslot/base_backup_slot/state", O_RDWR) = 6
fsync(6)                                = 0
close(6)                                = 0
open("pg_replslot/base_backup_slot", O_RDONLY) = 6
fsync(6)                                = 0
close(6)                                = 0
open("pg_replslot", O_RDONLY)           = 6
fsync(6)                                = 0
close(6)                                = 0
openat(AT_FDCWD, "pg_logical/snapshots", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 6
getdents(6, /* 2 entries */, 32768)     = 48
getdents(6, /* 0 entries */, 32768)     = 0
close(6)                                = 0
openat(AT_FDCWD, "pg_logical/mappings", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 6
getdents(6, /* 2 entries */, 32768)     = 48
getdents(6, /* 0 entries */, 32768)     = 0
close(6)                                = 0
unlink("pg_logical/replorigin_checkpoint.tmp") = -1 ENOENT (No such file or directory)
open("pg_logical/replorigin_checkpoint.tmp", O_WRONLY|O_CREAT|O_EXCL, 0600) = 6
write(6, "\336\332W\22", 4)             = 4
write(6, "6\262\0j", 4)                 = 4
close(6)                                = 0
open("pg_logical/replorigin_checkpoint.tmp", O_RDWR) = 6
fsync(6)                                = 0
close(6)                                = 0
open("pg_logical/replorigin_checkpoint", O_RDWR) = 6
fsync(6)                                = 0
close(6)                                = 0
rename("pg_logical/replorigin_checkpoint.tmp", "pg_logical/replorigin_checkpoint") = 0
open("pg_logical/replorigin_checkpoint", O_RDWR) = 6
fsync(6)                                = 0
close(6)                                = 0
open("pg_logical", O_RDONLY)            = 6
...

#10 Re : Général » [ABANDONNE] [9.6] Plus de checkpoint » 11/12/2019 11:23:20

Pour info complémentaire, ce que retourne un strace du process checkpointer lors d'un CHECKPOINT :

semop(3014694, {{4, -1, 0}}, 1
 
 
)         = -1 EINTR (Interrupted system call)
--- SIGINT (Interrupt) @ 0 (0) ---
rt_sigreturn(0x7fb272979904)            = -1 EINTR (Interrupted system call)

Pa d'erreur notable dans pg_log, seulement lors de l'interruption de la commande :

2019-12-11 08:54:35 GMT postgres@[local] (postgres) [8419]  ERROR:  canceling statement due to user request
2019-12-11 08:54:35 GMT postgres@[local] (postgres) [8419]  STATEMENT:  CHECKPOINT;

Pour le process checkpointer, pas de consommation CPU/RAM particulière, tout à fait similaire à un autre environnement :

PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 9471 postgres  20   0 6435m 6.1g 6.1g S    0  9.7 519:31.75 postgres

Ça correspond donc à un PGSemaphoreLock().  J'imagine qu'il s'agit de celui correspondant à l'attente durant LWLockAcquire().  Malheureusement, je pense que la seule manière d'en savoir plus sur la cause de ce verrou non accordé (ou autre cause d'attente sur sémaphore) est d'inspecter le processus avec gdb et d'afficher sa stack trace, en ayant pris soin d'installer les symboles de debug.  Vous pouvez consulter https://wiki.postgresql.org/wiki/Gettin … _Linux/BSD en cas de besoin.

#11 Général » [ABANDONNE] [9.6] Plus de checkpoint » 09/12/2019 23:52:42

jeff7194
Réponses : 20

Bonjour,

J'ai une base qui tourne sous PostgreSQL 9.6 / Ubuntu 12.04 (volumétrie ~ 80Go)

Voilà quelques jours, le filesystem a été saturé par l'archivage des fichiers WAL... je sais c'est ballot mais c'est conçu ainsi.
De la place a pu être libérée et la base a repris son fonctionnement sans qu'aucune relance de service n'ait été nécessaire.

Toutefois, j'ai depuis constaté que le dossier pg_xlog ne se vidait plus.
Plus de sauvegarde non plus (basée sur amanda), le pg_start_backup() n'aboutit jamais.

En fait, il n'y a plus aucun checkpoint qui passe sur la base et un pg_controldata indique que le dernier date du moment de la saturation disque.
Lancée manuellement, la commande CHECKPOINT ne rend jamais la main même après plusieurs heures.

N'ayant pas trouvé secours auprès de mes DBA j'espère que la communauté pourra m'aider.
La base étant répliquée, la solution ultime restera la bascule et la reconstruction du moteur master par pg_basebackup/pg_rewind

Salutations.
JF

Pied de page des forums

Propulsé par FluxBB