- Sur une application Rails en production vieille de 10 ans, la mémoire des dynos
web a brutalement augmenté pendant un déploiement. Le service encaissait une charge continue de 400 à 500 req/s, avec des pics à plusieurs milliers de req/s, ce qui imposait une atténuation rapide.
- Sur Heroku, les dynos proches de la limite mémoire ont été redémarrés et les changements de code et de métriques des 3 derniers jours ont été annulés, mais la fuite mémoire persistait.
- Alors que Sidekiq et Delayed::Job semblaient normaux, seul un sous-ensemble des workers Puma grossissait, ce qui faisait soupçonner un lien avec un type de trafic particulier.
- Le suivi du heap avec
rbtrace, ObjectSpace, heapy, sheap et reap a montré qu’un thread de traitement de requêtes Puma retenait 32 067 objets et 1.9GiB de mémoire via le tableau @children de ActiveSupport::Notifications::Event.
- Des paramètres de requête manipulés déclenchaient un
URI::InvalidURIError pendant le nettoyage d’URL de Bugsnag ; la réponse à court terme a été une mise à niveau de Bugsnag, et la réponse de fond une mise à niveau de Rails.
Une fuite apparaît sur une application Rails en production
- La cible était une application Rails vieille de 10 ans, un service de production générant un vrai chiffre d’affaires.
- La charge soutenue habituelle était de 400 à 500 req/s, avec des pics à plusieurs milliers de requêtes par seconde.
- Lors d’un déploiement classique, un pic de mémoire a commencé et a déclenché une alerte pager.
- L’application tournait sur Heroku, donc l’état était observé à partir des métriques mémoire par dyno.
L’atténuation de l’incident commence par le redémarrage des dynos
- Le phénomène ressemblait non pas à un simple gonflement mémoire (bloat), mais à une fuite, et la solution temporaire consistait à redémarrer les processus.
- Les nombreux déploiements quotidiens redémarraient normalement les instances
web, mais les dynos approchant de la limite mémoire ont été redémarrés manuellement.
La fuite persiste même après annulation des changements suspects
- Un audit des 3 jours de changements de code a été mené en remontant jusqu’avant le premier gros pic.
- Trois changements semblaient potentiellement liés :
- un changement provoquant une fuite mémoire à cause du rechargement du code Rails en mode
development
- un changement augmentant plus que prévu les appels Redis pendant un filtrage de certaines requêtes
- un changement de type N+1 entraînant davantage d’appels à la base de données et le chargement d’instances
ActiveRecord
- Les deux premiers changements ont été corrigés, le troisième annulé, puis redéployés un par un, mais la fuite a continué.
- Les changements d’outillage destinés à collecter des métriques Ruby et des métriques d’utilisation du pool Puma ont aussi été annulés, sans stopper la hausse mémoire.
Le motif de fuite pointe vers un trafic spécifique
- La fuite ne se produisait que sur les dynos
web ; les dynos Sidekiq et Delayed::Job semblaient normaux.
- Tous les dynos
web ne fuyaient pas en permanence.
- Pendant plusieurs heures, leur consommation mémoire restait relativement plate, comme celle d’un processus web de longue durée.
- Puis, à un moment donné, un, plusieurs, ou tous les dynos commençaient à fuir.
- Puma tournait en mode cluster, avec 12 worker process par dyno pour 8 vCPU.
- Même à l’intérieur d’un dyno, seuls certains des 12 workers consommaient parfois presque toute la mémoire.
- Les traces OpenTelemetry étaient fortement échantillonnées, ce qui rendait difficile l’association entre un type de requête précis et un dyno précis ; la corrélation avec les logs non échantillonnés n’était pas simple non plus avec les outils disponibles.
Procédure de collecte des heap dumps
rbtrace a été utilisé pour s’attacher à un processus Ruby en cours d’exécution.- Comme
rbtrace doit être chargé dans le processus, il a été ajouté au Gemfile, avec activation contrôlée par variable d’environnement.
gem "rbtrace", require: String(ENV.fetch("FEATURE_ENABLE_MEMORY_DUMPS", false)) == "true"
- Sur Heroku, un tunnel SSH a été ouvert vers le dyno en fuite avec
heroku ps:exec, puis ps a servi à trier les processus Ruby par RSS.
ps -eo pid,ppid,comm,rss,vsz --sort -rss | grep ruby
- Sur les dynos
web, les processus partageant le même PPID étaient les workers Puma, et le PID du worker consommant le plus de mémoire a été ciblé.
- Le suivi des allocations mémoire a été activé avec
ObjectSpace.trace_object_allocations_start, ce qui peut avoir un impact sur les performances, la mémoire et le CPU.
DUMP_PID=<pid>
rbtrace --pid="${DUMP_PID}" --eval="Thread.new{require 'objspace';ObjectSpace.trace_object_allocations_start}.join"
- Les heap dumps ont été générés dans
/tmp avec ObjectSpace.dump_all, et sur un processus en fuite actif depuis plusieurs heures, le fichier JSON pouvait atteindre 5 à 6GiB.
rbtrace --pid="${DUMP_PID}" --eval="Thread.new{require 'objspace'; GC.start(); io=File.open('/tmp/heap-${DUMP_PID}.json', 'w'); ObjectSpace.dump_all(output: io); io.close}.join" --timeout=600
gzip "/tmp/heap-${DUMP_PID}.json"
- Sur Heroku, le dump a été récupéré en local avec
heroku ps:copy, et il fallait collecter au moins trois dumps pour observer la retained memory avec heapy.
- Une fois le travail terminé, le suivi des allocations était désactivé et les dumps supprimés, ou bien le dyno redémarré.
L’analyse du heap révèle un thread retenant 1.9GiB
- Les rapports de retained memory de
heapy et les diffs de sheap ne suffisaient pas à identifier facilement le point de départ.
- Un flame graph a été généré avec
reap, qui analyse et visualise le graphe de références d’un heap dump Ruby.
- Le flame graph montre, depuis les racines du point de vue du GC Ruby, les références vers les objets en dessous ; plus un objet retient de mémoire, plus sa cellule est large.
- Dans le troisième heap dump, un
Thread retenait 1.9GiB de mémoire.
- En réalité, c’était un
Array plus bas dans la chaîne qui référençait 32 067 objets et maintenait 1.9GiB.
Remonter le chemin de référence avec sheap
- La dernière branche
main de sheap a été utilisée pour comparer les deuxième et troisième dumps.
- Comme les dumps approchaient 6GiB, le parsing prenait du temps.
- Le résultat de
find_path a montré que le Thread problématique n’était pas un thread d’arrière-plan de télémétrie ou de métriques, mais un thread Puma traitant des requêtes.
ActiveSupport::SubscriberQueueRegistry fonctionne dans Rails 6.1 comme un Hash par thread stockant les listes de ActiveSupport::Subscriber par nom d’événement.- Ce registre référençait un
Hash, et l’un des Array qu’il contenait retenait des ActiveSupport::Notifications::Event.
- Cet
Event référençait à son tour plus de 32 067 objets Event enfants via son tableau @children.
- Le nom du premier
Event enfant était redirect_to.action_controller, et il contenait un objet ActionDispatch::Request.
Une requête anormale fournit l’indice de reproduction
- Le
ActionDispatch::Request trouvé dans le heap contenait une vraie route et un identifiant valide de ressource publique, mais les paramètres de requête avaient été manipulés.
- Le chemin de requête contenait
password=[FILTERED], signe qu’un nettoyage des données sensibles intervenait.
- En rejouant la même route et les mêmes paramètres sur l’application de production depuis une fenêtre privée du navigateur, une 500 server error s’est produite.
- Les logs montraient un
URI::InvalidURIError, et il a aussi été possible d’identifier le dyno ayant reçu la requête.
- Ce dyno affichait alors une consommation mémoire normale, mais après avoir brièvement suspendu les déploiements et observé, une tendance de fuite est apparue.
- En local, du débogage
binding.pry et puts a été ajouté au gem activesupport pour reproduire la même situation et la backtrace.
La vraie cause était la combinaison d’un changement Rails et d’un changement Bugsnag
- La backtrace de l’erreur pointait vers le gem
uri de la bibliothèque standard Ruby, utilisé par Bugsnag.cleaner.clean_url.
- Ce code se trouvait dans un bloc
ActiveSupport::Notifications.subscribe, lors du nettoyage de l’URL des breadcrumbs Rails.
- Le problème venait de la combinaison de deux éléments :
- dans Rails 6.1,
ActiveSupport::Subscriber suit les événements via Event#children et un Array partagé
- un changement dans Bugsnag utilisait
URI pour nettoyer les URL des breadcrumbs Rails, ce qui pouvait lever une exception sur une URI invalide
- Quand
URI levait une erreur sur une URI invalide, le bloc subscribe de Bugsnag déclenchait une exception pendant le traitement de ActiveSupport::Notifications::Event.
- À cause de cette exception, le
Event parent n’était pas retiré de Subscriber#event_stack, restait en mémoire et provoquait la fuite.
- Ce
Event parent continuait de référencer les Event enfants via le tableau #children, retenant ainsi toujours plus de mémoire.
- Le correctif de Rails 7.1 par John Hawthorn supprime à la fois le concept de
Event#children et le Array partagé servant au suivi des événements, éliminant ainsi les deux causes de fuite.
La solution : mise à niveau de Bugsnag puis de Rails
- Dans les versions récentes de Rails, ce problème ne se produit plus grâce au correctif de John Hawthorn.
- À ce moment-là, l’application tournait sur Rails 6.1 et ne pouvait donc pas bénéficier immédiatement du correctif Rails.
- Bugsnag avait déjà corrigé le fait que
Bugsnag.cleaner.clean_url ne lève plus d’exception sur une URI invalide.
- La solution à court terme a donc été de mettre à niveau vers la version du gem Bugsnag contenant ce correctif.
- La solution de long terme a été de mettre à niveau la version de Rails.
- Le changement coïncidant avec le premier pic mémoire était la mise à niveau de Bugsnag de
v6.26.0 à v6.26.1, effectuée pour corriger un avertissement de dépréciation dans une autre dépendance.
1 commentaires
Avis de Hacker News
Je ne comprends pas pourquoi la gestion manuelle de la mémoire fait si peur. Avec RAII et des règles de propriété claires, la gestion mémoire est une tâche d’ingénierie facile.
À l’inverse, les frameworks qui imposent le comptage de références ou les pointeurs partagés me semblent plus difficiles, parce que la propriété devient floue.
Si vous l’avez créé vous-même, vous le libérez vous-même ; si vous l’avez transmis, vous ne vous en souciez plus. On gère déjà manuellement les ressources de l’OS comme les handles et les sockets, sans gestionnaire automatique de ressources ; je ne vois donc pas pourquoi il faudrait compliquer la conception avec une gestion automatique de la mémoire.
Après des années de développement, j’en suis venu à penser que la plupart des développeurs n’ont pas assez de marge en mémoire de travail pour raisonner en même temps sur la gestion mémoire. Même si l’on connaît mécaniquement la méthode, quand on jongle avec trop de choses dans sa tête, on en laisse tomber.
À l’inverse, il existe une minorité de personnes qui réussissent presque sans effort la gestion manuelle de la mémoire à chaque fois. Pour elles, c’est effectivement facile, et elles ont donc du mal à comprendre pourquoi c’est difficile pour les autres. Pour ce type de personne, la gestion automatique de la mémoire peut avoir des avantages peu évidents et des inconvénients qui paraissent énormes.
En gros, ces bugs n’ont pas été remplacés par d’autres : ils ont simplement disparu. Cela ne demande pas plus de travail aux programmeurs ; au contraire, cela réduit ce qu’ils ont à faire par rapport à la gestion manuelle de la mémoire.
Bien sûr, le garbage collection ne gagne pas à tous les coups et a de vrais inconvénients. Mais pour la plupart des programmes, un garbage collector moderne est suffisamment bon pour que ces inconvénients ne posent pas vraiment problème.
Les bugs logiques posent un problème similaire, et même dans des langages comme Java il peut rarement y avoir des fuites mémoire, mais les langages à sûreté mémoire sont une amélioration. C’est comparable à TypeScript par rapport à JavaScript. S’il existe une automatisation capable de faire passer les erreurs mémoire de 1 % à 0,01 %, je ne vois pas pourquoi la prévention des fuites et des comportements indéfinis devrait rester une préoccupation manuelle.
On peut utiliser un langage à garbage collection facile mais avec overhead, comme Java, ou un langage imposant la propriété, avec une courbe d’apprentissage mais sans overhead, comme Rust. Les bugs logiques sont eux aussi pénibles, mais les bugs mémoire sont particulièrement tristement célèbres parce qu’ils ne donnent pas forcément de message d’erreur clair, ou parce que le programme ne s’arrête pas même lorsqu’ils se produisent.
À côté de cela, la vérification formelle est aussi une façon d’éliminer pratiquement toute une catégorie de bugs. Aujourd’hui, on la voit surtout dans les systèmes où l’exactitude est primordiale, car contrairement à la gestion mémoire, ses inconvénients sont trop importants. Le code devient extrêmement verbeux et exigeant, et impose certaines structures. Mais si la vérification formelle s’améliore, je pense qu’elle deviendra elle aussi plus mainstream.
« Je ne suis pas un vrai programmeur. Je colle des trucs ensemble jusqu’à ce que ça marche et je passe à autre chose. Les vrais programmeurs diraient : “Ça fonctionne, mais il y a des fuites mémoire partout. On ne devrait pas corriger ça ?” Moi, je redémarrerais simplement Apache toutes les 10 requêtes. » — Rasmus Lerdorf, PHP Non-Designer
https://en.wikiquote.org/wiki/Rasmus_Lerdorf
Mon ancien lieu de travail aurait mérité le prix de la façon la plus stupide de perdre 5 millions de dollars à cause d’une fuite mémoire.
Dans les années 90, le pilote d’imprimante de Solaris avait une fuite mémoire[1]. Je travaillais alors comme prestataire pour une grande banque, et à l’époque, le statut juridique des fax dans la confirmation des contrats n’avait pas encore été suffisamment éprouvé devant les tribunaux ; les banques consignaient donc les transactions par fax. Le système qui envoyait les fax envoyait aussi le document à une imprimante donnée pour imprimer une confirmation de transaction, et quelqu’un prenait cette confirmation pour la lire par téléphone à la contrepartie, afin qu’elle figure dans l’enregistrement de l’appel[2] et soit juridiquement confirmée.
Un jour, à cause de la fuite mémoire, le pilote d’imprimante a planté et une confirmation n’a pas été imprimée ; la personne responsable n’a donc pas pu la lire au téléphone. Le marché a fortement bougé et la contrepartie a traité cette transaction en DK[3]. Les dirigeants de la banque ont eu beau faire tout le vacarme possible, cela n’a servi à rien : ils ont inscrit une perte de 5 millions de dollars dans les comptes, puis ont instauré une politique consistant à ne plus jamais traiter avec cette banque[4]. Le travail d’impression des fax a été déplacé vers Windows NT.
[1] D’après l’excellent livre « Expert C Programming », Scott McNealy, alors CEO de Sun Microsystems, recevait malgré son poste de CEO des workstations peu performantes et rencontrait souvent ce problème ; après s’en être suffisamment plaint, les développeurs ont fini par le corriger https://progforperf.github.io/Expert_C_Programming.pdf
[2] Les appels de la division titres d’une banque sont presque toujours enregistrés pour des raisons juridiques et de conformité.
[3] DK signifie « Don’t know ». Quand la contrepartie dit qu’elle « ne connaît pas » la transaction, elle conteste le fait que le contrat ait été conclu.
[4] La contrepartie pouvait traiter ailleurs et verser des commissions à une autre banque, donc c’est probablement nous qui y avons perdu le plus.
Citi a aussi été poursuivie pour avoir remboursé un prêt trop tôt. Dans la finance, je pense que n’importe qui s’appuiera vigoureusement sur un contrat écrit si cela l’avantage.
En C, trouver les fuites est très facile grâce à Valgrind
Les corriger est plus difficile, mais si la conception est bonne, c’est généralement simple. En général, sauf s’il s’agit d’une fonction qui alloue pour le compte de l’appelant, on alloue et on libère dans la même fonction. Si c’est une fonction qui alloue pour l’appelant, on considère cet appel lui-même comme une allocation côté appelant
Lors d’une analyse statique de la base de code, les chemins de gestion des erreurs se sont révélés être la cause la plus fréquente du problème
De même qu’il existe une portée de bloc, de fonction, de fichier et globale, il existe aussi plusieurs niveaux de portée dans les modèles qui abstraient le domaine du problème ou de la solution. Je n’ai toutefois jamais vu cela enseigné
Quand une portée acquiert une ressource dans
$SCOPE::foo()et ne la libère pas dans$SCOPE::cleanup(), c’est assez facile à repérer visuellement. La capacité à modéliser le domaine du problème et la solution proposée avant de se lancer dans le code est utileCela me rappelle une histoire que j’ai entendue à propos de Yahoo. Leur serveur publicitaire avait une fuite mémoire et tombait en gros en mémoire insuffisante après environ 10 000 requêtes
La solution consistait à redémarrer le serveur après 8 000 requêtes. Cette approche a fonctionné un an ou deux, puis il a commencé à tomber en mémoire insuffisante même après 8 000 requêtes
La solution suivante a été de redémarrer le serveur après 6 000 requêtes
Pour que cette méthode fonctionne, le redémarrage devait être incroyablement rapide
Quand j’étais développeur Rails, ajouter davantage de matériel pour ce genre de problème passait pour un compromis acceptable en faveur de la productivité. L’état d’esprit était que, si l’on se souciait de ce type de problème, il suffisait d’utiliser des outils plus stricts
Personnellement, mon côté perfectionniste rend cette approche difficile à accepter, mais il est difficile de nier qu’elle fonctionne réellement
J’ai utilisé à la fois des langages avec ramasse-miettes et sans. En général, la gestion manuelle est plus difficile à écrire, et la gestion automatique rend les problèmes plus difficiles à résoudre
J’aimerais utiliser un langage qui permette les deux. Quand on écrit du code exploratoire, la gestion automatique de la mémoire est pratique, et pour certains types de code, la gestion manuelle de la mémoire est avantageuse
C’est frustrant de ne pas trouver de juste milieu entre interdiction et obligation
@[manualfree], et pour tout le projet avecv -gc nonehttps://vlang.io
« De nombreux articles ont été écrits sur les différents outils pour profiler les fuites, comprendre les dumps de tas et les causes courantes de fuites »
Beurk, des fuites et des dumps de tas. On dirait que quelqu’un aurait besoin d’un régime alimentaire plus sain