Less is more : J'ai eu beaucoup de crash mémoire sur mon application
RssFeedPulse est en production depuis mi-mai. Tout se passait bien et puis, d'un coup, il y a 2 semaines j'ai commencé à avoir des problèmes de crash de l'application.
Ça, c'est l'email que je recevais. Plusieurs fois par jour, j'avais un email m'indiquant le redémarrage de l'application par mon hébergeur PAAS.
Sauf que moi, il y a 2 semaines, je n'ai pas fait grand-chose. Alors, que s'est-il passé ?
Les logs
La première chose qu'on regarde quand une application s'arrête, ce sont les logs. Qu'est-ce que faisait mon application avant de crasher, et est-ce qu'il y a des erreurs visibles ?
Eh bien, mauvaise surprise, rien du tout. L'application ne faisait rien. Les logs sont quasi vides. Il n'y a jamais de corrélation entre un log et un redémarrage.
D'ailleurs, on ne peut pas vraiment parler de crash. L'application était redémarrée, mais sans aucune erreur constatée de mon côté.
L'API RssFeedPulse est loin d'être surchargée. Il y a peu de clients, donc peu de traitements.
Bref, pas de logs pour comprendre...
Par contre, Clever Cloud propose de visualiser des métriques sur Grafana et on y voit ça :
Une mémoire trop haute ?!
84% de mémoire utilisée ?! C'est juste pas normal. Et éventuellement, ça peut expliquer des redémarrages.
Beaucoup de PAAS regardent les ressources utilisées par une application et redémarrent l'application si celle-ci en utilise trop.
Donc mon hypothèse était simple. Je consomme trop de mémoire, et à partir d'un moment, Clever Cloud décide que c'est plus possible.
Sauf que, le support m'a indiqué que ce n'était pas le cas :
Le monitoring regarde si l'application accepte les connexions sur le port 8080. Quand ça n'est pas le cas, cela veut dire que l'application ne répond pas du tout.
Malgré tout, j'ai souhaité continuer sur cette piste. Parce que j'ai 1Go de ram sur cette machine. Et vu ce qu'elle fait, ce n'est pas possible d'utiliser 84% de cette RAM.
Quand je vois une anomalie comme ça, j'aime bien comprendre. Parfois ça peut être la manifestation d'un effet secondaire d'un problème plus grave, ou inversement, ça peut créer des effets de bord insoupçonnés (comme les redémarrages).
Mais à ce stade, je ne vois aucun souci venant de l'application elle-même.
Et une autre info donnée par clever cloud me semblait aller dans ce sens-là :
La heap utilisée ne serait "que" de 60Mo. C'est pas surprenant vu l'application actuelle et surtout, très loin d'occuper 84% de la mémoire de la machine.
Le modèle mémoire de Java
Je ne vais pas entrer dans le détail, mais c'est important de comprendre un minimum comment fonctionne une JVM.
Java est souvent décrié pour sa très grosse consommation mémoire (et son temps de démarrage, mais c'est pas le sujet ici).
Et il faut bien avouer qu'on fait rapidement des conneries avec une JVM.
Quand on lance une application Java, celle-ci s'exécute au sein d'une JVM qui interprète un fichier de code semi-compilé (le byte code) pour le compiler à la volée en langage machine.
Une JVM demande une quantité de mémoire au démarrage.
Une partie de cette mémoire s'appelle la Heap (le tas). Elle sert à stocker toutes les allocations dynamiques de votre application. Vous créez une variable, hop, ca part dans la Heap. Et la mémoire est libérée automatiquement quand la variable n'est plus utilisée.
Pour des raisons de performances, la JVM prend une quantité de mémoire au système dès le démarrage même si elle ne l'utilise pas. Parce que sinon ça coûterait trop cher de constamment allouer et rendre de la mémoire au système.
Donc il est possible que la JVM prenne 1Go de mémoire sur une machine, quand bien même la Heap utilisée n'est "que" de 50Mo.
C'est un peu contre productif et c'est pourquoi on peut paramétrer la taille minimale et maximale de la Heap avec les options -Xmx et -Xms.
Une solution aurait été de prendre une machine plus puissante sur Clever Cloud. Mais ce serait quand même assez ridicule (et cher) de prendre 2Go de ram pour une application qui consomme sans doute moins de 100Mo la majorité du temps.
Et je sais par expérience que bien souvent, pour résoudre des problèmes de sur-consommation en Java, il vaut mieux baisser la Heap plutôt que de l'augmenter.
(Oui, parce que c'est non plus très efficace d'avoir une Heap très large dans laquelle il faut constamment faire des opérations d'allocation, désallocation, inspection etc...)
Bref, et si je diminuais la taille de cette JVM ?
Il faut appeler un ami
Mon premier réflexe a été de surcharger des variables d'environnement sur Clever Cloud pour diminuer la Heap utilisée.
J'ai donc utilisé l'option -Xmx pour n'utiliser "que" 512Mo de Heap.
Et pourtant...
On peut pas dire que le résultat ait été convaincant. J'ai donc fait appel au support Clever Cloud pour comprendre.
Le support Clever Cloud fait partie des bons points de ce provider. J'ai d'autres réserves sur le PAAS en lui-même mais un bon support est un atout appréciable.
Ça a été réactif (réponse rapide), proactif (la personne a pris l'initiative de tester des choses sans que je le demande) et, à priori, efficace.
Deux éléments ont été mis en évidence :
- l'option que j'utilisais pour modifier le Xmx ne fonctionnait pas et il fallait utiliser une autre option sur Clever Cloud
- mon script de lancement de l'application n'était pas bon...
Oui alors, tout à l'heure je vous ai dit que je ne soupçonnais pas du tout mon application.
Je me trompais un peu. C'est vrai que l'application en elle-même ne semble pas contenir de problème. Par contre j'utilisais cette commande pour la démarrer :
mvn spring-boot:run -Pnative -Dspring-boot.run.profiles=native
Et ça, c'est co....
Lancer une application avec maven, c'est pas du tout optimal. C'est fait pour le dev. Ça a l'énorme avantage de surveiller le code source pour repérer les modifications et les recharger à la volée et il y a donc tout une machinerie supplémentaire, qui créé un overhead, qui n'a aucune utilité en production.
Les deux remarques ont été prises en compte. Et désormais :
Mais surtout, aucun redémarrage intempestif depuis cette modification.
Des questions en suspens
Tout est bien qui finit bien ?
Partiellement, oui.
- L'application consomme moins. J'aurais même pu descendre à 384Mo vu la conso réelle.
- plus de redémarrages
Il y a quand même des questions qui ne sont pas résolues.
- Pourquoi est-ce que je n'ai aucun log avant les redémarrages ?
- Pourquoi est-ce que ça a démarré il y a 2 semaines ?
- Pourquoi est-ce que la charge de la machine et la consommation CPU augmentaient avant les "crashs" ?
Ok, la JVM prenait 84% de la RAM de la machine. Mais... Et alors ?
Est-ce que ce serait lié à des opérations internes de la JVM qui tentait à ce moment-là d'inspecter la HEAP, de faire des allocations mémoire ou que sais-je encore ?
Ça reste mon hypothèse principale, mais je n'en ai pas la certitude.
Toujours est-il que je suis de nouveau serein sur RssFeedPulse. Et c'est quand même agréable.
