Peut-être que chaque programmeur connaît les mots de Kent Beck: "Faites-le fonctionner, faites-le bien, faites-le vite." Vous devez d'abord faire fonctionner le programme, puis vous devez le faire fonctionner correctement, et seulement ensuite vous pouvez procéder à l'optimisation.
L'auteur de l'article, dont nous publions la traduction, dit qu'il a récemment décidé de reprendre le profilage de son projet open-source
Flipt . Il voulait trouver dans le projet du code qui pourrait être optimisé sans effort et accélérer ainsi le programme. Lors du profilage, il a découvert des problèmes inattendus dans un projet open source populaire utilisé par Flipt pour organiser le routage et la prise en charge du middleware. En conséquence, il a été possible de réduire de 100 fois la quantité de mémoire allouée par l'application pendant le fonctionnement. Ceci, à son tour, a entraîné une réduction du nombre d'opérations de collecte des ordures et amélioré la performance globale du projet. Voici comment c'était.
Génération de trafic élevé
Avant de pouvoir commencer le profilage, je savais que je devais d'abord générer une grande quantité de trafic entrant dans l'application, ce qui m'aiderait à voir certains modèles de son comportement. Ici, j'ai immédiatement rencontré un problème, car je n'ai rien qui puisse utiliser Flipt en production et obtenir du trafic qui me permet d'évaluer le travail du projet sous charge. En conséquence, j'ai trouvé un excellent outil pour les projets de test de charge. Voici
Vegeta . Les auteurs du projet disent que Vegeta est un outil HTTP universel pour les tests de charge. Ce projet est né de la nécessité de charger des services HTTP avec un grand nombre de requêtes venant de services avec une fréquence donnée.
Le projet Vegeta s'est avéré être exactement l'outil dont j'avais besoin, car il m'a permis de créer un flux continu de demandes vers l'application. Avec ces requêtes, vous pouvez "shell" l'application autant que nécessaire afin de trouver des indicateurs tels que l'allocation / l'utilisation de la mémoire sur le tas, les fonctionnalités des goroutines, le temps passé sur la collecte des ordures.
Après avoir mené quelques expériences, je suis passé à la configuration suivante du lancement de Vegeta:
echo 'POST http://localhost:8080/api/v1/evaluate' | vegeta attack -rate 1000 -duration 1m -body evaluate.json
Cette commande lance
Vegeta en mode d'
attack , envoyant des requêtes HTTP
Flipt API POST
REST à une vitesse de 1000 requêtes par seconde (et cela, certes, est une charge sérieuse) pendant une minute. Les données JSON envoyées par Flipt ne sont pas particulièrement importantes. Ils ne sont nécessaires que pour la formation correcte de l'organisme demandeur. Une telle demande a été reçue par le serveur Flipt, qui a pu effectuer la procédure de
vérification de la demande.
Veuillez noter que j'ai d'abord décidé de tester le
/evaluate Flipt
/evaluate . Le fait est qu'il exécute la plupart du code qui implémente la logique du projet et effectue des calculs de serveur "complexes". Je pensais que l'analyse des résultats de ce point final me donnerait les données les plus précieuses sur les domaines de l'application qui pourraient être améliorés.
Mesures
Maintenant que j'avais un outil pour générer une quantité de trafic suffisamment importante, je devais trouver un moyen de mesurer l'impact de ce trafic sur une application en cours d'exécution. Heureusement, Go dispose d'un assez bon ensemble d'outils standard qui peuvent mesurer les performances du programme. Il s'agit du paquet
pprof .
Je n'entrerai pas dans les détails de l'utilisation de pprof. Je ne pense pas que je le ferai mieux que Julia Evans, qui a écrit
ce merveilleux article sur le profilage des programmes Go avec pprof (si vous ne l’avez pas lu, je vous recommande vraiment de le consulter).
Étant donné que le routeur HTTP dans Flipt est implémenté à l'aide de
go-chi / chi , il n'a pas été difficile pour moi d'activer pprof à l'aide du gestionnaire intermédiaire Chi
approprié .
Donc, dans une fenêtre, Flipt a fonctionné pour moi, et Vegeta, remplissant Flipt de demandes, a travaillé dans une autre fenêtre. J'ai lancé la troisième fenêtre de terminal afin de collecter et d'examiner les données de profilage de tas:
pprof -http=localhost:9090 localhost:8080/debug/pprof/heap
Il utilise l'outil Google pprof, qui peut visualiser les données de profilage directement dans le navigateur.
J'ai d'abord vérifié les
inuse_space inuse_objects et
inuse_space afin de comprendre ce qui se passe sur le tas. Cependant, je n'ai rien trouvé de remarquable. Mais quand j'ai décidé de jeter un œil aux
alloc_space alloc_objects et
alloc_space , quelque chose m'a alerté.
Analyse des résultats du profilage ( original )Il y avait un sentiment que quelque chose appelé
flate.NewWriter alloué 19370 Mo de mémoire pendant une minute. Et cela, soit dit en passant, représente plus de 19 gigaoctets! Ici, évidemment, quelque chose d'étrange se passait. Mais quoi exactement? Si vous regardez attentivement l'original du diagramme ci-dessus, il s'avère que
flate.NewWriter est appelé à partir de
gzip.(*Writer).Write , qui, à son tour, est appelé à partir du
middleware.(*compressResponseWriter).Write . J'ai rapidement réalisé que ce qui se passait n'avait rien à voir avec le code Flipt. Le problème était quelque part dans le code du middleware
Chi utilisé pour compresser les réponses de l'API.
// r.Use(middleware.Compress(gzip.DefaultCompression))
J'ai commenté la ligne ci-dessus et relancé les tests. Comme prévu, un grand nombre d'opérations d'allocation de mémoire ont disparu.
Avant de commencer à trouver une solution à ce problème, je voulais examiner ces opérations d'allocation de mémoire de l'autre côté et comprendre comment elles affectent les performances. En particulier, j'étais intéressé par leur impact sur le temps nécessaire au programme pour collecter les ordures. Je me suis souvenu que Go a toujours un outil de suivi qui vous permet d'analyser les programmes pendant leur exécution et de collecter des informations à leur sujet pendant certaines périodes. Les données collectées par trace incluent des indicateurs importants tels que l'utilisation du tas, le nombre de goroutines en cours d'exécution, des informations sur les requêtes réseau et système et, ce qui était particulièrement précieux pour moi, des informations sur le temps passé dans le garbage collector.
Pour collecter efficacement des informations sur un programme en cours d'exécution, je devais réduire le nombre de requêtes par seconde envoyées à l'application en utilisant Vegeta, car le serveur me donnait régulièrement du
socket: too many open files erreurs de
socket: too many open files . J'ai supposé que c'était parce que
ulimit était réglé trop bas sur mon ordinateur, mais je ne voulais pas y entrer.
J'ai donc redémarré Vegeta avec cette commande:
echo 'POST http://localhost:8080/api/v1/evaluate' | vegeta attack -rate 100 -duration 2m -body evaluate.json
Par conséquent, si nous comparons cela avec le scénario précédent, seulement un dixième des demandes ont été envoyées au serveur, mais cela a été fait pour une période de temps plus longue. Cela m'a permis de collecter des données de haute qualité sur le travail du programme.
Dans une autre fenêtre de terminal, j'ai exécuté cette commande:
wget 'http://localhost:8080/debug/pprof/trace?seconds=60' -O profile/trace
En conséquence, j'avais à ma disposition un fichier contenant des données de trace collectées en 60 secondes. Vous pouvez examiner ce fichier à l'aide de la commande suivante:
go tool trace profile/trace
L'exécution de cette commande a conduit à la découverte des informations collectées dans le navigateur. Ils ont été présentés sous une forme graphique pratique pour étude.
Des détails sur la
go tool trace peuvent être trouvés dans
ce bon article.
Résultats de trace de flipt. Un graphique en dents de scie de l'allocation de mémoire sur le tas est clairement visible ( original )Sur ce graphique, il est facile de voir que la quantité de mémoire allouée sur le tas a tendance à augmenter assez rapidement. Dans ce cas, après la croissance devrait être une forte baisse. Les emplacements où la mémoire allouée tombe sont des opérations de récupération de place. Ici, vous pouvez voir les colonnes bleues prononcées dans la zone GC, représentant le temps passé sur la collecte des ordures.
Maintenant, j'ai rassemblé toutes les preuves du «crime» dont j'ai besoin et je pourrais commencer à chercher une solution au problème d'allocation de mémoire.
Résolution de problèmes
Afin de découvrir la raison pour laquelle appeler
flate.NewWriter conduit à autant d'opérations d'allocation de mémoire, j'ai dû regarder le code source de
Chi . Afin de savoir quelle version de Chi j'utilise, j'ai exécuté la commande suivante:
go list -m all | grep chi github.com/go-chi/chi v3.3.4+incompatible
Ayant atteint le code source
chi / middleware / compress.go @ v3.3.4 , j'ai pu trouver la méthode suivante:
func encoderDeflate(w http.ResponseWriter, level int) io.Writer { dw, err := flate.NewWriter(w, level) if err != nil { return nil } return dw }
Dans d'autres recherches, j'ai découvert que la méthode
flate.NewWriter , via un gestionnaire intermédiaire, était appelée pour chaque réponse. Cela correspondait à l'énorme quantité d'opérations d'allocation de mémoire que j'ai vu plus tôt, chargeant l'API avec mille requêtes par seconde.
Je ne voulais pas refuser de compresser les réponses de l'API ou chercher un nouveau routeur HTTP et une nouvelle bibliothèque de support de middleware. Par conséquent, j'ai tout d'abord décidé de savoir s'il était possible de faire face à mon problème simplement en mettant à jour Chi.
J'ai exécuté
go get -u -v "github.com/go-chi/chi" , mis à niveau vers Chi 4.0.2, mais le code du middleware pour la compression des données semblait, comme il me semblait, le même qu'auparavant. Lorsque j'ai relancé les tests, le problème n'a pas disparu.
Avant de mettre fin à ce problème, j'ai décidé de rechercher des problèmes ou des messages PR dans le référentiel Chi qui mentionnent quelque chose comme «middleware de compression». Je suis tombé sur un PR avec le titre suivant: "Réécriture de la bibliothèque de compression middleware". L'auteur de ce PR a déclaré ce qui suit: "De plus, sync.Pool est utilisé pour les encodeurs, qui a une méthode de réinitialisation (io.Writer), ce qui réduit la charge de la mémoire."
Ça y est! Heureusement, ce PR a été ajouté à la branche principale, mais comme aucune nouvelle version de Chi n'a été créée, j'ai dû mettre à jour comme ceci:
go get -u -v "github.com/go-chi/chi@master"
Cette mise à jour, qui m'a beaucoup plu, était rétrocompatible, son utilisation n'a pas nécessité de modification du code de mon application.
Résultats
J'ai exécuté à nouveau les tests de charge et le profilage. Cela m'a permis de vérifier que la mise à jour Chi a résolu le problème.
Maintenant, flate.NewWriter utilise un centième de la quantité de mémoire allouée précédemment ( originale )En regardant à nouveau les résultats de la trace, j'ai vu que la taille du tas augmente maintenant beaucoup plus lentement. De plus, le temps requis pour la collecte des ordures a diminué.
Au revoir - «scie» ( original )Après un certain temps, j'ai
mis à jour le référentiel Flipt, ayant plus confiance qu'auparavant que mon projet sera capable de faire face de manière adéquate à la charge élevée.
Résumé
Voici les conclusions que j'ai tirées après avoir réussi à trouver et à résoudre les problèmes ci-dessus:
- Vous ne devez pas vous fier à l'hypothèse que les bibliothèques open source (même les plus populaires) ont été optimisées ou qu'elles n'ont pas de problèmes évidents.
- Un problème innocent peut entraîner des conséquences graves, des manifestations de l '"effet domino", notamment sous forte charge.
- Si possible, vous devez utiliser sync.Pool .
- Il est utile de garder à portée de main les outils de test des projets en charge et de profilage.
- Go Toolkit et Open Source - Super!
Chers lecteurs! Comment recherchez-vous les performances de vos projets Go?
