Phương pháp phân tích hiệu suất của plugin WordPress

Tôi xin đưa ra một ví dụ chi tiết về phân tích hiệu suất của một plugin WordPress. Tối ưu hóa hiệu suất là một quá trình quan trọng, và bước đầu tiên trong quy trình này chính là phân tích hiệu suất – bạn cần xác định rõ ràng những điểm nghẽn hiệu suất trong hệ thống của mình.

Trong WordPress, điểm nghẽn hiệu suất thường được tìm thấy chủ yếu ở cơ sở dữ liệu. Việc tối ưu hóa cơ sở dữ liệu là một yếu tố quyết định đến tốc độ tải trang và trải nghiệm người dùng. Một công cụ plugin như Query Monitor có thể cung cấp thông tin quý giá về các truy vấn cơ sở dữ liệu, thời gian thực thi và các lỗi có thể xảy ra. Điều này giúp bạn nhận diện được những phần nào của plugin hoặc theme đang gây ra sự chậm trễ.

Tuy nhiên, để thực hiện phân tích và tối ưu hóa hiệu suất một cách triệt để, bạn cần sử dụng những công cụ mạnh mẽ hơn. Những công cụ này không chỉ giúp bạn phân tích một cách sâu sắc mà còn cung cấp các giải pháp cụ thể để cải thiện hiệu suất tổng thể của website. Việc sử dụng kết hợp nhiều công cụ và kỹ thuật sẽ giúp bạn có cái nhìn toàn diện hơn về tình trạng hiệu suất của website và từ đó đưa ra các biện pháp khắc phục hiệu quả.

Percona Toolkit

Để thu thập tất cả các truy vấn SQL vào một bảng xếp hạng, tôi đã thiết lập nhật ký truy vấn chậm cho PerconaDB/MySQL để ghi lại mọi truy vấn SQL.

Chỉnh sửa tệp /etc/mysql/my.cnf của bạn – tệp mặc định có một lỗi khi thiết lập nhật ký truy vấn chậm, nhưng hãy tìm dòng bắt đầu bằng log_slow_queries (có thể nó đã bị chú thích). Đừng bỏ chú thích, thay vào đó hãy sử dụng các giá trị như sau:

slow-query-log = 1
slow-query-log-file = /var/log/mysql/slow.log
long_query_time = 1
log-queries-not-using-indexes

long_query_time có thể là số thập phân nếu bạn muốn – nó tính bằng giây, nhưng bạn có thể nhập 0.1 hoặc thậm chí 0 để ghi lại mọi thứ.

Bạn cũng cần tạo tệp nhật ký đó, vì vậy hãy sử dụng các lệnh sau để thực hiện:

mkdir /var/log/mysql
touch /var/log/mysql/slow.log
chown mysql:mysql -R /var/log/mysql

Bây giờ khởi động lại MySQL/PerconaDB bằng cách sử dụng:

service mysql restart

Chạy các trang trên trang web của bạn mà bạn muốn phân tích – bạn có thể sử dụng một webcrawler nếu bạn thích – Screaming Frog là một lựa chọn tuyệt vời cho việc này nếu bạn không có một tập hợp các trang cụ thể để kiểm tra và chỉ muốn kiểm tra mọi thứ – tải xuống phiên bản miễn phí, chỉ định nó vào trang chính của trang web của bạn và nó sẽ quét trang web của bạn và truy cập nhiều trang. Hoặc chỉ cần truy cập vào các trang mà bạn biết là chậm, hoặc thậm chí chỉ để nó chạy để lấy mẫu hành vi sử dụng của người dùng và phát hiện các truy vấn chậm cho họ. Chạy lệnh này để kiểm tra tệp nhật ký của bạn đang được ghi:

tail /var/log/mysql/slow.log

Bạn sẽ thấy một số văn bản mà PerconaDB đang lưu vào tệp. Để phân tích tệp này và có được một cấu trúc kết quả rõ ràng cho thấy các truy vấn nào đang tác động nhiều nhất đến máy chủ của bạn, hãy chạy lệnh sau:

pt-query-digest /var/log/mysql/slow.log

(nếu bạn chưa cài đặt, bạn sẽ nhận được thông báo về lệnh để cài đặt nó)

Điều này sẽ hiển thị bảng xếp hạng các câu lệnh SQL với câu lệnh có ảnh hưởng tiêu cực nhất đến máy chủ của bạn ở đầu. Bạn có thể sao chép một trong những ví dụ của truy vấn này vào công cụ MySQL yêu thích của mình (Toad, MySQL Workbench hoặc trực tiếp qua SSH) và chạy lệnh giải thích (EXPLAIN) để xác định các bảng nào đang bị truy cập nhiều nhất và nơi nào có thể cần thêm chỉ mục hoặc sửa đổi truy vấn để cải thiện hiệu suất.

Tôi đang sử dụng giá trị long_query_time = 0 để bắt tất cả các truy vấn.

XDebug Profiler

Để phân tích các nút thắt cổ chai trong PHP, hãy sử dụng XDebug Profiler. Đừng bận tâm đến những công cụ như P3 Performance Profiler – vì kết quả từ chúng hoàn toàn không đáng tin cậy.

Nói một chút về XDebug Profiler

Có rất nhiều công cụ profiler có sẵn cho WordPress, nhưng tất cả đều có những điểm yếu nhất định trong việc cung cấp kết quả thực sự mà bạn cần.

Query Monitor, chẳng hạn, rất tuyệt vời trong việc phân tích các truy vấn cơ sở dữ liệu, thường là nơi phát sinh vấn đề về hiệu suất, nhưng nó lại không hoàn toàn giúp bạn xác định được các plugin hoặc đường dẫn mã nào đang tiêu tốn nhiều thời gian với PHP.

P3 Profiler gần như không có giá trị gì và không có công cụ nào khác – về plugin – mà tôi tìm thấy thực sự cố gắng phân tích các đường dẫn thực thi PHP.

Nhưng Xdebug lại có thể phân tích mọi thứ sử dụng PHP và giờ đây đã tương thích với PHP 7.

Cài đặt XDebug profiler

Chạy lệnh này:

php -i > ~/phpinfo.txt

Sau đó, lấy nội dung của tệp phpinfo.txt và dán vào trang web này: https://xdebug.org/wizard.php

Trang này sẽ cho bạn biết cách cài đặt nó, cụ thể cho máy chủ của bạn.

Đối với máy chủ của tôi, cài đặt trông như sau:

wget http://xdebug.org/files/xdebug-2.4.0.tgz
tar -xvzf xdebug-2.4.0.tgz
cd xdebug-2.4.0
phpize 
sudo apt-get install php7.0-dev
./configure
make
cp modules/xdebug.so /usr/lib/php/20151012

Bây giờ chỉnh sửa: /etc/php/7.0/fpm/php.ini (và tùy chọn /etc/php/7.0/cli/php.ini), tìm khu vực modules và chèn các dòng sau:

zend_extension = /usr/lib/php/20151012/xdebug.so
xdebug.profiler_enable_trigger = 1
xdebug.profiler_output_dir = /var/log/xprofiler/
xdebug.profiler_output_name = cachegrind.out.%t.%p
xdebug.profiler_enable_trigger_value = secretpassword

Lưu ý: Tôi đã đặt profiler_output_name vì mặc định là cachegrind.out.%p – %p là process ID, vì vậy khi cùng một tiến trình PHP-FPM được sử dụng lại để phục vụ yêu cầu khác, tệp log trước đó sẽ bị ghi đè. Bằng cách thêm timestamp, điều này sẽ được tránh. Nếu bạn không muốn có nhiều tệp log, thì đừng làm điều này và bạn sẽ chỉ có b стệp log bằng với số tiến trình PHP mà bạn có.

Hãy chắc chắn chọn một số ký tự khác cho mật khẩu bí mật – xprofiler lưu rất NHIỀU thông tin vào đĩa (nếu bạn đặt profiler_output_name như trên), vì vậy nếu một robot xấu tìm thấy trang web của bạn và thêm tham số này, nó có thể khiến trang web của bạn gặp sự cố rất nhanh chóng. Lưu tệp và sau đó hãy chắc chắn tạo thư mục và thay đổi quyền sở hữu để PHP có thể ghi vào đó:

mkdir /var/log/xprofiler
chown www-data:www-data /var/log/xprofiler

Khởi động lại dịch vụ php7.0-fpm với lệnh này:

service php7.0-fpm restart

Thiêt lập XDebug profiler chạy liên tục

Để thiết lập XDebug profiler chạy liên tục, nếu bạn không muốn sử dụng URL trigger và muốn ghi lại mọi thứ xảy ra trên máy chủ của mình, bạn có thể sửa đổi cài đặt sau trong file php.ini:

xdebug.profiler_enable = 1
xdebug.profiler_enable_trigger = 0

Hãy chắc chắn rằng bạn có đủ không gian lưu trữ, vì điều này sẽ ghi lại rất nhiều dữ liệu vào đĩa. Để biết thêm thông tin chi tiết, hãy tham khảo trang web này: XDebug Profiler Documentation.

Sử dụng XDebug profiler để tìm hiểu lý do tại sao một trang WordPress lại chậm

Truy cập vào một trong những trang web gặp vấn đề của bạn và thêm tham số sau vào URL:

?XDEBUG_PROFILE=secretpassword

Bạn sẽ nhận được một loạt dữ liệu phân tích được lưu trong /var/log/xprofiler. Bạn có thể phân tích dữ liệu này bằng công cụ trực quan KCacheGrind. Tải nó về cho Linux hoặc Windows (cho Windows, tôi sử dụng QCacheGrind) và tải các tệp cachegrind.out.* về máy tính của bạn để phân tích và tìm ra nguyên nhân gây ra hiệu suất kém.

Ví dụ, tôi đã gặp phải thời gian tải trang 90 giây khó chịu trên trang widget của mình trên một trong những trang web. Sử dụng XDebug Profiler và QCacheGrind, tôi đã nhận được hình ảnh này:

Làm việc từ trên xuống dưới, bạn có thể thấy 2 lệnh gọi đến curl_exec – được thực hiện bởi plugin DatafeedrAPI trong file datafeedr.php. Những lệnh gọi này mất 98 giây. Điều đó có nghĩa là tôi ngay lập tức biết nơi cần tìm để khắc phục vấn đề này.

Hóa ra, trong trường hợp này, máy chủ của tôi đã cập nhật quá nhiều sản phẩm đến nỗi trang web datafeedr đã tự động cấm trang của tôi!

Giờ đây, nó đã được mở khóa và phần back-end WordPress của tôi hoạt động với tốc độ dưới một giây trở lại.

Tôi đang sử dụng profiler để thu thập mọi thứ vì đây là một plugin dựa trên cron, nhưng bạn có thể sử dụng tùy chọn kích hoạt từ trang trên nếu cần.

Bức tranh gần như hoàn chỉnh về hiệu suất

Với 2 công cụ trên, bạn sẽ nhận được tất cả các nút thắt SQL và tất cả các nút thắt PHP. Có nhiều yếu tố khác có thể ảnh hưởng đến hiệu suất, nhưng tôi không đề cập đến chúng ở đây – chỉ để liệt kê một số yếu tố mà tôi không xem xét, đây là danh sách:

• Mạng/băng thông
• Cấu hình hệ điều hành/sự tắc nghẽn bộ nhớ/gây rối
• Cấu hình máy chủ/tốc độ đĩa/tốc độ CPU
• Tài nguyên cạnh tranh – ví dụ: các hoạt động khác trên máy chủ, tải v.v.

Trong ví dụ này, tôi đang thực hiện phân tích hiệu suất trên một máy chủ phát triển và tôi biết thông số kỹ thuật. Tôi cũng có một máy chủ tham chiếu trùng lặp với mã gốc và cấu hình giống hệt để tôi có thể thực hiện so sánh hiệu suất song song sau khi tối ưu hóa.

Phân Tích Hiệu Suất

Đầu tiên, hãy tải xuống trace của XDebug Profiler cho bất kỳ thứ gì bạn đang theo dõi và mở nó bằng QCacheGrind. Tôi sử dụng tab Callee Map, giống như trong ảnh chụp màn hình này:

Các mục tôi đã đánh dấu trên màn hình:

Đây là danh sách sắp xếp các mục tốn kém – mục tốn kém nhất ở trên cùng tự động. Cột đầu tiên, Incl, cho thấy tổng thời gian của hàm này bao gồm cả các hàm con của nó. Cột thứ hai chỉ hiển thị thời gian sử dụng của hàm này, không bao gồm các hàm con. Sau đó bạn sẽ có số lần gọi, tên hàm và nguồn gốc của nó.

Đây là bản đồ callee – khá thú vị – bạn có thể thấy phần lớn 33% là wpdb->query, sau đó 3 mục tiếp theo chiếm khoảng 25% tổng thời gian thực thi của hàm đầu tiên này (do_action). Ba mục tiếp theo là: PMXI_Chunk, PMXI_Admin và apply_filters. Mỗi hộp này có thể được mở rộng để xem chi tiết hiệu suất về mục cụ thể đó.

Phần thứ ba ở dưới cùng hiển thị thêm thông tin – bạn có thể điều chỉnh để hiển thị biểu đồ của các hàm gọi và hàm được gọi.

Vậy nên chúng ta có 3 khu vực mục tiêu để xem xét – Câu lệnh SQL, PMXI_Chunk và PMXI_Admin.

Những gì bạn đang xem ở trên là:

• Hạng của truy vấn cùng với tổng % thời gian mà loại truy vấn này đã tiêu tốn – những truy vấn ở trên cùng là mục tiêu lớn nhất của bạn – tối ưu hóa chúng để tạo ra ảnh hưởng lớn nhất.
• Cột bên phải cho bạn một tóm tắt cơ bản về truy vấn.
• Phần còn lại của báo cáo bao gồm chi tiết về từng loại truy vấn. Để thể hiện điều đó, đây là văn bản cho 4 truy vấn hàng đầu (tôi đã cắt bớt một số thông tin không cần thiết):

# Query 1: 20.36 QPS, 0.05x concurrency, ID 0xFD1893280DD503F4 at byte 12710724
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 9 3930
# Exec time 20 10s 1ms 76ms 3ms 4ms 2ms 2ms
# Lock time 7 455ms 36us 1ms 115us 224us 71us 98us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Rows affecte 33 3.84k 1 1 1 1 0 1
# Bytes sent 0 53.73k 14 14 14 14 0 14
# Query size 7 498.77k 91 776 129.96 258.32 126.56 97.36
# Tables
# SHOW TABLE STATUS FROM `awdstackdb` LIKE 'wp_postmeta'G
# SHOW CREATE TABLE `awdstackdb`.`wp_postmeta`G
INSERT INTO `wp_postmeta` (`post_id`, `meta_key`, `meta_value`) VALUES (2399, '_product_version', '2.6.4')G

# Query 2: 20.32 QPS, 0.05x concurrency, ID 0x42B194D1A514097D at byte 10645618
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 10 3942
# Exec time 18 9s 485us 92ms 2ms 4ms 3ms 2ms
# Lock time 4 253ms 31us 897us 64us 144us 52us 44us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 1 3.85k 1 1 1 1 0 1
# Rows affecte 33 3.85k 1 1 1 1 0 1
# Bytes sent 0 42.35k 11 11 11 11 0 11
# Query size 2 188.63k 49 49 49 49 0 49
# Tables
# SHOW TABLE STATUS FROM `awdstackdb` LIKE 'wp_postmeta'G
# SHOW CREATE TABLE `awdstackdb`.`wp_postmeta`G
DELETE FROM wp_postmeta WHERE meta_id IN( 48049 )G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select * from wp_postmeta WHERE meta_id IN( 48049 )G

# Query 3: 42.82 QPS, 0.03x concurrency, ID 0x56ED2B5B5549F23D at byte 73914
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 21 8308
# Exec time 10 5s 177us 10ms 610us 2ms 576us 424us
# Lock time 14 937ms 41us 2ms 112us 348us 121us 66us
# Rows sent 2 3.85k 0 1 0.47 0.99 0.50 0
# Rows examine 38 119.08k 0 29 14.68 27.38 8.14 14.52
# Rows affecte 0 0 0 0 0 0 0 0
# Bytes sent 2 809.26k 95 105 99.74 102.22 4.75 92.72
# Query size 10 667.26k 74 97 82.24 88.31 4.92 80.10
# Tables
# SHOW TABLE STATUS FROM `awdstackdb` LIKE 'wp_postmeta'G
# SHOW CREATE TABLE `awdstackdb`.`wp_postmeta`G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT meta_id FROM wp_postmeta WHERE meta_key = '_product_url' AND post_id = 2224G

# Query 4: 7.52 QPS, 0.02x concurrency, ID 0x90EFB67D60488121 at byte 5430080
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 3 1452
# Exec time 8 4s 527us 57ms 3ms 5ms 2ms 3ms
# Lock time 2 172ms 42us 879us 118us 214us 70us 103us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 1.42k 1 1 1 1 0 1
# Rows affecte 12 1.42k 1 1 1 1 0 1
# Bytes sent 0 73.73k 52 52 52 52 0 52
# Query size 1 103.78k 72 74 73.19 72.65 1 72.65
# Tables
# SHOW TABLE STATUS FROM `awdstackdb` LIKE 'wp_term_taxonomy'G
# SHOW CREATE TABLE `awdstackdb`.`wp_term_taxonomy`G
UPDATE wp_term_taxonomy SET count = count + 1 WHERE term_taxonomy_id = 836G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select count = count + 1 from wp_term_taxonomy where term_taxonomy_id = 836G

Các phần hữu ích nhất ở đây là các ví dụ truy vấn – vì vậy tôi sao chép/dán chúng vào mysql và thêm từ EXPLAIN ở phía trước, ví dụ:

explain select * from wp_postmeta WHERE meta_id IN( 48049 );

Trong trường hợp này, khi tôi chạy truy vấn này trên cơ sở dữ liệu, nó đang sử dụng một chỉ mục vì vậy không có nhiều thứ tôi có thể làm để tối ưu hóa ở đây bằng các kỹ thuật SQL. Tuy nhiên, điều tôi có thể nhận ra từ mã là 3 truy vấn hàng đầu thực sự đang cố gắng thực hiện một câu lệnh UPDATE, và trong phần lớn các trường hợp, việc cập nhật là không cần thiết.

Tức là, nhà phát triển của mã này, thay vì chạy một câu lệnh UPDATE SQL, đã thực hiện một câu lệnh DELETE theo sau là một câu lệnh INSERT. Điều này có lẽ là vì một câu lệnh DELETE theo sau là một câu lệnh INSERT yêu cầu ít đường dẫn mã hơn. Nếu dữ liệu chưa tồn tại, câu lệnh xóa sẽ không làm gì và sau đó câu lệnh chèn có thể chạy như bình thường. Nếu dữ liệu ĐÃ tồn tại, nó sẽ bị xóa trước khi được chèn vào.

Để kiểm tra điều này có đúng hay không, tôi có thể xem trong tệp mysql-slow.log. Những gì tôi tìm thấy là thực sự có nhiều câu lệnh SELECT và sau đó là các câu lệnh DELETE. Việc có các câu lệnh INSERT riêng lẻ là hợp lý, nhưng không phải là các câu lệnh DELETE riêng lẻ vì DELETE đang xóa tất cả postmeta. Một lần nữa, sẽ tốt hơn nếu chỉ thực hiện cái gọi là UPSERT (cập nhật hoặc chèn).

Vì vậy, tôi đã tìm thấy nút thắt cổ chai hiệu suất chính tiếp theo cần sửa. Bằng cách xem qua tệp mysql-slow.log, tôi đã tìm kiếm câu lệnh DELETE đầu tiên đối với wp_postmeta và phát hiện ra rằng có 24 câu lệnh DELETE cho mỗi bài viết. Điều này có thể được chuyển thành một câu lệnh duy nhất, điều này sẽ cung cấp khoảng 20 lần tốc độ cho phần này.

Tóm tắt

Sử dụng XDebug profiler để phân tích các điểm nghẽn hiệu suất, sau đó xem xét mã liên quan – có thể là SQL, PHP hoặc cả hai. Sử dụng nhật ký truy vấn chậm và công cụ pt-query-digest để hỗ trợ bạn phân tích các truy vấn SQL.