Restauration en échec : problème possible avec Data Explorer

J’ai un forum fonctionnel et je souhaite restaurer l’état d’il y a quelques jours, avant que des problèmes ne surviennent. Je suis sur AWS, j’ai donc créé une AMI de mon forum fonctionnel, lancé une nouvelle instance et tenté de restaurer une sauvegarde datant de quelques jours. Cela a échoué avec les messages ci-dessous.

Ce ne peut pas être un problème de version ou de schéma, car le serveur est construit à partir d’une image fraîche de mon forum fonctionnel.

J’ai essayé de reconstruire.

J’ai aussi essayé de restaurer à partir d’une autre sauvegarde datant d’un jour seulement : même résultat.

La seule chose étrange que j’ai faite est d’avoir supprimé des fichiers PDF du répertoire d’upload (…/uploads/original/1X/*.pdf) pour libérer de l’espace. Je vais réessayer sans cette étape, mais il est peu probable que ce soit la cause du problème.

> [2019-11-30 01:17:44] 'admin' a commencé la restauration !
> [2019-11-30 01:17:44] Marquage de la restauration comme en cours...
> [2019-11-30 01:17:44] Vérification de l'existence de /var/www/discourse/tmp/restores/default/2019-11-30-011744...
> [2019-11-30 01:17:44] Téléchargement de l'archive vers le répertoire temporaire...
> [2019-11-30 01:23:24] Décompression de l'archive, cela peut prendre un certain temps...
> [2019-11-30 01:27:52] Aucun fichier de métadonnées à extraire.
> [2019-11-30 01:27:52] Validation des métadonnées...
> [2019-11-30 01:27:52]   Version actuelle : 20191129144706
> [2019-11-30 01:27:52]   Version restaurée : 20191120015344
> [2019-11-30 01:27:52] Extraction du fichier dump...
> [2019-11-30 01:50:57] commande invalide \N
> [2019-11-30 01:50:57] commande invalide \N
> 
> 
> < répété environ 100 fois >
> 
> [2019-11-30 01:51:07] commande invalide \N
> [2019-11-30 01:54:13] commande invalide \N
> [2019-11-30 01:54:13] EXCEPTION : psql a échoué
> [2019-11-30 01:54:14] /var/www/discourse/lib/backup_restore/restorer.rb:331:in `restore_dump'
> /var/www/discourse/lib/backup_restore/restorer.rb:75:in `run'
> /var/www/discourse/lib/backup_restore.rb:166:in `block in start!'
> /var/www/discourse/lib/backup_restore.rb:163:in `fork'
> /var/www/discourse/lib/backup_restore.rb:163:in `start!'
> /var/www/discourse/lib/backup_restore.rb:22:in `restore!'
> /var/www/discourse/app/controllers/admin/backups_controller.rb:119:in `restore'
> etc...

Néanmoins, l’erreur invalid command \N est typique d’un conflit de version Postgres…

root@example:/var/www/discourse# psql --version
psql (PostgreSQL) 10.10 (Debian 10.10-1.pgdg100+1)

C’est la même version sur le nouveau serveur et le forum fonctionne.

J’avais tendance à associer ces erreurs à une correspondance de version de PostgreSQL, mais j’ai remarqué ces erreurs \N l’autre jour sur un système qui avait épuisé son espace disque (je restaurais sur le même système qui avait créé la sauvegarde). Je n’ai pas terminé le diagnostic du problème (c’était un autre problème bizarre que je rencontrais, et la restauration d’une sauvegarde sur un autre serveur a résolu le problème ; je me demandais si la restauration sur le même serveur l’aurait également résolu).

Vous avez mentionné que vous manquiez d’espace. Je soupçonne que c’est la cause. La restauration utilise beaucoup d’espace car elle décompresse la sauvegarde, ce qui nécessite donc deux copies complètes de celle-ci, plus l’espace nécessaire pour la restauration et pour permettre un retour en arrière en cas d’échec.

Donc il faut 23 minutes avant que cela échoue ?

Ça empire, mais c’est peut-être plus proche du vrai problème… En partant de l’hypothèse que j’avais besoin de plus d’espace disque, j’ai créé une nouvelle instance à partir de mon image, cette fois avec 100 Go, contre 50 Go auparavant. (Les sauvegardes font 5 Go chacune et sont stockées sur S3.) Cette fois, j’ai obtenu une erreur explicite : « No space left on device ». Pourtant, la commande df affiche beaucoup d’espace disponible.

> [2019-11-29 22:42:58] Vérification que /var/www/discourse/tmp/restores/default/2019-11-29-224258 existe...
> [2019-11-29 22:42:58] Téléchargement de l'archive dans le répertoire temporaire...
> [2019-11-29 22:45:46] Décompression de l'archive, cela peut prendre un certain temps...
> [2019-11-29 22:51:46] Aucun fichier de métadonnées à extraire.
> [2019-11-29 22:51:46] Validation des métadonnées...
> [2019-11-29 22:51:46]   Version actuelle : 20191129144706
> [2019-11-29 22:51:46]   Version restaurée : 20191108000414
> [2019-11-29 22:51:46] Extraction du fichier dump...
> [2019-11-29 22:53:47] EXCEPTION : No space left on device @ io_write - /shared/tmp/restores/default/2019-11-29-224258/dump.sql

> [ec2-user@ip-172-31-47-237 discourse]$ df / -h
> Filesystem      Size  Used Avail Use% Mounted on
> /dev/xvda1       99G   28G   71G  28% /

Curieusement, il n’y a rien dans le répertoire mentionné :

> /var/www/discourse# ls /shared/tmp/*
> /shared/tmp/backups :
> < vide >
> /shared/tmp/restores :
> < vide >

Est-ce que cela pourrait être un problème lié au fichier d’échange (swap) ? L’instance EC2 est un t2.small avec 2 Go de mémoire, j’avais donc créé un fichier d’échange il y a longtemps sur le forum fonctionnel. Je suppose que le fichier d’échange a été répliqué sur la nouvelle instance. Je ne suis pas expert, mais je pense que le fichier d’échange existe, car il ne m’a pas permis d’en créer un nouveau, et parce que :

> /var/www/discourse# swapon -s
> Filename                                Type            Size    Used    Priority
> /swapfile                               file            2097148 1024    -2

Cela pourrait être un problème d’inodes. Que vous indique df -i ?

df -i
Filesystem Inodes IUsed IFree IUse% Mounted on
devtmpfs 252562 437 252125 1% /dev
tmpfs 255203 1 255202 1% /dev/shm
/dev/xvda1 6553600 737194 5816406 12% /

Je sors de mon domaine d’expertise, mais je suppose que ce n’est pas grave ?

Non, ce n’est pas grave.

L’erreur « No space left on device » (Espace disque insuffisant) ne se produit pas uniquement lorsque le disque est plein en gigaoctets, mais aussi lorsque le système de fichiers épuise ses inodes. Cependant, ce n’est clairement pas le problème ici. (iUse% serait alors à 100 %).

Toujours pas de succès. J’ai pensé essayer une restauration sur une nouvelle instance Lightsail, plutôt que de lancer une AMI de mon instance EC2 fonctionnelle. Cela échoue toujours, mais les messages sont quelque peu différents.

Les deux instances, ancienne et nouvelle, sont à jour, toutes deux sont des installations Docker standard, et toutes deux exécutent la même version de postgres :

psql --version
psql (PostgreSQL) 10.10 (Debian 10.10-1.pgdg100+1)

Est-ce normal :

Création des fonctions manquantes dans le schéma discourse_functions
Impossible de restaurer dans un schéma différent, restauration in-place

Cela pourrait-il être lié aux plugins ? J’ai plusieurs plugins, à la fois pris en charge et personnalisés, installés sur le site « source ». Certains utilisent des champs utilisateur personnalisés. J’ai essayé de restaurer sur des sites « destination » propres, avec et sans plugins.

Des pistes pour commencer à comparer les schémas ?

> [2019-12-07 04:51:36] 'admin' a commencé la restauration !
> [2019-12-07 04:51:36] Marquage de la restauration comme en cours...
> [2019-12-07 04:51:36] Vérification de l'existence de /var/www/discourse/tmp/restores/default/2019-12-07-045136...
> [2019-12-07 04:51:36] Téléchargement de l'archive dans le répertoire tmp...
> [2019-12-07 04:53:49] Décompression de l'archive, cela peut prendre un certain temps...
> [2019-12-07 04:57:12] Aucun fichier de métadonnées à extraire.
> [2019-12-07 04:57:12] Validation des métadonnées...
> [2019-12-07 04:57:12]   Version actuelle : 20191129144706
> [2019-12-07 04:57:12]   Version restaurée : 20191120015344
> [2019-12-07 04:57:12] Extraction du fichier dump...
> [2019-12-07 04:59:10] Création des fonctions manquantes dans le schéma discourse_functions
> [2019-12-07 04:59:11] Impossible de restaurer dans un schéma différent, restauration in-place
> [2019-12-07 05:05:02] ERREUR : la transaction en cours est annulée, les commandes sont ignorées jusqu'à la fin du bloc de transaction
> [2019-12-07 05:05:03] ERREUR : la transaction en cours est annulée, les commandes sont ignorées jusqu'à la fin du bloc de transaction
> < répété environ 100 fois >
> [2019-12-07 05:05:03] ERREUR : la transaction en cours est annulée, les commandes sont ignorées jusqu'à la fin du bloc de transaction
> [2019-12-07 05:05:03] EXCEPTION : psql a échoué
> [2019-12-07 05:05:03] /var/www/discourse/lib/backup_restore/restorer.rb:331:in `restore_dump'
> /var/www/discourse/lib/backup_restore/restorer.rb:75:in `run'
> /var/www/discourse/lib/backup_restore.rb:166:in `block in start!'
> /var/www/discourse/lib/backup_restore.rb:163:in `fork'
> /var/www/discourse/lib/backup_restore.rb:163:in `start!'
> /var/www/discourse/lib/backup_restore.rb:22:in `restore!'
> /var/www/discourse/app/controllers/admin/backups_controller.rb:119:in `restore'
> < reste de la trace de l'appel >

Oui, c’est normal.

Il y a manifestement un problème à l’intérieur de PostgreSQL. Avez-vous consulté ses journaux ?

Hypothèse peu probable : cela pourrait-il être lié à la mémoire ? Pouvez-vous essayer de surveiller la sortie de free -m pendant la restauration et vérifier si la mémoire (virtuelle) vient à manquer.

Je sais que c’est une question difficile puisque nous ne connaissons pas le problème, mais en général, dois-je installer les plugins sur le site de destination avant d’essayer de restaurer ? Ou la restauration récupère-t-elle et construit-elle les plugins ?

Oui, c’est nécessaire : la restauration ne le fera pas pour vous.

Cependant, je ne pense pas que ce soit votre problème, car la restauration prendra bien en charge la structure correcte de la base de données (y compris les éléments spécifiques aux plugins).

J’ai créé un nouveau Lightsail à 20 $ avec 4 Go de mémoire. J’ai surveillé free -m pendant la restauration. Il y avait toujours beaucoup de mémoire libre et disponible.

Les erreurs spécifiques varient selon que les plugins sont installés ou non, mais elles sont probablement dues à la même cause racine. Dans ce cas, je n’avais pas installé les plugins avant la sauvegarde. Il existe deux catégories d’erreurs :

  1. Dans les journaux de postgres, je vois beaucoup de ces messages, parfois au caractère 34 et parfois au caractère 41.

discourse@discourse ERROR: relation “user_auth_tokens” does not exist at character 34

Celles-ci n’ont pas de sortie correspondante dans la page admin > sauvegarde > journal, et la restauration continue pendant plusieurs minutes malgré ces erreurs.

  1. La deuxième erreur dépend du fait que les plugins soient installés. Dans ce cas, je ne les avais pas installés, donc j’ai reçu une erreur concernant Data Explorer, et c’est là que tout a dérapé.

Dans admin > sauvegarde > journaux :

[2019-12-07 07:38:34] CREATE INDEX
[2019-12-07 07:38:34] CREATE INDEX
[2019-12-07 07:38:34] ERROR: could not create unique index “index_plugin_store_rows_on_plugin_name_and_key”
[2019-12-07 07:38:34] DETAIL: Key (plugin_name, key)=(discourse-data-explorer, q:-6) is duplicated.
[2019-12-07 07:38:34] ERROR: current transaction is aborted, commands ignored until end of transaction block
[2019-12-07 07:38:34] ERROR: current transaction is aborted, commands ignored until end of transaction block
< répété 1000 fois et s’arrête >

Et la sortie correspondante dans le journal de postgres :

2019-12-07 07:38:34.718 UTC [8991] discourse@discourse LOG: duration: 165.427 ms statement: CREATE INDEX index_notifications_on_user_
id_and_topic_id_and_post_number ON public.notifications USING btree (user_id, topic_id, post_number);
2019-12-07 07:38:34.767 UTC [8991] discourse@discourse ERROR: could not create unique index “index_plugin_store_rows_on_plugin_name_an
d_key”
2019-12-07 07:38:34.767 UTC [8991] discourse@discourse DETAIL: Key (plugin_name, key)=(discourse-data-explorer, q:-6) is duplicated.
2019-12-07 07:38:34.767 UTC [8991] discourse@discourse STATEMENT: CREATE UNIQUE INDEX index_plugin_store_rows_on_plugin_name_and_key O
N public.plugin_store_rows USING btree (plugin_name, key);
2019-12-07 07:38:34.984 UTC [8991] discourse@discourse ERROR: current transaction is aborted, commands ignored until end of transactio
n block
2019-12-07 07:38:34.984 UTC [8991] discourse@discourse STATEMENT: CREATE INDEX index_policy_users_on_post_policy_id_and_user_id ON pub
lic.policy_users USING btree (post_policy_id, user_id);

Je pense que le problème #1 n’est pas fatal et n’est qu’un effet secondaire de la restauration sur place.

Vous pourriez envisager d’exporter (et) de supprimer toutes les requêtes de l’explorateur de données, puis de désinstaller le plugin de l’explorateur de données avant de créer votre sauvegarde.

Sinon, pouvez-vous publier le contenu pertinent de la table plugin_store_rows ?

Il existe en effet des requêtes en double avec des paires (plugin_name, key) identiques, par exemple q:-11 et q:-2, mais avec des identifiants uniques. Je ne vois aucun motif parmi les doublons ; ce ne sont pas mes requêtes préférées ou autre chose de similaire.

Ma prochaine étape consistera donc à supprimer les doublons, à créer une sauvegarde, puis à tenter une restauration à partir de celle-ci.

SELECT id, plugin_name, key from plugin_store_rows
WHERE plugin_name = ‘discourse-data-explorer’
ORDER BY key

id plugin_name key
1138 discourse-data-explorer q:-1
1136 discourse-data-explorer q:-10
813 discourse-data-explorer q:10
1142 discourse-data-explorer q:-11
1397 discourse-data-explorer q:-11
825 discourse-data-explorer q:11
889 discourse-data-explorer q:13
1004 discourse-data-explorer q:14
1005 discourse-data-explorer q:15
1043 discourse-data-explorer q:17
1044 discourse-data-explorer q:18
514 discourse-data-explorer q:-2
1249 discourse-data-explorer q:-2
764 discourse-data-explorer q:2
1053 discourse-data-explorer q:21
1066 discourse-data-explorer q:22
1082 discourse-data-explorer q:23
1097 discourse-data-explorer q:24
1131 discourse-data-explorer q:26
1132 discourse-data-explorer q:27
1134 discourse-data-explorer q:28
1135 discourse-data-explorer q:29
775 discourse-data-explorer q:3
1137 discourse-data-explorer q:30
1140 discourse-data-explorer q:31
1141 discourse-data-explorer q:32
1143 discourse-data-explorer q:33
1149 discourse-data-explorer q:34
1155 discourse-data-explorer q:35
1156 discourse-data-explorer q:36
1157 discourse-data-explorer q:37
1158 discourse-data-explorer q:38
1161 discourse-data-explorer q:39
513 discourse-data-explorer q:-4
777 discourse-data-explorer q:4
1211 discourse-data-explorer q:40
1215 discourse-data-explorer q:41
1223 discourse-data-explorer q:42
1224 discourse-data-explorer q:43
1225 discourse-data-explorer q:44
1226 discourse-data-explorer q:45
1269 discourse-data-explorer q:46
1272 discourse-data-explorer q:47
1273 discourse-data-explorer q:48
1274 discourse-data-explorer q:49
1279 discourse-data-explorer q:50
1281 discourse-data-explorer q:51
1282 discourse-data-explorer q:52
1301 discourse-data-explorer q:53
1349 discourse-data-explorer q:54
1369 discourse-data-explorer q:55
1373 discourse-data-explorer q:56
1384 discourse-data-explorer q:57
1387 discourse-data-explorer q:58
1396 discourse-data-explorer q:59
1222 discourse-data-explorer q:-6
1348 discourse-data-explorer q:-6
781 discourse-data-explorer q:6
763 discourse-data-explorer q:-7
782 discourse-data-explorer q:7
515 discourse-data-explorer q:-8
791 discourse-data-explorer q:8
1139 discourse-data-explorer q:-9
798 discourse-data-explorer q:9
507 discourse-data-explorer q:_id

En fait, comment puis-je supprimer les doublons ? Les trois sont détenus par « system », donc je ne peux pas les modifier ou les supprimer.

J’ai trouvé le motif. Lorsque j’exécute une requête appartenant au système, cela crée un doublon, ce qui semble visiblement casser la restauration.

Je ne parviens pas à reproduire ce problème sur un site de test propre, mais il se produit systématiquement sur mon site de production. J’ai installé tous les plugins de production sur le site de test, mais je ne parviens toujours pas à reproduire le problème.

  1. Comment puis-je identifier ce qui ne va pas avec mon site de production ?

  2. Comment puis-je supprimer les requêtes en double, puisqu’elles sont gérées par le système ? Dois-je exécuter sudo -u postgres psql discourse ? Cela semble effrayant.

Pour que la sauvegarde soit restaurable, vous pouvez probablement supprimer les lignes en double du fichier SQL sauvegardé.

Il est possible que la base de données de développement manque de cet index pour une raison quelconque ?