Shop facts:
- around 100 categories
- but in the main category, there are ~ 70.000 products (because filtering is heavily used)
After moving a shop developed by us to a production server of an external hosting company, we experience the problem, that the php bin/magento index:reindex command is stuck during the catalog category index.
On our local systems, this action takes less than two minutes. On the production server it takes more than 1 hour (we did not wait longer) and SHOW PROCESSLIST\G in mysql shows:
*************************** 1. row ***************************
Id: 538862
User: shop_production
Host: localhost
db: shop_production
Command: Query
Time: 169
State: Sending data
Info: INSERT INTO `catalog_category_product_index_store2_tmp` (`category_id`, `product_id`, `position`, `i
Progress: 0.000
*************************** 2. row ***************************
Id: 538888
User: shop_production
Host: localhost
db: shop_production
Command: Query
Time: 136
State: Sending data
Info: INSERT INTO `catalog_category_product_index_store1_tmp` (`category_id`, `product_id`, `position`, `i
Progress: 0.000
The Time spent goes higher and higher.
The production system is based on CloudLinux, uses CageFS and Plesk.
The MariaDB version in use is similar, but different.
This is the diff between the configurations:
https://gist.github.com/amenk/049480614ac7ff1daf6b6cadbbcdacaf
- How can this be debugged?
- Did anybody have such a problem before and it rings a bell?
EDIT
- mysql_upgrade -f shows no problems for the tables shop_production (but some in Plesk's )
Output of top during indexing:
top - 20:21:38 up 21 days, 2:36, 3 users, load average: 1,76, 1,19, 0,95
Tasks: 216 total, 1 running, 215 sleeping, 0 stopped, 0 zombie
%Cpu(s): 22,7 us, 1,0 sy, 0,1 ni, 76,1 id, 0,0 wa, 0,0 hi, 0,0 si, 0,0 st
KiB Mem : 15878512 total, 1608264 free, 5029540 used, 9240708 buff/cache
KiB Swap: 4095996 total, 4095996 free, 0 used. 8572156 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
3477819 mysql 20 0 3507868 813656 14688 S 168,8 5,1 4:27.35 mysqld
3478187 shop-fo+ 20 0 992172 180892 41912 S 18,6 1,1 0:19.42 php-fpm
3478175 shop-fo+ 20 0 907396 94840 38424 S 12,3 0,6 0:20.54 php-fpm
2438090 root 30 10 481408 38412 1220 S 0,7 0,2 56:29.47 python2.7
2438127 root 30 10 430592 59036 4380 S 0,7 0,4 49:54.24 python2.7
9 root 20 0 0 0 0 S 0,3 0,0 30:00.48 rcu_sched
584 root 20 0 0 0 0 S 0,3 0,0 5:07.81 jbd2/sda3-8
2438015 root 30 10 333944 39984 2832 S 0,3 0,3 22:22.89 python2.7
2912509 root 20 0 919048 20148 1612 S 0,3 0,1 24:55.24 containerd
3127797 nginx 20 0 67228 13084 2644 S 0,3 0,1 4:13.13 nginx
3127798 nginx 20 0 67584 13504 2640 S 0,3 0,1 2:39.75 nginx
3127799 nginx 20 0 78492 22100 2632 S 0,3 0,1 2:15.81 nginx
3373021 root 20 0 751756 26348 25416 S 0,3 0,2 0:10.24 rsyslogd
3474176 root 20 0 0 0 0 S 0,3 0,0 0:00.14 kworker/4:0
3478507 postfix 20 0 106288 5184 4096 S 0,3 0,0 0:00.01 plesk_saslauthd
1 root 20 0 191308 3808 2040 S 0,0 0,0 13:50.14 systemd
2 root 20 0 0 0 0 S 0,0 0,0 0:00.75 kthreadd
3 root 20 0 0 0 0 S 0,0 0,0 0:39.93 ksoftirqd/0
5 root 0 -20 0 0 0 S 0,0 0,0 0:00.00 kworker/0:0H
Output of mytop:
MySQL on localhost (10.3.18-MariaDB) up 0+00:05:45 [20:22:30]
Queries: 74.1k qps: 220 Slow: 0.0 Se/In/Up/De(%): 156/00/01/00
qps now: 197 Slow qps: 0.0 Threads: 8 ( 8/ 3) 165/01/00/00
Cache Hits: 46.5k Hits/s: 137.9 Hits now: 133.7 Ratio: 40.2% Ratio now: 41.2%
Key Efficiency: 99.7% Bps in/out: 361.6k/474.6k Now in/out: 501.3k/761.7k
Id User Host/IP DB Time Cmd Query or State
-- ---- ------- -- ---- --- ----------
1 system us 0 Daemon InnoDB purge coordinator
2 system us 0 Daemon InnoDB purge worker
3 system us 0 Daemon InnoDB purge worker
4 system us 0 Daemon InnoDB purge worker
5 system us 0 Daemon InnoDB shutdown handler
136 admin localhost shop_produ 0 Query show full processlist
186 shop_prod localhost shop_produ 0 Sleep
187 shop_prod localhost shop_produ 0 Sleep
188 shop_prod localhost shop_produ 0 Sleep
189 shop_prod localhost shop_produ 0 Sleep
275 shop_prod localhost shop_produ 0 Query INSERT INTO `search_tmp_5da75fe6204cb3_57318472` SELECT `main_select`.`entity_id`, SUM(score) AS `relevance` FROM (SELECT DISTINCT `search_index`.`entity_id`, (((0) + (0) +
153 admin localhost psa 148 Sleep
148 shop_prod localhost shop_produ 151 Query INSERT INTO `catalog_category_product_index_store2_tmp` (`category_id`, `product_id`, `position`, `is_parent`, `store_id`, `visibility`) SELECT 2 AS `category_id`, `cp`.`en
EDIT2
This is the query which is hanging.
INSERT INTO `catalog_category_product_index_store2_tmp` (`category_id`, `product_id`, `position`, `is_parent`, `store_id`, `visibility`) SELECT 2 AS `category_id`, `cp`.`entity_id` AS `product_id`, IF(ccp.product_id IS NOT NULL, ccp.position, 0) AS `position`, IF(ccp.product_id IS NOT NULL, 1, 0) AS `is_parent`, 2 AS `store_id`, IFNULL(cpvs.value, cpvd.value) AS `visibility` FROM `catalog_product_entity` AS `cp`
INNER JOIN `catalog_product_website` AS `cpw` ON cpw.product_id = cp.entity_id
INNER JOIN `catalog_product_entity_int` AS `cpsd` ON cpsd.entity_id = cp.entity_id AND cpsd.store_id = 0 AND cpsd.attribute_id = 97
LEFT JOIN `catalog_product_entity_int` AS `cpss` ON cpss.entity_id = cp.entity_id AND cpss.attribute_id = cpsd.attribute_id AND cpss.store_id = 2
INNER JOIN `catalog_product_entity_int` AS `cpvd` ON cpvd.entity_id = cp.entity_id AND cpvd.store_id = 0 AND cpvd.attribute_id = 99
LEFT JOIN `catalog_product_entity_int` AS `cpvs` ON cpvs.entity_id = cp.entity_id AND cpvs.attribute_id = cpvd.attribute_id AND cpvs.store_id = 2
LEFT JOIN `catalog_category_product` AS `ccp` ON ccp.product_id = cp.entity_id WHERE (cpw.website_id = '1') AND (IFNULL(cpss.value, cpsd.value) = 1) AND (IFNULL(cpvs.value, cpvd.value) IN (2, 3, 4)) AND (cp.entity_id IN ('107280', '107281', '107282', '107283', '107284', '107285', '107286', '107287', '107288', '107289', '107290', '107291', '107292', '107293', '107294', '107295', '107296', '107297', '107298', '107299', '107300', '107301', '107302', '107303', '107304', '107305',
[ ... around 700 Kilobyte of query in total ... ]
5', '187946', '187947', '187948', '187949', '187950', '187951', '187952', '187953', '187954', '187955', '187956', '187957', '187958', '187959', '187960', '187961', '187962', '187963', '187964', '187965', '187966')) GROUP BY `cp`.`entity_id` ON DUPLICATE KEY UPDATE `category_id` = VALUES(`category_id`), `product_id` = VALUES(`product_id`), `position` = VALUES(`position`), `is_parent` = VALUES(`is_parent`), `store_id` = VALUES(`store_id`), `visibility` = VALUES(`visibility`)
In the full query there are 73607 ",", so in the WHERE clause there are a bit less than 73600 values. I guess Magento is not very well prepared, that all products are in one category.
But still: It works locally, but not on the production server.
EDIT3 More debug Info
show global status\G;
show global variables\G;
show engine innodb status\G;
https://gist.github.com/amenk/424acf3567486f4f94cb3086e6bf3380
EDIT5 Version without \G:
https://gist.github.com/amenk/7d6a94536b28b4564a611e6adbdc1a3c
EDIT4
The problem can be reproduced locally by
- Starting MariaDB 10.3.18 in a docker container
- Importing the Prod database
- Reindexing
So it is related to that specific database version in combination with the massive queries Magento runs, that were running fine on previous versions.
Best Answer
@Alex In your value list of id's to be managed, the quotes are likely causing the processing to work harder than when you use simply the number to be managed as an INT data type. If you find this suggestion helpful, please consider upvote and accept.