Which server settings can cause Magento reindex to run really slow?

Question

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.

@alex Why are you already running 10.3.18 that just became GA on 9/11/2019? Many people would avoid new version for 6 calendar months to avoid the 'bug' reporting, wait for corrective action cycle for any production system. But since you are here, we can try to rescue your situation, if you will post additional information listed in previous comment. — Wilson Hauck, Commented Oct 17, 2019 at 19:41
@WilsonHauck More debug info added in EDIT3 above, SHOW CREATE TABLE Is not working ,because the table is temporary and seems to be inside a transaction. The 10.3.18 version is supplied by the hoster, that was not our choice. It currently looks like I might be able to reproduce it with that version locally. — Alex, Commented Oct 18, 2019 at 16:15
@WilsonHauck okay, here you go: gist.github.com/amenk/7d6a94536b28b4564a611e6adbdc1a3c — Alex, Commented Oct 19, 2019 at 7:22
It's 8 vCore, datastorage is currently unkown for me. It does not seem to be a hardware-dependent problem, as I can now reproduce locally where it worked with 10.1 but does not with 10.3. Unfortunately downgrading might not be so easy, but still easier than debugging this all to the bones :) SET GLOBAL innodb_buffer_pool_size to 8GB did not have a drastic effect (still takes more > 5 minutes, stopped the script then) — Alex, Commented Oct 19, 2019 at 15:49

Wilson Hauck · Accepted Answer · 2019-10-21 16:41:35Z

5

@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.

edited Oct 21, 2019 at 16:41

answered Oct 21, 2019 at 16:19

Wilson Hauck

3101 silver badge7 bronze badges

Add a comment |

Alex · Accepted Answer · 2019-10-21 14:53:30Z

And another Answer --- thanks to the Chat with Wilson Hauck:

He pointed out, that the quotes might confuse the new optimized in 10.3

I took the full query.sql from above and extracted only the select part:

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'
    [... around 70 K entity IDs ...]
    187965', '187966')) GROUP BY `cp`.`entity_id`;

This query alone runs 8 minutes on Maria DB 10.3.18

When I simply remove all the quotes via s/'//g in vi in the line with the "IN" statement I get

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
    [... around 70 K entity IDs ...]
    187965, 187966)) GROUP BY `cp`.`entity_id`;

The essentially same query runs in less than 3 seconds.

Gotcha!

Magento issue: https://github.com/magento/magento2/issues/25199 MariaDB issue: https://jira.mariadb.org/browse/MDEV-20871

Please let us know status from the Magento MDEV-20871 open issue in a week or so. It is not obvious looking at the issue details you went from 8 Minutes to 3 seconds for query completion. Please consider attributing the suggestion to our website. Thanks — Wilson Hauck, Commented Oct 22, 2019 at 15:32
Since this has been reported to MariaDB with MDEV-20871, they may or may not 'cover' this coding error of using quotes in the 'selection' IN list. Please consider reporting this discovery to Magento for their corrective action since it is their code that should not be using quoted IN values when their datatype is INT. Please report this discovery to Magento for their code correction to benefit their World Wide Base of customers with 3 second completion vs 8 minutes when dealing with 70,000 items in the catalog. 480 / 3 = 160 times faster completion of this query. — Wilson Hauck, Commented Oct 25, 2019 at 10:34
@Alex Could you please help me on this question. magento.stackexchange.com/questions/293336/… — Kirti Nariya, Commented Oct 31, 2019 at 5:39

sqlexception · Accepted Answer · 2019-10-18 20:29:51Z

2

I would suggest you to create a temporary Table. Only one Column, which is the category entity Id afterwards make an insert statement to insert all entity ids into this tmp table. Afterwards convert the way to big in condition into an Join.

answered Oct 18, 2019 at 20:29

sqlexception

311 bronze badge

Does that mean I have to patch the magento core?
– Alex
Commented Oct 19, 2019 at 6:41
1

Beware: This is standard Magento code -- we did not customize anything in this regards, only we have lots of products in the category. In MariaDB 10.1 it works pretty well though, just not in MariaDB 10.3
– Alex
Commented Oct 19, 2019 at 7:30
1

Yes patch or write a Plugin. Yes its standard Magento stuff. Bur magento declined mysql only optimations so they can switch the engines. I already made a pull request with optimations was declined with the argument this is a mysql only optimation.
– sqlexception
Commented Oct 19, 2019 at 10:02
Ah okay, we will consider that, if the hoster is not able to downgrade MariaDB to a supported version.
– Alex
Commented Oct 19, 2019 at 12:23
Okay if u need help, i poked you on twitter. Anyways it will be faster.
– sqlexception
Commented Oct 19, 2019 at 13:06

Add a comment |

Wilson Hauck · Accepted Answer · 2019-10-21 13:39:54Z

Rate per Second=RPS - Suggestions to consider for your MariaDB 10.3.18 instance my.cnf [mysqld] section

innodb_buffer_pool_size=8G  # from 512M to reduce innodb_buffer_pool_reads RPS of ~ 5
innodb_io_capacity=1900  # from 200 to enable higher IOPS to your data devices
read_buffer_size=256K  # from 128K to reduce handler_read_next RPS of 136,418
read_rnd_buffer_size=128K  # from 256K to recude handler_read_rnd_next RPS of 320,764

There are many more tuning opportunities to improve performance. After implementation + 24 hours, please post observation of better/worse from your client's perspective.

Alex · Accepted Answer · 2019-10-18 17:56:43Z

1

Partial answer - better debugging welcome.

Turns out that the issue is reproducible with MariaDB 10.3.18 locally as well.

According to DevDocs "Magento is also compatible with MySQL NDB Cluster 7.4.*, MariaDB 10.0, 10.1, 10.2, Percona 5.7, and other binary-compatible MySQL technologies."

This does not mention 10.3.x

answered Oct 18, 2019 at 17:56

Alex

13.9k19 gold badges83 silver badges163 bronze badges

Refer to this url mariadb.com/kb/en/library/changes-improvements-in-mariadb-103 for history of 10.3.nn versions (down a few pages). It is likely Magento has not had time to validate 10.3.nn due to recent availability.
– Wilson Hauck
Commented Oct 19, 2019 at 14:11

Add a comment |

Stack Exchange Network

Which server settings can cause Magento reindex to run really slow?

5 Answers 5

Your Answer

Not the answer you're looking for? Browse other questions tagged
reindex
magento2.3.2
debugging
or ask your own question.

Linked

Hot Network Questions

Which server settings can cause Magento reindex to run really slow?

5 Answers 5

Your Answer

Sign up or log in

Post as a guest

Not the answer you're looking for? Browse other questions tagged reindexmagento2.3.2debugging or ask your own question.

Linked

Related

Hot Network Questions

Not the answer you're looking for? Browse other questions tagged
reindex
magento2.3.2
debugging
or ask your own question.