Pourquoi mes appels SOAP v2 WS-I sont-ils si lents (7 à 10 secondes par mise à jour du produit)?

16

Nous utilisons l'API Magento SOAP v2 avec WS-I.

Le problème est que les appels SOAP sont extrêmement lents (7-10 secondes par produit!). Nous appelons catalogProductUpdate sans images. La boutique elle-même fonctionne bien, seul l'appel SOAP est lent. Nous avons activé le cache et modifié l'indice pour améliorer les performances (qui aident de nombreux autres magasins lorsque l'importation SOAP était lente).

J'ai mis des messages de log dans divers fichiers pour savoir où ça va mal. Il s'agit du journal de combinaison des appels de fonction et des événements de répartition:

20.03.2013 14:17:43: Mage_Api_V2_SoapController
20.03.2013 14:17:43: dispatchEvent: controller_action_postdispatch_api_v2_soap_index
20.03.2013 14:17:43: dispatchEvent: controller_action_postdispatch_api
20.03.2013 14:17:43: dispatchEvent: controller_action_postdispatch
20.03.2013 14:17:43: dispatchEvent: controller_front_send_response_before
20.03.2013 14:17:43: dispatchEvent: http_response_send_before
20.03.2013 14:17:43: dispatchEvent: controller_front_send_response_after
20.03.2013 14:17:43: Mage::run
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: core_collection_abstract_load_before
20.03.2013 14:17:51: dispatchEvent: core_collection_abstract_load_after
20.03.2013 14:17:51: dispatchEvent: core_collection_abstract_load_before
20.03.2013 14:17:51: dispatchEvent: core_collection_abstract_load_after
20.03.2013 14:17:51: dispatchEvent: core_collection_abstract_load_before
20.03.2013 14:17:51: dispatchEvent: core_collection_abstract_load_after
20.03.2013 14:17:51: dispatchEvent: controller_front_init_before
20.03.2013 14:17:51: dispatchEvent: controller_front_init_routers
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: model_load_after
20.03.2013 14:17:51: dispatchEvent: core_abstract_load_after
20.03.2013 14:17:51: Mage_Core_Controller_Varien_Front
20.03.2013 14:17:51: Mage_Core_Controller_Varien_Front
20.03.2013 14:17:51: Mage_Core_Controller_Varien_Router_Standard
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: core_locale_set_locale
20.03.2013 14:17:51: dispatchEvent: controller_action_predispatch
20.03.2013 14:17:51: dispatchEvent: controller_action_predispatch_api
20.03.2013 14:17:51: dispatchEvent: controller_action_predispatch_api_v2_soap_index
20.03.2013 14:17:51: Mage_Core_Controller_Varien_Action
20.03.2013 14:17:51: Mage_Api_Model_Server
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: Mage_Api_Model_Server_Handler_Abstract
20.03.2013 14:17:51: Neues Update: 2110000438920 
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: model_load_after
20.03.2013 14:17:51: dispatchEvent: core_abstract_load_after
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: model_load_before
20.03.2013 14:17:51: dispatchEvent: catalog_product_load_before
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: model_load_after
20.03.2013 14:17:51: dispatchEvent: catalog_product_load_after
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: prepareDataForSave Dauer: 0.75447800 1363789071-0.77473800 1363789071=0.02026
20.03.2013 14:17:51: dispatchEvent: catalog_product_validate_before
20.03.2013 14:17:51: dispatchEvent: catalog_product_validate_after
20.03.2013 14:17:51: dispatchEvent: application_clean_cache
20.03.2013 14:17:51: dispatchEvent: model_save_before
20.03.2013 14:17:51: dispatchEvent: catalog_product_save_before
20.03.2013 14:17:51: dispatchEvent: model_load_after
20.03.2013 14:17:51: dispatchEvent: core_abstract_load_after
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: catalog_product_media_save_before
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
20.03.2013 14:17:51: dispatchEvent: application_clean_cache
20.03.2013 14:17:51: dispatchEvent: model_save_after
20.03.2013 14:17:51: dispatchEvent: catalog_product_save_after
20.03.2013 14:17:51: dispatchEvent: model_save_after
20.03.2013 14:17:52: dispatchEvent: cataloginventory_stock_item_save_after
20.03.2013 14:17:52: dispatchEvent: resource_get_tablename
20.03.2013 14:17:52: dispatchEvent: core_collection_abstract_load_before
20.03.2013 14:17:52: dispatchEvent: core_collection_abstract_load_after
20.03.2013 14:17:52: dispatchEvent: resource_get_tablename
20.03.2013 14:17:52: dispatchEvent: model_load_before
20.03.2013 14:17:52: dispatchEvent: core_abstract_load_before
20.03.2013 14:17:52: dispatchEvent: resource_get_tablename
20.03.2013 14:17:52: dispatchEvent: model_load_after
20.03.2013 14:17:52: dispatchEvent: core_abstract_load_after
20.03.2013 14:17:52: dispatchEvent: start_process_event_cataloginventory_stock_item_save
20.03.2013 14:17:52: dispatchEvent: index_process_change_status
20.03.2013 14:17:52: dispatchEvent: index_process_change_status
20.03.2013 14:17:52: dispatchEvent: index_process_change_status
20.03.2013 14:17:52: dispatchEvent: model_save_before
20.03.2013 14:17:52: dispatchEvent: core_abstract_save_before
20.03.2013 14:17:52: dispatchEvent: resource_get_tablename
20.03.2013 14:17:52: dispatchEvent: resource_get_tablename
20.03.2013 14:17:52: dispatchEvent: model_save_after
20.03.2013 14:17:52: dispatchEvent: core_abstract_save_after
20.03.2013 14:17:52: dispatchEvent: end_process_event_cataloginventory_stock_item_save
20.03.2013 14:17:52: dispatchEvent: start_index_events_catalog_product_mass_action
20.03.2013 14:17:52: dispatchEvent: end_index_events_catalog_product_mass_action
20.03.2013 14:17:52: dispatchEvent: resource_get_tablename
20.03.2013 14:17:52: dispatchEvent: core_collection_abstract_load_before
20.03.2013 14:17:52: dispatchEvent: core_collection_abstract_load_after
20.03.2013 14:17:52: dispatchEvent: start_process_event_catalog_product_save
20.03.2013 14:17:52: dispatchEvent: index_process_change_status
20.03.2013 14:17:52: dispatchEvent: index_process_change_status
20.03.2013 14:17:52: dispatchEvent: index_process_change_status
20.03.2013 14:17:52: dispatchEvent: index_process_change_status
20.03.2013 14:17:52: dispatchEvent: index_process_change_status
20.03.2013 14:17:52: dispatchEvent: index_process_change_status
20.03.2013 14:17:52: dispatchEvent: index_process_change_status
20.03.2013 14:17:52: dispatchEvent: index_process_change_status
20.03.2013 14:17:52: dispatchEvent: index_process_change_status
20.03.2013 14:17:52: dispatchEvent: model_save_before
20.03.2013 14:17:52: dispatchEvent: core_abstract_save_before
20.03.2013 14:17:52: dispatchEvent: model_save_after
20.03.2013 14:17:52: dispatchEvent: core_abstract_save_after
20.03.2013 14:17:52: dispatchEvent: end_process_event_catalog_product_save
20.03.2013 14:17:52: dispatchEvent: model_save_commit_after
20.03.2013 14:17:52: dispatchEvent: core_abstract_save_commit_after
20.03.2013 14:17:52: dispatchEvent: model_save_commit_after
20.03.2013 14:17:52: dispatchEvent: cataloginventory_stock_item_save_commit_after
20.03.2013 14:17:52: dispatchEvent: model_save_commit_after
20.03.2013 14:17:52: dispatchEvent: core_abstract_save_commit_after
20.03.2013 14:17:52: dispatchEvent: model_save_commit_after
20.03.2013 14:17:52: dispatchEvent: catalog_product_save_commit_after
20.03.2013 14:17:52: update Dauer: 0.02026

La partie intéressante est:

20.03.2013 14:17:43: Mage::run
20.03.2013 14:17:51: dispatchEvent: resource_get_tablename
...
20.03.2013 14:17:51: Mage_Core_Controller_Varien_Front

Il y a toujours 7 à 10 secondes entre Mage::runle prochain appel d'événement / fonction Mage_Core_Controller_Varien_Front. Des idées qui peuvent mal tourner ici?

Nous avons le même problème avec une autre boutique (sur un autre serveur, client différent) avec les mêmes paramètres, où une mise à jour prend 15 secondes.

ce-1.7.0.2 api soap event-observer Anna Völkl
la source
Avez-vous essayé de déboguer les temps de chargement de la configuration? Cela semble être la raison la plus probable d'un retard
Petar Dzhambazov
Pourriez-vous expliquer ce que vous entendez par «déboguer les temps de chargement de la configuration»?
Anna Völkl
Je suppose que Petar parle du temps qu'il faut pour compiler l'arborescence des nœuds de configuration.
Matthias Zeis
Oui, je veux dire le temps qu'il faut pour amorcer Magento avant de traiter la demande réelle. Aussi, pourquoi Mage :: s'exécute-t-il dans le journal? Je ne vois pas un tel appel dans api.php
Petar Dzhambazov
J'ai un petit conseil sur les performances ci-dessous, mais si vous / vos développeurs souhaitez approfondir les coudes dans l'API, cette série d'API couvre la répartition en détail et peut aider à détecter les
Alan Storm

Réponses:

17

Avez-vous une configuration PHP pour mettre en cache les fichiers WSDL? L' SoapServerimplémentation de PHP (utilisée par Magento) doit examiner le fichier WSDL au moins une fois pendant un appel SOAP, parfois plus d'une fois. Cela peut créer une croissance exponentielle de vos délais de demande. Vérifiez le réglage à

System -> Configuration -> Magento Core Api -> Enable WSDL Cache

et assurez-vous que sa valeur est oui. Cela demandera à PHP de mettre en cache le fichier WSDL, ce qui devrait améliorer vos performances.

Alan Storm
la source
3
Je travaille également sur le même projet, donc je sais que oui, nous avons déjà activé le cache WSDL. Cela a fait environ 1 seconde de différence, mais ce n'est pas encore beaucoup compte tenu du fait que l'appel de mise à jour prend 8 à 10 secondes ...
Daniel Lang
2
À droite, Activer le cache WSDL dans le backend est défini sur "Oui".
Anna Völkl
Même si ce n'était pas la vraie solution, je sélectionne cette réponse pour fermer la question.
Anna Völkl
Cela m'a fait passer de 30 secondes pour faire une mise à jour à 4 secondes. Gagner.
dgig