WP Desk Care - zadbaj o swój biznes online!

Sprawdzona opieka techniczna dla Twojego sklepu

Wpływ wtyczek na szybkość działania WordPress

Wszystkie zgłaszane przez klientów problemy traktujemy bardzo poważnie. Czasami pojawiają się zgłoszenia które, ponieważ mogą dotyczyć całej grupy naszych wtyczek, analizowane są przeze mnie. Zdecydowałem, że podzielę się tutaj jedną z moich analiz.

Jeden z naszych klientów zainstalował 17 naszych wtyczek oraz WPML, a następnie zmierzył czas odpowiedzi skryptu admin-ajax.php. Stwierdził, że największe spowolnienie spowodował WPML: o około 224%, ale na drugiej pozycji znalazł się pakiet 7 wtyczek ShopMagic, który spowodował spowolnienie o około 33%. Zaniepokoiliśmy się, ponieważ to dość znacząca różnica i postanowiliśmy to sprawdzić.

Odtworzenie problemu

Jako że test klienta opierał się na wysłaniu serii pojedynczych requestów do prostego skryptu admin-ajax.php i zmierzeniu czasu wykonania, w celu odtworzenia opisanego problemu zdecydowałem się na analogiczny test.

Testowa akcja

Najpierw dodałem prostą testową akcję:

I sprawdziłem czy WordPress zwraca spodziewany wynik.

curl -I http://wordpress.lh/wp-admin/admin-ajax.php?action=test

HTTP/1.1 200 OK
Date: Thu, 26 Nov 2020 20:25:04 GMT
Server: Apache/2.4.46 (Unix) PHP/7.4.10
TEST OK

Akcja testowa została dodana poprawnie.

Mierzenie czasu

Teraz należało zmierzyć średni czas odpowiedzi WordPressa. W tym celu użyłem prostego narzędzia ApacheBench dostarczanego razem z pakietem Apache HTTP Server. Zmierzyłem najpierw czas odpowiedzi WordPressa z WooCommerce, bez żadnych innych wtyczek.

Wysłałem 100 zapytań, jedno po drugim. Najczęściej podczas tego typu testów wysyłane jest wiele zapytań równolegle, ale zdecydowałem, że przeprowadzę testy analogiczne do zgłoszonych.

$ ab -n100 -c1 http://wordpress.lh/wp-admin/admin-ajax.php?action=test

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       0
Processing:   383  396   9.0    392     417
Waiting:      382  396   9.0    392     417
Total:        383  396   9.0    392     417

Średni czas odpowiedzi wyniósł 0,396 sekundy przy medianie 0,392 sekundy.

Następnie uruchomiłem 10 wtyczek pakietu ShopMagic, 7 dostępnych oraz trzy dodatkowe znajdujące się w fazie alfa.

Connection Times (ms)
              min  mean[+/-sd] median   max
Processing:   476  525 128.0    495    1062
Waiting:      475  524 128.0    494    1062
Total:        476  525 128.0    495    1062

Wnioski

Różnica jest znacząca. Średni czas odpowiedzi wzrósł do 0,525 sekundy, a mediana do 0,495 sekundy, czyli o około 26%-37%. Problem zgłoszony przez klienta został potwiedzony.

Analiza grupowa

ShopMagic, podobnie jak wszystkie wtyczki WP Desk, wykonuje pewne standardowe akcje podczas każdego uruchomienia. Każda wtyczka sprawdza, czy wszystkie wymagania są spełnione i czy wtyczka może bezpiecznie się uruchomić. Testujemy wersję PHP, wersję WooCommerce, dostępne moduły PHP i wiele innych rzeczy. Pojedynczo te czynności nie zajmują wiele czasu, ale istnieje niebezpieczeństwo, że gdy wykona je 17 wtyczek, to łączny wpływ na czas pracy może być znaczący. Niebezpieczeństwo jest tym większe, że część z potrzebnych informacji trzeba pobrać z nagłówków innych wtyczek, a parsowanie tekstowych nagłówków jest dość czasochłonne.

Sprawdźmy to: usunąłem sprawdzanie wymagań we wszystkich wtyczkach i po raz kolejny wysłałem serię zapytań.

Connection Times (ms)
              min  mean[+/-sd] median   max
Processing:   512  551  37.4    549     689
Waiting:      512  551  37.4    549     689
Total:        512  551  37.4    549     689

Nie widać znaczącej różnicy, więc na razie hipoteza, że problem jest rozproszony we wszystkich wtyczkach, raczej nie znalazła potwierdzenia.

Analiza z poziomu WordPress

Jednym z pierwszych kroków przy problemach z szybkością działania wtyczek jest odwołanie się do jednego z WordPressowych profilerów. Moim ulubionym jest QueryMonitor.

Analiza zapytań

Miejscem, gdzie często powstaje najwięcej opóźnień, jest baza danych. Bardzo łatwo jest napisać nieoptymalne zapytanie albo wysłać setki małych zapytań, których łączny narzut zamuli każdy sklep.

Query Monitor - zapytania grupowo

Widać, że najbardziej czasochłonne są zapytania dotyczące opcji. Na drugiej pozycji znalazł się Action Scheduler, czyli komponent będący częścią WooCommerce, a służący do kolejkowania zdarzeń. Nie widać żadnych zapytań ze wtyczki, które znacząco wpłynęłyby na czas ładowania.
Dlaczego tyle czasu zajmuje obsługa opcji? WordPress wszystkie dane zapisywane w cache domyślnie trzyma w tabeli opcji, przy czym każdy transient to dwa oddzielne rekordy w bazie danych. Jest to jeden z powodów, dlaczego zawsze warto zainstalować cache, dzięki któremu wszystkie zapytania związane z danymi tymczasowymi trafią do serwera wyspecjalizowanego w cache takiego jak Redis.

Query Monitor - zapytania ShopMagic

Tutaj znajdują się zapytania, za które odpowiada ShopMagic. Niestety nie możemy ich bardziej zoptymalizować i oba są konieczne. Testowany sklep ma dodanych 36 różnych automatyzacji i trzeba zawsze pobrać je wszystkie, wraz z ich danymi, i zainicjalizować. Tylko wtedy ShopMagic wie, na jakie zdarzenia ma zareagować podczas trwania wywołania.
Znaleźliśmy zatem element, który odpowiada za część opóźnienia. Niestety nie ma tutaj miejsca na optymalizację.

Analiza pozostałych wskaźników Query Monitor

Poza zapytaniami do bazy Query Monitor pokazuje też szereg innych przydatnych informacji.

Często najbardziej czasochłonną operacją są odwołania sklepu do zasobów zewnętrznych HTTP API calls. W tym przypadku nie ma takich odwołań.

Warto sprawdzić też zakładkę Transient updates. Czasami wtyczki nadużywają mechanizmu danych tymczasowych/transientów, a ponieważ domyślnie transienty trzymane są w bazie danych, potrafi to bardzo opóźnić działanie strony.

Analiza za pomocą niskopoziomowego profilera

Baza danych odpowiada za część opóźnień, ale to nie wystarczy, żeby wytłumaczyć tak dużą różnicę w czasie ładowania. Może po prostu w kodzie wtyczki istnieją miejsca, które wykonują jakieś wyjątkowo czasochłonne operacje?
XDebug jest najczęściej używanym przez developerów PHP debuggerem. Oprócz typowego debugowania potrafi również profilować kod i, po prześledzeniu każdej linii, stworzyć raport, który pozwoli na analizę czasu wykonania linia po linii. Raport utworzony przez XDebug tworzony jest w postaci dość wymagającej dla czytelnika, dlatego wykorzystam program QCacheGrind do jego dalszej analizy.

QCacheGrind - procentowo

Polecenia posortowane łącznym czasem wywołania pokazują, w których miejscach najwięcej czasu przecieka nam przez palce. To, co przede wszystkim rzuca się w oczy to fakt, że łącznie ponad 50% czasu procesor spędza na wykonywaniu poleceń load_textdomain oraz różne odwołania do funkcji związanych z tłumaczeniami. Composer\Autoload to proces, który ładuje kolejne pliki PHP do parsowania. Widać także WooCommerce zjadające ok. 20% oraz wtyczkę do logowania emaili, która też jest uruchomiona w sklepie testowym.

QCacheGrind - ShopMagic

Ponieważ wszystkie wtyczki z pakietu mają te same przedrostki w klasach, łatwo można przefiltrować wywołania pod kątem wtyczek ShopMagic. Najdłużej wykonywane polecenie get_build_in_events jest konieczne dla poprawnego działania wtyczki, a po rozbiciu na szczegóły pokazuje, że najwięcej czasu zajmuje samo załadowanie plików z kodem: Class Autoloader.

Weryfikacja hipotez

Na podstawie zebranych danych możemy przetestować, jak zachowa się pakiet wtyczek, gdy wprowadzimy modyfikacje we wtyczce głównej ShopMagic.

Aktywny tylko WooCommerce

Connection Times (ms)
              min  mean[+/-sd] median   max
Processing:   383  396   9.0    392     417
Waiting:      382  396   9.0    392     417
Total:        383  396   9.0    392     417

Średnia 396 ms.

Uruchomione wszystkie wtyczki pakietu ShopMagic oraz WooCommerce

Connection Times (ms)
              min  mean[+/-sd] median   max
Processing:   476  525 128.0    495    1062
Waiting:      475  524 128.0    494    1062
Total:        476  525 128.0    495    1062

Średnia 525 ms.

Pakiet ShopMagic i WooCommerce, ale wtyczki ShopMagic nie ładują swoich tłumaczeń

Connection Times (ms)
              min  mean[+/-sd] median   max
Processing:   457  484  25.6    471     536
Waiting:      457  484  25.6    471     536
Total:        457  484  25.6    471     536

Średnia 484 ms.

Widać bardzo znaczącą poprawę; niestety nie możemy zrezygnować z tłumaczeń.

Pakiet ShopMagic i WooCommerce bez tłumaczeń oraz bez sprawdzania wymagań

Connection Times (ms)
              min  mean[+/-sd] median   max
Processing:   444  483  89.1    457     849
Waiting:      444  483  89.1    457     848
Total:        444  483  89.1    457     849

Średnia 483 ms.
Sprawdzanie wymagań (PHP, wersji wtyczki głównej, kompatybilności itp.) nie wpływa w znaczący sposób na szybkość działania.

Po zakomentowaniu linii, która pobiera automatyzacje i buduje automatyzacje

Connection Times (ms)
              min  mean[+/-sd] median   max
Processing:   363  393  52.9    375     700
Waiting:      363  393  52.9    375     700
Total:        363  393  52.9    375     700

Średnia 393 ms.

W tym momencie zbliżyliśmy się do czasu ładowania samego WooCommerce. Problem jednak w tym, że wtyczka nie nasłuchuje już żadnych zdarzeń. Wtyczka oprócz tego nadal robi szereg ważnych rzeczy, ale — jak widać — nie mają one większego znaczenia dla szybkości działania sklepu. Niestety nie możemy usunąć głównej funkcjonalności (to tam wysyłamy zapytanie do bazy), ale ten test pokazał, że poza nią wtyczki praktycznie nie obciążają sklepu.

Niekończąca się praca

Czy to oznacza, że nie udało się znaleźć żadnych elementów wymagających optymalizacji? Nie. Przy okazji tej analizy znalazłem szereg niewymienionych mniej istotnych elementów, które warto było poddać optymalizacji.
Cześć z nich została zmodyfikowana od razu, część dodana do @TODO. Niestety nie udało się znaleźć żadnych elementów, które odpowiadałyby za spowolnienie i których optymalizacja w znaczący sposób wpłynęłaby na szybkość działania sklepu.

Przykładowo, podczas analizy QCacheGrind odkryłem, że metoda get_event_list wywoływana była bardzo często, więc dodaliśmy cache, który o około 1% polepszył czas działania wtyczki. Niestety zmiany nie były na tyle duże, żeby były widoczne w testach.

Odkryłem też, że wtyczka przez pomyłkę ładowała swoje tłumaczenia dwukrotnie. Niemniej WordPress sprawdza, czy plik tłumaczeń był już ładowany, więc wyeliminowanie problemu nie przyspieszyło w żaden sposób wtyczki, a jedyne wpłynęło na licznik uruchomień pokazywany w profilerze.

Udało się też częściowo obalić tezę, że sama liczba zainstalowanych wtyczek w WordPress ma znaczenie. Okazuje się, że znacznie większe znaczenie ma łączna ilość tłumaczonego tekstu we wtyczkach. Być może autorzy wtyczek powinni rozważyć kompilowanie wtyczki pod konkretną wersję językową?

Czy to oznacza, że praca przy optymalizacji wtyczek została zakończona? Nie. Ta praca wciąż trwa i ciągle będzie trwała. Dodajemy nowe funkcjonalności, poprawiamy błędy i stale rozwijamy wtyczki, a każda nowa linia kodu zmusza nas do dalszych optymalizacji i ulepszeń.

Zobacz inne artykuły

Dołącz do ponad 10 000 czytelników

Poradniki WooCommerce i nowości –
wprost na Twój e-mail.