0

Linux Out-Of-Memory Killer (OOM-Killer) pour un serveur base de données PostgreSQL

twitterlinkedinmail

 

Hello,

bonjour à toutes et tous et bonne année 2021 à vous !

Aujourd’hui nous allons nous pencher sur un nouveau sujet qui parlera à beaucoup d’entre nous utilisateurs linux qui administrons des bases de données sous ce système !

Nous avons rencontré, récemment chez un de nos clients, des soucis de “kill” de process survenus sur notre instance PostgreSQL. C’est durant des opérations assez lourdes en terme de charge mémoire que cela s’est produit. Notre client utilise l’extension “pg_partman” qui, couplé avec “pg_cron” permet de disposer du partitionning non natif, au sein d’une base PostgreSQL.

Jusqu’ici tout allait bien, mais avec la charge de données insérées dans les partitions, certaines opérations ont pris beaucoup plus de temps, et surtout ont nécessité de d’avantage de ressources mémoire !

Nous avons remonté l’ordre SQL en cause qui était exécuté via “pg_partman” :

select result.fn_agreg_rumresulthourly();

Pour les utilisateurs de cette extension, cela parlera très certainement, il s’agit d’un job qui va “merger” les données par heures pour en faire une nouvelle partition journalière. Et c’est la que la mécanique peut vite être très compliquée à gérer par l’OS en arrière plan….

 

OOM-Killer, qu’est ce que c’est ?

Lorsqu’un processus requiert de la mémoire pour son fonctionnement, le kernel Linux va alors lui réserver des pages qui lui seront nécessaire pour mener à bien son opération, c’est le principe de la mémoire réservée (reserved memory). Au fur et à mesure du cycle de vie du processus, le système devra lui valider ces pages réellement en mémoire, afin que celles ci ne soient pas potentiellement réutilisables par d’autres processus, ces pages lui sont définitivement attribuées en fonction de la RAM disponible (principe de “commited” memory).

Cependant, comment cela se passe si ce même processus demande trop de mémoire et que l’on arrive à une saturation RAM ? il y’a alors des conséquences pour votre système Linux. L’OS va devoir procéder à ce que l’on appelle du “over-commit” !

Mais il faut bien garder à l’esprit que cela est un mécanisme qui reste dans le cadre de l’exceptionnel, et lorsque le processus demande trop de ressources, l’OS ne pourra, à un moment, plus y répondre.
C’est la qu’intervient le process système “Out-of-memory Killer” ou “OOM-Killer”.

Le kernel linux doit tout faire pour éviter un “kernel panic” et par conséquence un “crash” du système global et un reboot du serveur. Ainsi il va se défendre grâce à ce “garde-fou” qui lui permettra de conserver la stabilité du système et surtout supprimer le processus qui demande trop de ressources mémoire.

La configuration de ce processus se fera dans “sysctl” en configurant les paramètres suivants :

vm.overcommit_memory
vm.overcommit_ratio

 

Les valeurs possibles pour le paramètre “vm.overcommit_memory” sont :

0 – Le système va tenter d’effectuer de l’over-commit selon un algorithme défini et en fonction des ressources (valeur par défaut)
1 – le système va effectuer de l’over-commit dans tous les cas, sans vérification (à vos risques et périls !)
2 – Pas d’over-commit, seule la mémoire réellement allouable sera utilisée selon un ratio défini.

Si la valeur 2 est choisie pour “vm.overcommit_memory” alors le paramètre “vm.overcommit_ratio” rentre en jeu.

Ce dernier paramètre renseigne sur quel pourcentage de mémoire l’OS va pouvoir utiliser au maximum pour un processus. Par défaut, la valeur est fixé à 50%.
Mais il sera possible de l’augmenter .

Gardons à l’esprit que Linux utilisera cette formule pour savoir combien de mémoire il pourra au plus allouer :

Limite allocation mémoire = Swap + RAM * (Overcommit Ratio / 100)

 

Il est possible de complètement désactiver OOM-Killer, même si cela n’est pas vraiment recommandé.

sysctl -w vm.oom-kill=0 
ou bien directement dans le fichier /etc/sysctl.conf : echo "vm.oom-kill=0" >> /etc/sysctl.conf

Par défaut, lorsque “OOM-Killer” se déclenche, nous n’avons pas de kernel panic, c’est ce qui est attendu afin de protéger l’OS et les autres processus actifs du serveur.
Pour s’en assurer, nous interrogerons le paramètre “panic_on_oom” et vérifions que la valeur est à 0 :

[root@VM_client]# cat /proc/sys/vm/panic_on_oom
0

La valeur est bien à 0. Si tel n’était pas le cas, nous devrions la modifier :

sysctl -w vm.panic_on_oom=0 
ou bien directement dans le fichier /etc/sysctl.conf : echo "vm.panic_on_oom=0" >> /etc/sysctl.conf

Cas d’un processus traité par “OOM-Killer”

 

S’il l’on revient à notre cas survenu chez notre client, nous avons l’exemple même du comportement lié à OOM-Killer.
Un matin, notre supervision nous a alerté d’une indisponibilité de la base PostgreSQL survenue en pleine nuit chez notre client. Le message d’erreur était le suivant :

2020-12-24 03:08:32.650 UTC [20332] LOG:  server process (PID 9725) was terminated by signal 9: Killed
2020-12-24 03:08:32.650 UTC [20332] DETAIL:  Failed process was running: select result.fn_agreg_rumresultdaily();
2020-12-24 03:08:32.650 UTC [20332] LOG:  terminating any other active server processes
2020-12-24 03:08:32.650 UTC [12164] WARNING:  terminating connection because of crash of another server process
2020-12-24 03:08:32.650 UTC [12164] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-12-24 03:08:32.650 UTC [12164] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-12-24 03:08:32.651 UTC [12288] WARNING:  terminating connection because of crash of another server process
2020-12-24 03:08:32.651 UTC [12288] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-12-24 03:08:32.651 UTC [12288] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-12-24 03:08:32.655 UTC [12287] WARNING:  terminating connection because of crash of another server process
2020-12-24 03:08:32.655 UTC [12287] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-12-24 03:08:32.655 UTC [12287] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-12-24 03:08:32.657 UTC [12286] WARNING:  terminating connection because of crash of another server process
2020-12-24 03:08:32.657 UTC [12286] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-12-24 03:08:32.657 UTC [12286] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-12-24 03:08:32.661 UTC [12291] WARNING:  terminating connection because of crash of another server process
2020-12-24 03:08:32.661 UTC [12291] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-12-24 03:08:32.661 UTC [12291] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-12-24 03:08:32.661 UTC [12162] WARNING:  terminating connection because of crash of another server process
2020-12-24 03:08:32.661 UTC [12162] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-12-24 03:08:32.661 UTC [12162] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-12-24 03:08:32.664 UTC [12285] WARNING:  terminating connection because of crash of another server process
.....
2020-12-24 03:08:32.752 UTC [10939] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-12-24 03:08:32.823 UTC [20332] LOG:  all server processes terminated; reinitializing
2020-12-24 03:08:33.161 UTC [12295] LOG:  database system was interrupted; last known up at 2020-12-24 03:05:33 UTC
2020-12-24 03:08:33.162 UTC [12297] FATAL:  the database system is in recovery mode
2020-12-24 03:08:33.162 UTC [12296] FATAL:  the database system is in recovery mode
2020-12-24 03:08:33.164 UTC [12298] FATAL:  the database system is in recovery mode
2020-12-24 03:08:33.245 UTC [12352] FATAL:  the database system is in recovery mode
2020-12-24 03:08:33.245 UTC [12350] FATAL:  the database system is in recovery mode
2020-12-24 03:08:33.246 UTC [12353] FATAL:  the database system is in recovery mode
2020-12-24 03:08:33.246 UTC [12354] FATAL:  the database system is in recovery mode
2020-12-24 03:08:33.249 UTC [12355] FATAL:  the database system is in recovery mode
2020-12-24 03:08:33.250 UTC [12356] FATAL:  the database system is in recovery mode
2020-12-24 03:08:33.877 UTC [12295] LOG:  database system was not properly shut down; automatic recovery in progress
2020-12-24 03:08:33.883 UTC [12295] LOG:  redo starts at 219E/595E1A0
2020-12-24 03:08:36.936 UTC [12360] FATAL:  the database system is in recovery mode
2020-12-24 03:08:37.355 UTC [12361] FATAL:  the database system is in recovery mode
2020-12-24 03:08:38.184 UTC [12363] FATAL:  the database system is in recovery mode
2020-12-24 03:08:41.792 UTC [12366] FATAL:  the database system is in recovery mode
2020-12-24 03:08:44.189 UTC [12369] FATAL:  the database system is in recovery mode
2020-12-24 03:08:44.191 UTC [12370] FATAL:  the database system is in recovery mode
2020-12-24 03:08:46.792 UTC [12373] FATAL:  the database system is in recovery mode
2020-12-24 03:08:51.751 UTC [12295] LOG:  invalid record length at 219E/6D68EE68: wanted 24, got 0
2020-12-24 03:08:51.751 UTC [12295] LOG:  redo done at 219E/6D68EE40
2020-12-24 03:08:51.751 UTC [12295] LOG:  last completed transaction was at log time 2020-12-24 03:08:32.212985+00
2020-12-24 03:08:51.757 UTC [12295] LOG:  checkpoint starting: end-of-recovery immediate
2020-12-24 03:08:51.795 UTC [12378] FATAL:  the database system is in recovery mode
2020-12-24 03:08:56.195 UTC [12383] FATAL:  the database system is in recovery mode
2020-12-24 03:08:56.196 UTC [12384] FATAL:  the database system is in recovery mode
2020-12-24 03:08:56.796 UTC [12385] FATAL:  the database system is in recovery mode
2020-12-24 03:08:58.621 UTC [12295] LOG:  checkpoint complete: wrote 120927 buffers (46.1%); 0 WAL file(s) added, 0 removed, 104 recycled; write=6.753 s, sync=0.022 s, total=6.865 s; sync files=62, longest=0.022 s, average=0.000 s; distance=1701059 kB, estimate=1701059 kB
2020-12-24 03:08:58.675 UTC [20332] LOG:  database system is ready to accept connections


Comme on peut le voir, un “kill -9” a été effectué sur le process 9725. Aussitôt le “postmaster” PostgreSQL a ordonné une opération “Rollback” sur la base afin d’assurer l’intégrité des données sur celle ci. Durant ce temps, la base n’était pas disponible (FATAL: the database system is in recovery mode).

Nous avons pu remonter les informations dans les traces systèmes avec “sar” mais également dans le “/var/log/messages” :

Dec 24 03:08:31 VM-client kernel: [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name
Dec 24 03:08:31 VM-client kernel: [ 7801] 26 7801 609660 5736 134 0 0 postmaster
Dec 24 03:08:31 VM-client kernel: [ 9725] 26 9725 1692322 1571644 3200 0 0 postmaster
Dec 24 03:08:31 VM-client kernel: [11225] 26 11225 612080 19332 341 0 0 postmaster
Dec 24 03:08:31 VM-client kernel: [11261] 0 11261 30815 58 17 0 0 anacron
Dec 24 03:08:31 VM-client kernel: [11447] 26 11447 611520 18491 325 0 0 postmaster
...
Dec 24 03:08:31 VM-client kernel: Out of memory: Kill process 9725 (postmaster) score 786 or sacrifice child
Dec 24 03:08:31 VM-client kernel: Killed process 9725 (postmaster) total-vm:6769288kB, anon-rss:4323864kB, file-rss:0kB, shmem-rss:1962700kB
Dec 24 03:10:02 VM-client systemd: Created slice User Slice of postgres.

 

Le process 9725 avait presque 1,7M de pages réservées, mais celui ci a été killé car il dépassait 6,5Go en mémoire.
Le serveur de notre client ne disposant que de 8Go de RAM, et surtout , pas de swap affecté au système.

Le log étant assez explicite, nous savons maintenant que c’est la commande SQL “select result.fn_agreg_rumresultdaily()” qui a provoqué cette surconsommation mémoire.

 

Les bonnes pratiques avec PostgreSQL

 

Comme nous le savons, un serveur de bases de données ne devrait pas swapper, c’est vrai dans la plupart des SGBDR. Cependant, les autres processus du système ou présents sur le serveurs peuvent disposer d’un espace de swap afin de consommer d’avantage de mémoire à un instant donné.
Nous avons donc demandé à notre client de créer cet espace SWAP sur le système, 4 Go pour le moment seront affectés.

Il est aussi de bonne pratique, pour un serveur base de données, d’utiliser des pages larges (huges pages) afin de disposer de pages mémoire les moins fractionnées possible. Cette configuration se fera via “sysctl” en définissant  les paramètres “vm.nr_hugepages”.
Par défaut, ce seront des pages de 2Mo que l’on pourra allouer.

Pour un serveur disposant de 8Go de RAM, on place les pages liés au paramètre “shared_buffers”, soit 2Go. Par conséquence, ce sera la commande :

sysctl -w vm.nr_hugepages=1024
ou bien : echo "vm.nr_hugepages=1024" >> /etc/sysctl.conf

 

Enfin l’autre solution si l’on ne met pas en place les “huges pages”, et ce en accord avec la documentation PostgreSQL, c’est de gérer manuellement  le over-commit sur le serveur en capant le ratio d’utilisation de la RAM pour un processus donné.

Comme le mentionne la documentation PostgreSQL sur le site ,  il est recommandé de passer le paramètre vm.overcommit_memory à 2 :

sysctl -w vm.overcommit_memory=2
ou bien directement dans le fichier /etc/sysctl.conf : echo "vm.overcommit_memory=2" >> /etc/sysctl.conf

Il restera alors à changer le ratio de mémoire utilisable au maximum. On pourra définir celui ci à 75% par exemple.

sysctl -w vm.overcommit_ratio=75
ou bien directement dans le fichier /etc/sysctl.conf : echo "vm.overcommit_ratio=75" >> /etc/sysctl.conf

 

S’il l’on reprend la formule Linux pour la limite d’affectation de processus, nous aurons donc :

Limite = 4096 + 8192 (75/100) – > soit une limite à 10Go. Le process peut utiliser jusqu’à 10Go en mémoire.

 

Depuis ces modifications, nous n’avons plus rencontré ce souci avec “OOM-Killer”, le batch de nuit lié à “pg_partman” se déroule correctement.

 

N’hésitez pas à laisser des commentaires.

@+

 

Emmanuel RAMI

 

Continuez votre lecture sur le blog :

twitterlinkedinmail

Emmanuel RAMI

Laisser un commentaire

Votre adresse e-mail ne sera pas publiée.

Ce site utilise Akismet pour réduire les indésirables. En savoir plus sur comment les données de vos commentaires sont utilisées.