Chapril » pad.chapril.org

Je pense que c'est drôlement bien observé.
Une piste : le plugin photo.

Dans le graphique, on peut voir une augmentation significative (15 Go) le 23/02/2021 entre 14h et 17h :

Pour rappel, les pads sont stockés sous forme de json contenant un champ timestamp. Trouvons une fourchette de timestamp compatible avec le créneau visé :

cpm@ocmstar (12:39:34) ~ 24 > date -d @1614080000; date -d @1614099999
mardi 23 février 2021, 12:33:20 (UTC+0100)
mardi 23 février 2021, 18:06:39 (UTC+0100)

Requêtons :

etherpad=# select count(*), sum(length(value)), sum(length(value))/1024/1024 as mo  from store s where (s.value like '%"timestamp":161408%' or s.value like '%"timestamp":161409%') ;
 count |    sum     |  mo  
-------+------------+------
 14222 | 1459047113 | 1391
(1 ligne)

etherpad=# select count(*), sum(length(value)) as taille ,sum(length(value))/1024/1024 as mo  from store s where s.key like 'pad%' and (s.value like '%"timestamp":161408%' or s.value like '%"timestamp":161409%')  ;
 count |   taille   |  mo  
-------+------------+------
 14180 | 1459040414 | 1391
(1 ligne)

Donc à cette période, on constate la création de 14180 lignes de pads pour un total de ~1,4 Go de données.

Déterminons combien de lignes pèsent le plus :

etherpad=# select count(*), sum(length(value)), sum(length(value))/1024/1024 as mo  from store s where s.key like 'pad%' and (s.value like '%"timestamp":161408%' or s.value like '%"timestamp":161409%') and length(s.value)>100000 ;
 count |   sum      |  mo  
-------+------------+------
    42 | 1454126556 | 1386
(1 ligne)

Donc l'augmentation de 16 Go constatée sur le graphique viendrait des 1,4 Go de ces 42 lignes.
Ça fait un facteur 10 de différence. Est-ce du à la gestion de Postgresql ?

etherpad=# select count(*), sum(length(key)+length(value)), sum(length(key)+length(value))/1024/1024 as Mo  from store s ;
  count   |    sum     |  mo  
----------+------------+------
 10497954 | 5590464435 | 5331
(1 ligne)

=(^-^)=root@pad:/var/lib/postgresql# du -sch 11
25G     total

Donc constat que ~5 Go de données prennent 25 Go d'espace disque, soit x5. On peut imaginer que pour de grosses données, ça passe à x10. Ok.

Déterminons le nom des pads concernés et leur taille :

etherpad=# select key,length(value) as taille from store s where s.key like 'pad%' and (s.value like '%"timestamp":161408%' or s.value like '%"timestamp":161409%')  order by taille desc limit 45 ; 
                            key                            |  taille  
-----------------------------------------------------------+----------
 pad:gxxxxx1:revs:32800                                    | 34627097
 […] x 40
 pad:gxxxxx1:revs:28700                                    | 34617731
 pad:Terxxxxxxxxxxxxxxx                                    |    71412
 pad:9lt1xxxxxxxxxxxx:revs:5400                            |    63445
 pad:9lt1xxxxxxxxxxxx:revs:5300                            |    62259
(50 lignes)

Donc, le 23/02/2021, l'augmentation de 15 Go de l'espace disque vient d'un seul pad, gxxxxxx1, dont 42 itérations pèsent chacune 34 Mo.

etherpad=# select substr(value, 0, 10000) from store where key='pad:gxxxxxxxxx1:revs:32800';
 {"changeset":"Z:1sx7<
[…]
"144":["color","orange"],"145":["img","<img src=data:image/png;base64,iVBORw0KGgoAAAANSUhEUgAABlQAAAhwCAIAAADUbkSSAAAAAXNSR0IArs4c6QAAAI5lWElmTU0AKgAAAAgAAgESAAMAAAABAAEAAIdpAAQAAAABAAAAJgAAAAAABZADAAIAAAAUAAAAaJKGAAcAAAASAAAAfKABAAMAAAABAAEAAKACAAQAAAABAAAGVKADAAQAAAABAAAIcAAAAAAyMDIxOjAyOjE5IDExOjE5OjQ5AEFTQ0lJAAAAU2NyZWVuc2hvdOOZOb4AAAHvaVRYdFhNTDpjb20uYWRvYmUueG1wAAAAAAA8eDp4bXBtZXRhIHhtbG5zOng9ImFkb2JlOm5

Une image plain-text dans le json du pad ? En fait, dans chaque itération du pad ?!!! Argh !

Donc l'augmentation soudaine viendrait de l'utilisation du plugin https://www.npmjs.com/package/ep_image_upload

Recommandations :
1) désactiver dès que possible le plugin image ;
2) retirer de tout les json de pad les champs img ;
3) ne plus activer de plugin sans une vérification préalable de leur fonctionnement.

Le 12/03/2021 sur Freenode#april-chapril :

13:04 < QGuLL> DISK CRITICAL - free space: /srv/backups 9227 MB (1% inode=99%);
13:04 < QGuLL> 1% libre /o\
13:08 < PoluX> oula
13:09 < PoluX> faut arrêter de backupper le pad
13:09 < neox> PoluX: ah c'est le pad qui prend tout ça ?
13:10 < PoluX> QGuLL: le pad fait de la merde aux backups
13:10 < PoluX> et il faut virer /var/lib/pg des backups
13:10 < QGuLL> le /var/lib/postgresql peut être mis en ignore
14:27 < cpm_screen> j'ai supprimé le plugin qui pose problème mais le fait est que l'image est potentiellement propager dans les nouvelles révision du pad
14:27 < cpm_screen> et donc la consommation est susceptible d'augmentée
14:27 < cpm_screen> j'ai passé du temps à regarder comment le nettoyer mais je suis inquiet de modifier directement la structure du pad
14:28 < cpm_screen> je vais regarder un peu plus
14:34 < cpm_screen> puisque là, on a un gros problème technique et que ça ne vient que de 4 pads, je propose de les supprimer et de les recréer (copier/coller du contenu) manuellement avec un message au début pour prévenir qu'on a du faire une action technique impérative
14:35 < QGuLL> je vote pour
14:35 < QGuLL> si on connait les auteurs et qu'ils sont sur irc leur demander avant ?
14:36 < cpm_screen> c'est peu probable, je regarde
14:36 < QGuLL> juste si c'est isa ping la avant de parter courir
14:36 < QGuLL> ou fred, ou etienne
14:37 < cpm_screen> oui, bien vu
14:37 < cpm_screen> =(^-^)=root@pad:~/Cpm# ll /root/Cpm/listgrospad-stats
14:38 < cpm_screen> dans ce fichier, tu as le nom des pads
14:38 < cpm_screen> pour info
14:40 < cpm_screen> rien que le nom des pads permet de déduire assez bien que ce ne sont pas des habitués d'irc
14:40 < QGuLL> 2.4G pour un pad c'est possible ? /o\
14:40 < cpm_screen> bah vala
14:41 < PoluX> cpm_screen: vaut supprimer le pad concerné, pas s'emmerder
14:41 < cpm_screen> le plugin photo est peut-être très bien mais il faut le configurer pour une sauvegarde externe des fichiers
14:42 < cpm_screen> oui, mais sauver le contenu pour pouvoir le récréer
14:42 < cpm_screen> avant
14:42 < cpm_screen> comme ça on fait perdre l'historique à l'utilisateur mais pas le contenu
14:42 < cpm_screen> et pis comme c'ets facile on peut le faire
14:43 < cpm_screen> teslix: du coup on va pas faire via commandes psql, merci quand même à toi, et y aura d'autres besoins hein :D
14:44 < cpm_screen> là mon script de stats montre qu'un des pads problématique est passé de 71 révisions à 88, 32 Mo * 17 = 544 Mo de plus, boom
14:45 < cpm_screen> bon, je vais essayer de faire l'opération de suite
14:46 < PoluX> je vais exclure le var lib psql des backups et tout pruner
14:49 < teslix> cpm_screen: dac ;)
14:50 < PoluX> cpm_screen: sauf si tu me dis que tu met la db au régime
14:51 < cpm_screen> je suis en train de recréer les 4 pads problèmétiques donc la bd va perdre 3 Go dans les 20 minutes qui viennent
14:51 < PoluX> ok ; j'essaie dans 20 mins :)
14:51 < cpm_screen> pardon, 3 Go de données effectives donc en données Postgresql, ça va faire dans les 25 Go en moins
14:52 < cpm_screen> vala, premier pad traité (c'est le plus léger, 1 révision seulement)
14:54 < cpm_screen> et de 2/4
14:56 < cpm_screen> et de 3/4
14:59 < PoluX> cpm_screen: je vais quand même exclure temporairement /var/lib/postgresql/ car il reste à 30G
15:04 < cpm_screen> bah nan, attends
15:04 < cpm_screen> voilà, j'ai recréé les 4 pads, donc noramlement maitenant la base devrait avoir perdu dans les 30 Go.
15:05 < cpm_screen> et du coup le prochain backup devrait être « normal »
15:07 < PoluX> du -sh /var/lib/postgresql/
15:07 < PoluX> 30GI/var/lib/postgresql/
15:08 < cpm_screen> bon, d'abord vérifier que mon nettoyage est opérant
15:09 < cpm_screen> pour vérifier, faudrait générer un export pour comparer, car après tout c'est l'export qui est backupé
15:10 < PoluX> je suis en train de dumper la db pour le backu
15:13 < PoluX> le nouveau dump fait 331M
15:14 < cpm_screen> et du coup, c'est mieux 331 Mo ? Avant c'était combien ?
15:15 < cpm_screen> 14:59 < PoluX> cpm_screen: je vais quand même exclure temporairement /var/lib/postgresql/ car il reste à 30G
15:15 < cpm_screen> heu … mais heu … il est sauvegardé ce dossier ?
15:15 < cpm_screen> à quoi ça sert puisqu'on fait le dump exprès ?
15:15 < PoluX> cpm_screen: on est descendu de 2Go sur le dump
15:15 < cpm_screen> haaaaaaaaaaaaaaaaa \o/
15:16 < PoluX> cpm_screen: oui il était sauvegardé
15:16 < cpm_screen> oups, bah oui mais nan, faut pas hein on est d'accord que faut pas ?
15:16 < PoluX> ça sert à ne pas se soucier des détails pour la reconstruction quand tu as une petite db
15:16 < PoluX> c'est pas un mal
15:17 < PoluX> mais ça scale pas, c'est sûr
15:18 < cpm_screen> bah j'ignore comment dire à postgrsql de faire le ménage dans ses tampons
15:18 < PoluX> cpm_screen: je ne connais pas assez postgres pour promettre que tout (user, grants, etc.) est contenu dans les dumps qu'on a
15:18 < PoluX> c'est l'intérêt de tout prendre :)
15:19 < cpm_screen> teslix: question pour toi, on vient de virer 3 Go de données de la base (30 Go en réel), et /var/lib/posgresql n'a pas maigri lui
15:19 < cpm_screen> teslix: comment le faire maigrir ?
15:19 < teslix> il faut faire un vacuum full de la table mais ça bloque les accès
15:20 < cpm_screen> pendant combien de temps ?
15:20 < teslix> après le moteur va réutiliser l'espace lors des prochain insertions
15:20 < teslix> ça dépend des perf de ton stockage ;)
15:20 < cpm_screen> et c'est quoi la commande ?
15:22 < teslix> vacuum full matable;
15:22 < teslix> après ça bloque les accès hein
15:22 < teslix> au pire tu peux faire un ctrl-c pour interrompre
15:22 < teslix> et pendant la copie tu bouffer le double d'espace disque
15:22 < cpm_screen> oui, logique, ha oups
15:23 < cpm_screen> oki, si ça dure quelques minutes, ça le fera bien
15:23 < teslix> tu as des ssd ?
15:23 < cpm_screen> nan, donc oui, lent
15:23 < cpm_screen> teslix: merci bcp pour l'aide :)
15:23 < cpm_screen> PoluX: y a un backup en cours ?
15:24 < PoluX> cpm_screen: oui; le pruning est en cours
15:24 < cpm_screen> oki, parce que je n'arrive pas à faire borg list, merci
15:25 < PoluX> cpm_screen: borg il rame un peu là : https://grafana.chapril.org/d/qfRrThRMk/icinga2-influxdb-host?from=now-1h&orgId=1&to=now&viewPanel=1&var-hostname=felicette.orbite.chapril.org&var-service=volume
15:25 < PoluX> mais contrairement à pg il libère pour de vrai :)
15:26 < cpm_screen> huhu
15:28 < cpm_screen> PoluX: tu dit prune et backup qui prune, ça veut dire que tu as changé la conf et compte dessus ? Tu ne pensais pas supprimer manuellement des sauvegardes ?
15:28 < PoluX> cpm_screen: oui j'ai changé la conf et je compte dessus
15:29 < PoluX> pruning fini
15:31 < PoluX> et je crois que je vais laisser l'exclusion :)
15:31 < cpm_screen> oki, je pense que c'est sage pour ce service, et que les inconvénients sont mineurs (ou gérables)
15:42 < PoluX> cpm_screen: backup fini en 7 mins, il fait un consistency check
15:42 < PoluX> dedup size : 217.24 MB
15:42 < PoluX> c'est mieux
15:42 < cpm_screen> \o/

Tout semble revenu bien (sauvegarde et espace disque). Fermeture du ticket.

Confirmé.