Comment accélérer l'importation de produits dans Prestashop
Pour les gens pressés : allez directement à la conclusion.
Introduction
Pour un client, récemment j’ai été amené à importer une quinzaine de millier de produits.
Très vite, des problèmes de perfs apparaissent sur le serveur de prod : c’est lent et beaucoup trop long.
Chez de nombreux hébergeurs, des erreurs vont apparaître car le script (AdminImportController.php) n’aura pas fini dans le délai défini par la directive de php max_execution_time. Provoquant des erreurs HTTP 500. Ou alors ce sera le serveur web (Apache, Nginx) qui va se lasser de ne pas avoir de réponse et nous renvoyer une erreur HTTP 504 Gateway Timeout.
Changer cette directive et les paramètres du serveur web peuvent, dans certains cas (des serveurs rapides et petits lots d’importation) rendre le traitement possible, mais c’est de la bidouille.
On va donc sortir les outils de mesure — profiling — et essayer de trouver les goulots d’étranglements et voir si on peut améliorer tout ça.
Profilage
On lance xhprof et xhgui pour voir ce qui se passe réellement dans le code.
Conditions de test:
Import de 449 produits en CSV. À chaque importation, on efface les produits déjà présent en base. Chaque produit est associé à une image, mais ces images sont introuvables.
Premier lancement, ça met des plombes, mais les objets associés sont crées, c’est l’initialisation.
Deuxième lancement, on a des données interéssantes : 156 secondes (2min36) de traitement.
On peut lire que la très grande majorité du temps à été passé à faire des appels à la base de données.
Regardons dans le détail:
C’est classé par temps de traitement dans chaque fonction elle-même (sans le temps passé dans chacun de ses descendants).
On retrouve bien sûr les fonctions liés à la BDD DbPDOCore en bonne position. L’information supplémentaire interessante est le “Call count”, c’est-à-dire le nombre de fois où chaque fonction à été appelée.
Appels | Fonction | Appels / Produit |
---|---|---|
49 000 | DbPDOCore::_query | ~100 |
160 000 | DBCore::escape | ~320 |
100 000 | ToolsCore::strtolower | ~200 |
Ça fait vraiment beaucoup de requêtes par produit.
On va partir de la fonction qui nous intéresse : l’import de produit, pour avoir une vision plus précise et descendre dans l’arbre des appels.
AdminImportControllerCore::productImport
Regardons d’abord le nombre d’appels.
On remarque :
Tools::getValue à été invoquée 8 fois par produit ShopCore::isFeatureActive, 3 fois par produit.
Tools::getValue récupère une valeur dans _GET ou _POST. Lorsqu’on regarde le code, aucun appel n’est fonction du produit, le résultat ne change pas entre chaque appel. On pourrait donc sortir ces 8 appels de la boucle et les executer qu’une fois pour toute. Mais la colonne WallTime nous apprends qu’on ne gagnerait que quelques miettes.
IsFeatureActive est dans le même cas, d’une ligne à l’autre, son résultat ne va pas changer. On pourrait lui aussi le sortir de la boucle.
Regardons maintenant les fonctions qui consomment du temps :
On remarque ces fonctions sont toutes appelées 449 fois, nous importons 449 produits. C’est donc normal.
Les deux fonctions les plus pénalisantes sont : ProductCore::Add et ImageCore::add (elles accaparent à elles seules 40% du temps de traitement de ProductImport)
ProductCore::setAdvancedStockManagement est également étrange, car je n’utilise pas le AdvancedStockManagement dans mon jeu de données et la gestion des stocks avancées n’est pas activé dans la boutique :
Plongeons dans ProductCore::Add
ProductCore::Add
Si on trie par temps d’execution, on trouve dans le top ObjectModelCore::Add (insertion en BD du produit) et HookCore::Exec (execution des hooks).
Continuons la descente. Qu’est ce qui se passe dans ObjectModelCore::Add… ?
ObjectModelCore::Add
Surprise ! On retrouve HookCore::Exec et il prends même plus de temps que DbCore::insert!
Il est peu probable qu’on en trouve plus en continuant la piste de DBCore::insert. Regardons HookCore::Exec.
HookCore::Exec
Dans Prestashop, les hooks (ou crochets) permettent aux modules d’exécuter des actions à des moments bien précis. C’est une implémentation du patron de conception Observateur.
Chaque module va donc “s’abonner” à des actions via ce système de “hooks”.
Dans notre cas, pour chaque produit crée, un certain nombres d’actions vont être effectuées par les modules.
Retournons à xhprof :
Dans Inclusive Wall Time on a le temps total passé dans HookCore::Exec.
On a vu que cette fonction est appelée pour chaque appel de ProductCore::Add et pour chaque appel de ObjectModelCore::Add. Regardons le code ProductCore::Add
ProductCore::Add invoque Hook::exec(‘actionProductSave’) ET ObjectModel::Add (qui lui même invoque Hook::exec())
Chaque appel de ObjectModel::Add va donc invoquer 4 hooks. On remarque que les paramètres ne sont pas les mêmes, malheureusement xhprof ne nous permettra pas de faire la distinctions entre eux.
On sait donc maintenant pourquoi le compteur d’appel de HookCore::exec est si important (22 par produits), reste à savoir pourquoi c’est si long.
La colonne InclusiveWallTime nous informe qu’une minute complète (sur les 2min30 du total) à été passé à exécuter ces actions de modules.
C’est énorme ! On tient un suspect !
Regardons les fonctions enfants:
Dans le top, on a Gamification::__call , BlockLayered::hookAfterSaveProduct , et dans une bien moindre mesure HookCore::getHookModuleExecList.
Le plus gros consommateur de temps (et de mémoire), c’est Gamification. Un module activé par défaut avec les versions récentes de Prestashop et qui pour l’importation ne sert à rien !
Deuxième coupable: BlockLayered.
Un module qui permet de faire de la recherche de produit par facette.
Il a donc besoin d’indexer les produits. Au lieu de reconstruire son indexe à chaque insertion de produit, il peut le faire qu’une seule fois pour toute, à la fin.
On va les désactiver tous les deux.
Et c’est parti pour un troisième tour !
Modules désactivés
Boom !!! 40% plus rapide et presque moitié moins de mémoire utilisée, juste en désactivant deux modules.
Function | Call Count | Self Wall Time | Self CPU | Inclusive Wall Time | Inclusive CPU | Inclusive Memory Usage |
---|---|---|---|---|---|---|
HookCore::exec</a> | 10338 | 987,550 µs | 739,406 µs | 62,357,007 µs | 23,211,780 µs | 18,617,208 bytes |
HookCore::exec</a> | 10338 | 619,802 µs | 481,420 µs | 5,224,022 µs | 4,631,482 µs | 3,235,904 bytes |
Comparons les graphes :
On a bien réduit le temps de traitement et accessoirement la mémoire utilisée.
Easy win !
Je ne l’ai pas explicité mais Gamification fait de nombreuses requêtes (dans mon cas 6 par produits) d’INSERT qui sont très consommatrices de resources.
En désactivant deux modules, on a pu réduire le nombre de requêtes et donc améliorer la performance. Mais ces requêtes restent un goulot d’étranglement et les perfs ne sont toujours pas très satisfaisantes.
Transactions
Une astuce trouvée sur programmation-web.net est interessante : les transactions.
Par défaut, MySQL va écrire chaque enregistrement immédiatement sur le disque dur. En utilisant les transactions, ces enregistrements seront gardés en mémoire et écrits qu’une seule fois.
La doc de MySQL sur les Transactions est une lecture interessante.
Une tuerie !
On a encore bien réduit le temps de traitement.
Pour 31070 appels à DbPDOCore::_query, on passe de 67 secondes à 7 !
Images
Pas abordé dans cet article, mais lorsqu’on importe des images, il vaut mieux les avoir en local pour les transformer que d’avoir à les télécharger une par une.
En conclusion
Pour avoir une importation csv plus rapide, il faut :
- la désactivation de modules (gamification et blocklayered)
- le passage aux transactions
- les images en local
- l’amélioration du code de Prestashop