Closed ioweb-gr closed 6 months ago
Hi @ioweb-gr. Thank you for your report. To speed up processing of this issue, make sure that you provided the following information:
Make sure that the issue is reproducible on the vanilla Magento instance following Steps to reproduce. To deploy vanilla Magento instance on our environment, Add a comment to the issue:
@magento give me 2.4-develop instance
- upcoming 2.4.x release
For more details, review the Magento Contributor Assistant documentation.
Add a comment to assign the issue: @magento I am working on this
To learn more about issue processing workflow, refer to the Code Contributions.
Join Magento Community Engineering Slack and ask your questions in #github channel.
:warning: According to the Magento Contribution requirements, all issues must go through the Community Contributions Triage process. Community Contributions Triage is a public meeting.
:clock10: You can find the schedule on the Magento Community Calendar page.
:telephone_receiver: The triage of issues happens in the queue order. If you want to speed up the delivery of your contribution, join the Community Contributions Triage session to discuss the appropriate ticket.
:pencil2: Feel free to post questions/proposals/feedback related to the Community Contributions Triage process to the corresponding Slack Channel
There might be a dead lock created. Use flock to separate your index thread for cron.
Hi @engcom-Dash. Thank you for working on this issue. In order to make sure that issue has enough information and ready for development, please read and check the following instruction: :point_down:
Issue: Format is valid
will be added to the issue automatically. Please, edit issue description if needed, until label Issue: Format is valid
appears.Issue: Clear Description
label to the issue by yourself.Component: XXXXX
label(s) to the ticket, indicating the components it may be related to.2.4-develop
branch@magento give me 2.4-develop instance
to deploy test instance on Magento infrastructure. 2.4-develop
branch, please, add the label Reproduced on 2.4.x
.Hi @ioweb-gr ,
We are trying to reproduce the issue in 2.4.4 magento instance...But We are not able to reproduce the issue. As per description we created 800 categories cart price rules,150k products,5 websites everything. While doing the reindexing process it will take long time..But it will not affect side down.The site is still working. Screenshots for your reference:
Let us know if we missing anything!!! Thanks!!!
Hi, it's not like it's dropping constantly when reindexing. The problem is that we get this situation randomly while the site is under normal load 40-60 users. I think @Adel-Magebinary may be right about this one and the original issue is the same as mine.
I experimented with changing the lock-mechanism from DB to File as a test, and the load average on the server decreased significantly (it was averaging at 9-14) and now it's constantly on 2-4.
I'm waiting a bit to see if the issue reoccurs with the file lock mechanism and if it does I'll experiment with flock as it was suggested in the thread.
It's entirely possible the cause is that same issue #25987
Let's put this issue on hold until I can verify this behavior has changed by changing the lock mechanism.
Hi @ioweb-gr ,
We are closing this issue as there has been no latest update on the same. Kindly reopen / create new issue if you are still facing any issues. Thank you.
HI @engcom-Dash I was trying to figure out what else might be the difference between our systems, in my case I have the indexers set to schedule mode.
Today I tried to reset the following indexers
inventory
cataloginventory_stock
Which in turn tried to trigger a reindex of
catalog_product_price
After doing this, I got the same picture as above. This doesn't seem to be a concurrency issue or a lock issue
Would you be willing to retry it once with the indexers set in scheduled mode?
Hi @ioweb-gr ,
Thanks for your Information... Verified the issue in 2.4-develop instance...The issue is not reproducible. As per your instructions we tried to reset the below indexers 1.inventory
But we got expected result as " The site is still working and queries are much faster and won't bring the site down."
Thanks.
This is a weekly occurence for us but I still need any ideas you can throw on how to reproduce the issue in a stable manner
Hi @Adel-Magebinary , @ilnytskyi , @Nuranto , @hostep ,
cc: @ioweb-gr ,
Thank you all for your kind cooperation, I am writing a request to all of you that here we are trying to reproduce the issue,But as neither reporter nor i am able to reproduce the issue. Hence a humble request to all of you, Kindly help as here to reproduce the issue.
Thanks.
Hi @engcom-Dash,
I'm not sure why I'm pinged here. However, that makes me think of an issue of mine : https://github.com/magento/magento2/issues/35685
As you can see in mview.xml
:
<view id="catalog_product_price" class="Magento\Catalog\Model\Indexer\Product\Price" group="indexer">
<subscriptions>
<table name="catalog_product_entity" entity_column="entity_id" />
<table name="catalog_product_entity_datetime" entity_column="entity_id" />
<table name="catalog_product_entity_decimal" entity_column="entity_id" />
<table name="catalog_product_entity_int" entity_column="entity_id" />
<table name="catalog_product_entity_tier_price" entity_column="entity_id" />
<table name="catalog_product_link" entity_column="product_id" />
</subscriptions>
</view>
Price index gets reindexed each time a product is updated. So if we update the color, the manufacturer or any int/decimal/date/static attribute, the price gets reindexed. On website with high amounts of product data writing, that could produce a huge quantity of useless reindex sql requests.
Hope it'll help.
This could be spot on, because we have a data entries of 1000 products a day. We also mass update cost prices, discounts and some visual attributes that refer to sales and discount classes and url keys. It's possible we may have 15000 - 30000 product updates per day. Also we also have multiple websites with different currencies and exchange rates as well as different prices per website.
Today we faced this after deleting a bunch of SKUs from the website
I'm not sure what we can do to reproduce this on a clean instance, as it seems to be data dependent in the sense that it's needed to cause the system to overload. There are 22 catalog product price rules, over 1000 categories, over 100k products, over 10 customer groups, and constant data entry and mass updates of data. And even so, it occurs randomly through the day, in different working hours, in different days, there's literally no way to pinpoint the source.
Moreover all those queries are created by the default price indexers.
How did you delete the products? Can you please create a console script by using product collections to delete 2000 random products to see if this triggers? Then you can just post the console script here.
That would probably require to create 2000 test products first on the site to delete them and its a production site. I'll see if I can arrange such a test
Just another piece of info here are the tables which are locked during the drop
MariaDB [(none)]> SHOW OPEN TABLES WHERE In_use > 0;
+-----------------+----------------------------------------+--------+-------------+
| Database | Table | In_use | Name_locked |
+-----------------+----------------------------------------+--------+-------------+
| db_example___ | inventory_stock_5 | 11 | 0 |
| db_example___ | catalog_product_link_attribute_decimal | 3 | 0 |
| db_example___ | inventory_stock_9 | 2 | 0 |
| db_example___ | catalog_category_product_index_store5 | 3 | 0 |
| db_example___ | inventory_stock_7 | 5 | 0 |
| db_example___ | catalog_product_website | 1 | 0 |
| db_example___ | catalog_product_index_price | 3 | 0 |
| db_example___ | catalog_product_relation | 96 | 0 |
| db_example___ | catalog_compare_item | 2 | 0 |
| db_example___ | catalog_product_entity | 333 | 0 |
| db_example___ | catalog_product_link | 3 | 0 |
| db_example___ | catalog_product_link_attribute_int | 3 | 0 |
| db_example___ | catalog_product_entity_int | 50 | 0 |
+-----------------+----------------------------------------+--------+-------------+
What I've noticed in common in all times the website stopped responding is that above the Rename Table query there's always a query like this
SELECT `e`.*,
`price_index`.`price`,
`price_index`.`tax_class_id`,
`price_index`.`final_price`,
IF(price_index.tier_price IS NOT NULL, LEAST(price_index.min_price, price_index.tier_price),
price_index.min_price) AS `minimal_price`,
`price_index`.`min_price`,
`price_index`.`max_price`,
`price_index`.`tier_price`,
`cat_index`.`position` AS `cat_index_position`,
`stock_status_index`.`is_salable`,
`links`.`link_id`,
`links`.`product_id` AS `_linked_to_product_id`,
`link_attribute_position_int`.`value` AS `position`,
`link_attribute_qty_decimal`.`value` AS `qty`
FROM `catalog_product_entity` AS `e`
INNER JOIN `inventory_stock_5` AS `inventory_in_stock` ON e.sku = inventory_in_stock.sku
INNER JOIN `catalog_product_index_price_ws2` AS `price_index`
ON price_index.entity_id = e.entity_id AND price_index.customer_group_id = 0 AND
price_index.website_id = '2'
INNER JOIN `catalog_category_product_index_store5` AS `cat_index`
ON cat_index.product_id = e.entity_id AND cat_index.store_id = 5 AND
cat_index.visibility IN (2, 4) AND cat_index.category_id = 2
INNER JOIN `catalog_product_entity` AS `product` ON product.entity_id = e.entity_id
INNER JOIN `inventory_stock_5` AS `stock_status_index` ON product.sku = stock_status_index.sku
INNER JOIN `catalog_product_link` AS `links`
ON links.linked_product_id = e.entity_id AND links.link_type_id = 1
LEFT JOIN `catalog_product_link_attribute_int` AS `link_attribute_position_int`
ON link_attribute_position_int.link_id = links.link_id AND
link_attribute_position_int.product_link_attribute_id = '2'
LEFT JOIN `catalog_product_link_attribute_decimal` AS `link_attribute_qty_decimal`
ON link_attribute_qty_decimal.link_id = links.link_id AND
link_attribute_qty_decimal.product_link_attribute_id = '6'
INNER JOIN `catalog_product_entity` AS `product_entity_table`
ON links.product_id = product_entity_table.entity_id
WHERE (inventory_in_stock.is_salable = 1)
AND (stock_status_index.is_salable = 1)
AND (links.product_id in ('154028'))
AND (`e`.`entity_id` != '154028')
ORDER BY `position` ASC
Which is taking long to execute for no apparent reason. If I kill this query execution, everything starts executing fast enough.
The weird thing is that if I retry the query later on, it executes lightning fast, in less than 100ms.
I don't understand why killing this query makes all other queries progress fast and I'm not sure why a select query would lock the database like this
It's possibly coming from \Magento\Catalog\Model\ResourceModel\Product\Collection::_productLimitationPrice
This is happening because there is another thread in MySQL is writing to one of these tables in the query. We call it "update while select". The issue is not select query. The issue is "write" queries.
Try adding the below to your env.php, which reduces the batch size while indexing. It might fix your issues. Make sure your cron job pick this up too.
'indexer' => [
'batch_size' => [
'cataloginventory_stock' => [
'simple' => 200
],
'catalog_category_product' => 666,
'catalogsearch_fulltext' => [
'partial_reindex' => 100,
'mysql_get' => 500,
'elastic_save' => 500
],
'catalog_product_price' => [
'simple' => 200,
'default' => 500,
'configurable' => 666
],
'catalogpermissions_category' => 999,
'inventory' => [
'simple' => 210,
'default' => 510,
'configurable' => 616
]
]
],
I've already experimented with
cataloginventory_stock catalog_category_product catalog_product_price catalogsearch_fulltext
Even reaching 20 items per batch and saw this still occurring :(
There must be something locking the tables and writing in them. Can you post your MySQL config here? Are you using MSI?
Yeah of course. I'm using MSI
Here's the output of show variables mariadb_config.txt
OK today it just replicated in an easy manner for me.
I made changes into 20 catalog rules that affect the product prices to include a new website in their effect scope.
As soon as we did that and reindexing started, I got into this situation
Killing the top 3 queries in the screenshot, let all the rest run again.
So the problem appears to come up when queries are inserting into the tables that are going to be renamed and creating deadlocks. Is it possible it's a conflict between the partial reindexing and the full reindex processes?
This is really similar to the issues that we had. After we applied flock in cron for each cron group, it went away. This is definitely "select on insert". Try changing the tmp table to memory in mysql.
Try adding the following to your mysql.cnf
innodb_autoinc_lock_mode=2
internal_tmp_mem_storage_engine=MEMORY
innodb_flush_log_at_trx_commit=2
transaction_isolation="READ-COMMITTED"
@Adel-Magebinary Thank you very much for trying to help. Perhaps I did something wrong in the flock separation of groups. For example for each group I added a definition like this
*/10 * * * * flock -n /tmp/amasty_base.lockfile /opt/plesk/php/7.4/bin/php -f 'httpdocs/bin/magento' -- 'cron:run' --group=amasty_base > /dev/null
This ended up spawning a bunch of lock files in the /tmp directory and my cron history shows cron jobs are being processed successfully. e.g.
Times shown in Europe/Athens
+------------------------------------------------------------+---------+---------------------+
| Job | Status | Finished |
+------------------------------------------------------------+---------+---------------------+
| indexer_reindex_all_invalid | success | 2023-07-05 15:40:37 |
However I didn't see that saving the situation.
Regarding your configs I'm not sure if our free memory will suffice we operate at like 94/128GB with our current traffic and I have concerns about innodb_flush_log_at_trx_commit=2. In the past I've dealt with database corruption due to this settings because the OS had it cached but then suffered a kernel panic which left things broken bad.
This innodb_autoinc_lock_mode=2 looks interesting as we face slowness generating increment ids. Not sure what transaction_isolation="READ-COMMITTED" does.
After using flock I got this
So as before I'm in the same situation. It did recover a bit faster, but still in the same state with one never-ending select
I'll try and experiment with the settings you provided to see if it mitigates the situation. However this issue shouldn't happen in the first place from the core. How can I determine which cron jobs / indexers are at fault here to prevent it?
In the end in the cron.log it's constantly this cron job timing out due to waiting on a lock. These are just examples it's always some RENAME query crashing.
[2023-07-05 04:10:23] main.ERROR: Cron Job indexer_update_all_views has an error: SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction, query was: TRUNCATE TABLE `catalog_category_product_index_store1_replica`. Statistics: {"sum":0,"count":1,"realmem":0,"emalloc":0,"realmem_start":115343360,"emalloc_start":34652360} [] []
and this one
[2023-07-05 08:39:52] main.ERROR: Cron Job indexer_reindex_all_invalid has an error: SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction, query was: RENAME TABLE catalog_product_index_price TO catalog_product_index_price_outdated,catalog_product_index_price_replica TO catalog_product_index_price,catalog_product_index_price_outdated TO catalog_product_index_price_replica. Statistics: {"sum":0,"count":1,"realmem":0,"emalloc":0,"realmem_start":115343360,"emalloc_start":34211560} [] []
Ι'll add some extra information.
Currently it shows that two queries are executing for a prolonged period
SELECT `e`.*, `price_index`.`price`, `price_index`.`tax_class_id`, `price_index`.`final_price`, IF(price_index.tier_price IS NOT NULL, LEAST(price_index.min_price, price_index.tier_price), price_index.min_price) AS `minimal_price`, `price_index`.`min_price`, `price_index`.`max_price`, `price_index`.`tier_price`, `cat_index`.`position` AS `cat_index_position`, `stock_status_index`.`is_salable`, `links`.`link_id`, `links`.`product_id` AS `_linked_to_product_id`, `link_attribute_position_int`.`value` AS `position`, `link_attribute_qty_decimal`.`value` AS `qty` FROM `catalog_product_entity` AS `e` INNER JOIN `inventory_stock_5` AS `inventory_in_stock` ON e.sku = inventory_in_stock.sku INNER JOIN `catalog_product_index_price` AS `price_index` ON price_index.entity_id = e.entity_id AND price_index.customer_group_id = 0 AND price_index.website_id = '2' INNER JOIN `catalog_category_product_index_store5` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=5 AND cat_index.visibility IN(2, 4) AND cat_index.category_id=2 INNER JOIN `catalog_product_entity` AS `product` ON product.entity_id = e.entity_id INNER JOIN `inventory_stock_5` AS `stock_status_index` ON product.sku = stock_status_index.sku INNER JOIN `catalog_product_link` AS `links` ON links.linked_product_id = e.entity_id AND links.link_type_id = 1 LEFT JOIN `catalog_product_link_attribute_int` AS `link_attribute_position_int` ON link_attribute_position_int.link_id = links.link_id AND link_attribute_position_int.product_link_attribute_id = '2' LEFT JOIN `catalog_product_link_attribute_decimal` AS `link_attribute_qty_decimal` ON link_attribute_qty_decimal.link_id = links.link_id AND link_attribute_qty_decimal.product_link_attribute_id = '6' INNER JOIN `catalog_product_entity` AS `product_entity_table` ON links.product_id = product_entity_table.entity_id WHERE (inventory_in_stock.is_salable = 1) AND (stock_status_index.is_salable = 1) AND (links.product_id in ('158898')) AND (`e`.`entity_id` != '158898') ORDER BY `position` ASC
SELECT `e`.*, `price_index`.`price`, `price_index`.`tax_class_id`, `price_index`.`final_price`, IF(price_index.tier_price IS NOT NULL, LEAST(price_index.min_price, price_index.tier_price), price_index.min_price) AS `minimal_price`, `price_index`.`min_price`, `price_index`.`max_price`, `price_index`.`tier_price`, `cat_index`.`position` AS `cat_index_position`, `stock_status_index`.`is_salable`, `links`.`link_id`, `links`.`product_id` AS `_linked_to_product_id`, `link_attribute_position_int`.`value` AS `position`, `link_attribute_qty_decimal`.`value` AS `qty` FROM `catalog_product_entity` AS `e` INNER JOIN `inventory_stock_5` AS `inventory_in_stock` ON e.sku = inventory_in_stock.sku INNER JOIN `catalog_product_index_price` AS `price_index` ON price_index.entity_id = e.entity_id AND price_index.customer_group_id = 0 AND price_index.website_id = '2' INNER JOIN `catalog_category_product_index_store5` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=5 AND cat_index.visibility IN(2, 4) AND cat_index.category_id=2 INNER JOIN `catalog_product_entity` AS `product` ON product.entity_id = e.entity_id INNER JOIN `inventory_stock_5` AS `stock_status_index` ON product.sku = stock_status_index.sku INNER JOIN `catalog_product_link` AS `links` ON links.linked_product_id = e.entity_id AND links.link_type_id = 1 LEFT JOIN `catalog_product_link_attribute_int` AS `link_attribute_position_int` ON link_attribute_position_int.link_id = links.link_id AND link_attribute_position_int.product_link_attribute_id = '2' LEFT JOIN `catalog_product_link_attribute_decimal` AS `link_attribute_qty_decimal` ON link_attribute_qty_decimal.link_id = links.link_id AND link_attribute_qty_decimal.product_link_attribute_id = '6' INNER JOIN `catalog_product_entity` AS `product_entity_table` ON links.product_id = product_entity_table.entity_id WHERE (inventory_in_stock.is_salable = 1) AND (stock_status_index.is_salable = 1) AND (links.product_id in ('154958')) AND (`e`.`entity_id` != '154958') ORDER BY `position` ASC
There doesn't seem to be a database lock currently
| InnoDB | |
=====================================
2023-07-06 11:02:41 0x7fef4d074700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 24 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 24347 srv_active, 0 srv_shutdown, 8847 srv_idle
srv_master_thread log flush and writes: 33193
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 16886491
OS WAIT ARRAY INFO: signal count 40586870
RW-shared spins 92106908, rounds 281998222, OS waits 5213540
RW-excl spins 45936899, rounds 205260401, OS waits 3412521
RW-sx spins 9359123, rounds 275438314, OS waits 8071513
Spin rounds per wait: 3.06 RW-shared, 4.47 RW-excl, 29.43 RW-sx
------------
TRANSACTIONS
------------
Trx id counter 1772230899
Purge done for trx's n:o < 1772180308 undo n:o < 0 state: running but idle
History list length 20289
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 422176365707528, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 422176365711744, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 422176365703312, ACTIVE 0 sec starting index read
mysql tables in use 3, locked 0
0 lock struct(s), heap size 1128, 0 row lock(s)
MySQL thread id 74906, OS thread handle 140665393481472, query id 134164457 localhost 127.0.0.1 db_live Sending data
SELECT `cpe`.`entity_id`, inventory_stock.quantity+IF(ISNULL(SUM(ir.quantity)),0,SUM(ir.quantity)) AS quantity, MAX(is_salable) as is_salable FROM `inventory_stock_7` AS `inventory_stock`
LEFT JOIN `inventory_reservation` AS `ir` ON ir.sku = inventory_stock.sku
LEFT JOIN `catalog_product_entity` AS `cpe` ON inventory_stock.sku = cpe.sku GROUP BY `cpe`.`entity_id`
Trx read view will not see trx with id >= 1772230895, sees < 1772230895
---TRANSACTION 422176365774984, ACTIVE 0 sec fetching rows
mysql tables in use 17, locked 17
264 lock struct(s), heap size 57464, 6041 row lock(s)
MySQL thread id 74251, OS thread handle 140666153232128, query id 134164580 localhost 127.0.0.1 db_live Sending data
INSERT INTO `catalog_category_product_index_store7_tmp` (`category_id`, `product_id`, `position`, `is_parent`, `store_id`, `visibility`) SELECT `cc`.`entity_id` AS `category_id`, `ccp`.`product_id`, IFNULL(ccp2.position, ccp.position + 10000) AS `position`, 0 AS `is_parent`, 7 AS `store_id`, IFNULL(cpvs.value, cpvd.value) AS `visibility` FROM `catalog_category_entity` AS `cc`
INNER JOIN `temp_catalog_category_tree_index_c1453bad` AS `cc2` ON cc2.parent_id = cc.entity_id AND cc.entity_id NOT IN (1)
INNER JOIN `catalog_category_product` AS `ccp` ON ccp.category_id = cc2.child_id
LEFT JOIN `ca
---TRANSACTION 422176365745472, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 422176365749688, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 422176365715960, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 422176366040592, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 422176365990000, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 422176365732824, ACTIVE 1338 sec starting index read
mysql tables in use 10, locked 0
0 lock struct(s), heap size 1128, 0 row lock(s)
MySQL thread id 69614, OS thread handle 140665391331072, query id 128136000 localhost 127.0.0.1 db_live Sending data
SELECT `e`.*, `price_index`.`price`, `price_index`.`tax_class_id`, `price_index`.`final_price`, IF(price_index.tier_price IS NOT NULL, LEAST(price_index.min_price, price_index.tier_price), price_index.min_price) AS `minimal_price`, `price_index`.`min_price`, `price_index`.`max_price`, `price_index`.`tier_price`, `cat_index`.`position` AS `cat_index_position`, `stock_status_index`.`is_salable`, `links`.`link_id`, `links`.`product_id` AS `_linked_to_product_id`, `link_attribute_position_int`.`value` AS `position`, `link_attribute_qty_decimal`.`value` AS `qty` FROM `catalog_product_entity` AS `e`
Trx read view will not see trx with id >= 1772180307, sees < 1772180307
---TRANSACTION 422176365724392, ACTIVE 1338 sec
mysql tables in use 10, locked 0
0 lock struct(s), heap size 1128, 0 row lock(s)
MySQL thread id 69607, OS thread handle 140665752717056, query id 128135089 localhost 127.0.0.1 db_live Sending data
SELECT `e`.*, `price_index`.`price`, `price_index`.`tax_class_id`, `price_index`.`final_price`, IF(price_index.tier_price IS NOT NULL, LEAST(price_index.min_price, price_index.tier_price), price_index.min_price) AS `minimal_price`, `price_index`.`min_price`, `price_index`.`max_price`, `price_index`.`tier_price`, `cat_index`.`position` AS `cat_index_position`, `stock_status_index`.`is_salable`, `links`.`link_id`, `links`.`product_id` AS `_linked_to_product_id`, `link_attribute_position_int`.`value` AS `position`, `link_attribute_qty_decimal`.`value` AS `qty` FROM `catalog_product_entity` AS `e`
Trx read view will not see trx with id >= 1772180307, sees < 1772180307
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
1667776 OS file reads, 9939666 OS file writes, 1470789 OS fsyncs
0.08 reads/s, 16384 avg bytes/read, 126.08 writes/s, 32.42 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 609294, seg size 609296, 7555 merges
merged operations:
insert 56518, delete mark 104706, delete 28855
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 8850487, node heap has 30509 buffer(s)
Hash table size 8850487, node heap has 52908 buffer(s)
Hash table size 8850487, node heap has 33460 buffer(s)
Hash table size 8850487, node heap has 16647 buffer(s)
Hash table size 8850487, node heap has 42176 buffer(s)
Hash table size 8850487, node heap has 49675 buffer(s)
Hash table size 8850487, node heap has 28265 buffer(s)
Hash table size 8850487, node heap has 34932 buffer(s)
2132837.05 hash searches/s, 363533.85 non-hash searches/s
---
LOG
---
Log sequence number 29949846571266
Log flushed up to 29949846571266
Pages flushed up to 29949832920413
Last checkpoint at 29949829760229
0 pending log flushes, 0 pending chkp writes
1204214 log i/o's done, 23.67 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 34368126976
Dictionary memory allocated 5858440
Buffer pool size 2054912
Free buffers 1000
Database pages 1765337
Old database pages 651637
Modified db pages 1691
Percent of dirty pages(LRU & free pages): 0.096
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 212082, not young 21165531
0.21 youngs/s, 2.83 non-youngs/s
Pages read 1665282, created 1089907, written 8589572
0.08 reads/s, 28.58 creates/s, 100.54 writes/s
Buffer pool hit rate 999 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1765337, unzip_LRU len: 0
I/O sum[5194]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
3 read views open inside InnoDB
Process ID=2893801, Main thread ID=140666312111872, state: sleeping
Number of rows inserted 164363494, updated 15842852, deleted 69133279, read 72104189322
7347.82 inserts/s, 375.28 updates/s, 3796.01 deletes/s, 3865928.96 reads/s
Number of system rows inserted 0, updated 0, deleted 0, read 0
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
Moreover if I execute the same queries at the same period the same queries they will take around 90ms to finish. While those are still hanging there and I notice it says 0 locks in the status report for those queries unless I'm reading something wrong
mysql tables in use 10, locked 0
0 lock struct(s), heap size 1128, 0 row lock(s)
MySQL thread id 69614, OS thread handle 140665391331072, query id 128136000 localhost 127.0.0.1 db_live Sending data
SELECT `e`.*, `price_index`.`price`, `price_index`.`tax_class_id`, `price_index`.`final_price`, IF(price_index.tier_price IS NOT NULL, LEAST(price_index.min_price, price_index.tier_price), price_index.min_price) AS `minimal_price`, `price_index`.`min_price`, `price_index`.`max_price`, `price_index`.`tier_price`, `cat_index`.`position` AS `cat_index_position`, `stock_status_index`.`is_salable`, `links`.`link_id`, `links`.`product_id` AS `_linked_to_product_id`, `link_attribute_position_int`.`value` AS `position`, `link_attribute_qty_decimal`.`value` AS `qty` FROM `catalog_product_entity` AS `e`
Trx read view will not see trx with id >= 1772180307, sees < 1772180307
---TRANSACTION 422176365724392, ACTIVE 1338 sec
mysql tables in use 10, locked 0
0 lock struct(s), heap size 1128, 0 row lock(s)
MySQL thread id 69607, OS thread handle 140665752717056, query id 128135089 localhost 127.0.0.1 db_live Sending data
SELECT `e`.*, `price_index`.`price`, `price_index`.`tax_class_id`, `price_index`.`final_price`, IF(price_index.tier_price IS NOT NULL, LEAST(price_index.min_price, price_index.tier_price), price_index.min_price) AS `minimal_price`, `price_index`.`min_price`, `price_index`.`max_price`, `price_index`.`tier_price`, `cat_index`.`position` AS `cat_index_position`, `stock_status_index`.`is_salable`, `links`.`link_id`, `links`.`product_id` AS `_linked_to_product_id`, `link_attribute_position_int`.`value` AS `position`, `link_attribute_qty_decimal`.`value` AS `qty` FROM `catalog_product_entity` AS `e`
Trx read view will not see trx with id >= 1772180307, sees < 1772180307
This looks really strange. What could be causing this delay?
Also I forgot to mention I'm on MariaDB so internal_tmp_mem_storage_engine=MEMORY
is invalid, the server wont' start if I add it.
Did you add transaction_isolation="READ-COMMITTED"?
@ioweb-gr did you fix it?
Unfortunately not, this is a sales period so we weren't able to change the database settings yet due to possible risks.
We'll do it a bit later when sales are off and assess if it helps with the situation :(
You can still apply transaction_isolation via the mysql command line to set the global variable. Have a read.
Same deal after changing to READ-COMMITED and using flock and all suggestions so far.
MariaDB [(none)]> show global variables like 'tx_iso%';
+---------------+----------------+
| Variable_name | Value |
+---------------+----------------+
| tx_isolation | READ-COMMITTED |
+---------------+----------------+
1 row in set (0.004 sec)
um....
Try setting the following too. It's definitely the MySQL thread got locked up while selecting when other threads are inserting.
innodb_autoinc_lock_mode=2 innodb_flush_log_at_trx_commit=2
I'm really concerned about those two just going through the documentation. Have you used them before? Were they safe?
An operating system crash could be really dangerous in such cases, we've had this in the past in other projects which left our DB entirely broken due to a Kernel Panic due to problematic memory module.
isn't that also dangerous to set?
Currently our server is using binlog format -> MIXED
+-----------------------------------------+----------------------+
| Variable_name | Value |
+-----------------------------------------+----------------------+
| binlog_annotate_row_events | ON |
| binlog_cache_size | 32768 |
| binlog_checksum | CRC32 |
| binlog_commit_wait_count | 0 |
| binlog_commit_wait_usec | 100000 |
| binlog_direct_non_transactional_updates | OFF |
| binlog_file_cache_size | 16384 |
| binlog_format | MIXED |
| binlog_optimize_thread_scheduling | ON |
| binlog_row_image | FULL |
| binlog_stmt_cache_size | 32768 |
| encrypt_binlog | OFF |
| gtid_binlog_pos | |
| gtid_binlog_state | |
| innodb_locks_unsafe_for_binlog | OFF |
| max_binlog_cache_size | 18446744073709547520 |
| max_binlog_size | 1073741824 |
| max_binlog_stmt_cache_size | 18446744073709547520 |
| read_binlog_speed_limit | 0 |
| sync_binlog | 0 |
| wsrep_forced_binlog_format | NONE |
The docs mention that for statement based it's dangerous, and mixed is actually also using statement based binlog intermixed with row based.
Interleaved Lock Mode
When [innodb_autoinc_lock_mode](https://mariadb.com/kb/en/innodb-system-variables/#innodb_autoinc_lock_mode) is set to 2, [InnoDB](https://mariadb.com/kb/en/innodb/) uses the interleaved lock mode.
In this mode, [InnoDB](https://mariadb.com/kb/en/innodb/) does not hold any table-level locks at all. This is the fastest and most scalable mode, but is not safe for [statement-based](https://mariadb.com/kb/en/binary-log-formats/#statement-based) replication.
I managed to grab a full process list during the issue
The only insert or update in the process list is this one
Does it help to detect the queries that cause the deadlock state?
I also saw this in show engine innodb status
------------------------
LATEST DETECTED DEADLOCK
------------------------
2023-08-26 06:42:16 0x7f0c1c36c700
*** (1) TRANSACTION:
TRANSACTION 421201532944528, ACTIVE 0 sec starting index read
mysql tables in use 13, locked 13
LOCK WAIT 58 lock struct(s), heap size 8312, 228 row lock(s)
MySQL thread id 386416, OS thread handle 139690001667840, query id 514670795 localhost 127.0.0.1 db_edomainnlive Sending data
INSERT INTO `catalog_category_product_index_store10_tmp` (`category_id`, `product_id`, `position`, `is_parent`, `store_id`, `visibility`) SELECT `cc`.`entity_id` AS `category_id`, `ccp`.`product_id`, `ccp`.`position`, 1 AS `is_parent`, 10 AS `store_id`, IFNULL(cpvs.value, cpvd.value) AS `visibility` FROM `catalog_category_entity` AS `cc`
INNER JOIN `catalog_category_product` AS `ccp` ON ccp.category_id = cc.entity_id
INNER JOIN `catalog_product_website` AS `cpw` ON cpw.product_id = ccp.product_id
INNER JOIN `catalog_product_entity` AS `cpe` ON ccp.product_id = cpe.entity_id
INNER JOIN `catalog_product_entity_int` AS `cpsd` ON cpsd.entity_id = cpe.entity_id AND cpsd.store_id = 0 AND cpsd.attribute_id = 84
LEFT JOIN `catalog_product_entity_int` AS `cpss` ON cpss.entity_id = cpe.entity_id AND cpss.attribute_id = cpsd.attribute_id AND cpss.store_id = 10
INNER JOIN `catalog_product_e
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 4665 page no 12 n bits 304 index PRIMARY of table `db_edomainnlive`.`catalog_category_entity` trx id 421201532944528 lock mode S locks rec but not gap waiting
Record lock, heap no 167 PHYSICAL RECORD: n_fields 12; compact format; info bits 0
0: len 4; hex 000004fd; asc ;;
1: len 6; hex 000072e0da58; asc r X;;
2: len 7; hex 18000840071e83; asc @ ;;
3: len 2; hex 0003; asc ;;
4: len 4; hex 000004fb; asc ;;
5: len 4; hex 64ad2e8c; asc d . ;;
6: len 4; hex 64e982a7; asc d ;;
7: len 18; hex 312f322f313237342f313237352f31323737; asc 1/2/1274/1275/1277;;
8: len 4; hex 80000002; asc ;;
9: len 4; hex 80000004; asc ;;
10: len 4; hex 80000000; asc ;;
11: len 4; hex 000021c5; asc ! ;;
*** (2) TRANSACTION:
TRANSACTION 1927338584, ACTIVE 1 sec starting index read
mysql tables in use 5, locked 5
26 lock struct(s), heap size 3488, 638 row lock(s), undo log entries 1581
MySQL thread id 389699, OS thread handle 139689989687040, query id 514670985 localhost 127.0.0.1 db_edomainnlive Starting cleanup
UPDATE `catalog_category_product` SET `position` = position + (-1) WHERE (category_id = 1277) AND (product_id IN (111510, 111520, 111525, 111641, 111642, 111649, 111660, 111667, 111684, 111697, 111698, 111705, 111712, 111728, 111733, 111739, 111746, 111753, 111760, 111793, 111800, 111807, 111814, 111821, 111828, 111854, 111869, 111875, 111886, 111892, 111909, 111917, 111932, 111938, 111989, 112025, 112032, 112038, 112043, 112049, 112055, 112062, 112069, 112182, 112188, 112256, 112261, 112267, 112422, 112675, 112683, 112690, 112697, 112765, 112781, 112872, 112897, 112903, 112931, 113034, 113067, 113187, 113195, 113231, 113296, 113302, 113309, 113335, 113426, 113440, 113550, 113566, 113605, 113670, 113677, 113768, 113775, 113782, 113863, 114091, 114099, 114108, 114116, 114124, 114159, 114200, 114207, 114225, 114269, 114310, 114314, 114344, 114349, 114364, 114419, 114422, 114448, 114
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 4665 page no 12 n bits 304 index PRIMARY of table `db_edomainnlive`.`catalog_category_entity` trx id 1927338584 lock_mode X locks rec but not gap
Record lock, heap no 167 PHYSICAL RECORD: n_fields 12; compact format; info bits 0
0: len 4; hex 000004fd; asc ;;
1: len 6; hex 000072e0da58; asc r X;;
2: len 7; hex 18000840071e83; asc @ ;;
3: len 2; hex 0003; asc ;;
4: len 4; hex 000004fb; asc ;;
5: len 4; hex 64ad2e8c; asc d . ;;
6: len 4; hex 64e982a7; asc d ;;
7: len 18; hex 312f322f313237342f313237352f31323737; asc 1/2/1274/1275/1277;;
8: len 4; hex 80000002; asc ;;
9: len 4; hex 80000004; asc ;;
10: len 4; hex 80000000; asc ;;
11: len 4; hex 000021c5; asc ! ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 4671 page no 5009 n bits 512 index PRIMARY of table `db_edomainnlive`.`catalog_category_product` trx id 1927338584 lock_mode X locks rec but not gap waiting
Record lock, heap no 242 PHYSICAL RECORD: n_fields 6; compact format; info bits 0
0: len 4; hex 82c22c0d; asc , ;;
1: len 4; hex 000004fd; asc ;;
2: len 4; hex 0001db14; asc ;;
3: len 6; hex 000000000000; asc ;;
4: len 7; hex 80000000000000; asc ;;
5: len 4; hex 800005c1; asc ;;
It hints at a problem in the category indexer causing a deadlock.
Could you guys take a look at this thread as well?
https://jira.mariadb.org/browse/MDEV-32033
I've opened it as a bug, and any input in the internal process of reindexing and why this might be happening is welcome.
A user hinted that the rename action on the indexing tables may be creating the metadata lock on the whole table, while other queries are pending leading to this.
e.g. this message
If it is RENAME TABLE indeed, then this won't be fixed anytime soon. RENAME changes table metadata, it has to take an exclusive metadata lock for a very short time. But if you have a long-running SELECT, RENAME won't be able to take a metadata lock, so it'll wait. And all later statements will wait for RENAME. When your long-running SELECT finishes, everything will start working again.
It points to a flaw in the design of the indexing process in Magento 2 as it relies on the core of renaming index tables from the replicas
to the normal name and the normal name
to the normal name _old
. This one seems to be spot on.
There is an opreation for a RENAME table almost 90% of the time I check the issue occuring. On top of it there are some price indexing queries which slow down and below the RENAME table there are other random queries either for price indexer or stock indexer or different other things.
I'm thinking that different indexers are trying to rename the tables while other processes are reading data from the index tables, thus causing this deadlock situation.
@engcom-Dash could you check with some core developer about this use case? It seems like a valid architectural flaw as described in MariaDB jira bug tracker because the RENAME table action can cause a deadlock when used in this context. If we could get some input from both ends we could fix this issue
Furthermore with the help from MariaDB people I was able to come up with this metadata lock analysis.
By using a small program I was able to come up to the conclusion that the thread most likely affecting all other threads directly or indirectly is 110871
because it's blocked by many threads selecting from the same table that is trying to be renamed
I don't see any particular thread directly locked by this one but it's possible it's indirectly blocked. Someone would need to create a graph to find this but I honestly can't do this due to lack of knowledge to program this algorithm.
I guess it's possible to replicate this issue with the new information
catalog_product_index_price
table to export a product feed for example catalog_product_price
catalog_product_index_price
table to rename it. What do you think @engcom-Dash ?
The only place I see this query getting built in the entire codebase is the
\Magento\Catalog\Model\ResourceModel\Product\Collection::_productLimitationPrice
So it's definitely the culprit of the long query execution which spans so long until reindex will try to rename the table and cause the deadlocks.
Any ideas how to make it perform well?
And now I'm even more confused because in an effort to get a backtrace of the function calls I decided to immediately kill the query from mytop so that I can get an exception.
I received this exception for both queries killed
The 3rd party modules don't affect this query in any way, their code is related to manipulating the output html only to format it. They don't interfere with the queries
I don't see a clear path from getCategoryTree to the LEAST
price query
Also the full query is weird
# Time: 230917 1:56:50
# User@Host: db_edomainnlive[db_edomainnlive] @ localhost []
# Thread_id: 1782741 Schema: db_edomainnlive QC_hit: No
# Query_time: 229.541896 Lock_time: 0.000152 Rows_sent: 0 Rows_examined: 292521249
# Rows_affected: 0 Bytes_sent: 0
# Tmp_tables: 1 Tmp_disk_tables: 0 Tmp_table_sizes: 127296
# Full_scan: Yes Full_join: Yes Tmp_table: Yes Tmp_table_on_disk: No
# Filesort: No Filesort_on_disk: No Merge_passes: 0 Priority_queue: No
#
# explain: id select_type table type possible_keys key key_len ref rows r_rows filtered r_filtered Extra
# explain: 1 SIMPLE inventory_in_stock ALL PRIMARY,index_sku_qty NULL NULL NULL 1 29302.00 100.00 24.13 Using where; Using temporary; Using filesort
# explain: 1 SIMPLE stock_status_index ALL PRIMARY,index_sku_qty NULL NULL NULL 1 82841.35 100.00 26.71 Using where; Using join buffer (flat, BNL join)
# explain: 1 SIMPLE product ref PRIMARY,CATALOG_PRODUCT_ENTITY_SKU CATALOG_PRODUCT_ENTITY_SKU 195 db_edomainnlive.stock_status_index.sku 1 1.00 100.00 100.00 Using index
# explain: 1 SIMPLE cat_index eq_ref PRIMARY,IDX_BF8E9C147B9E369FA5F75474BF410B76,IDX_399EE76B5BD4142D9CCF0511849161E3 PRIMARY 10 const,db_edomainnlive.product.entity_id,const 1 0.29 100.00 99.91 Using where
# explain: 1 SIMPLE price_index eq_ref PRIMARY,CATALOG_PRODUCT_INDEX_PRICE_CUSTOMER_GROUP_ID,CAT_PRD_IDX_PRICE_WS_ID_CSTR_GROUP_ID_MIN_PRICE PRIMARY 10 db_edomainnlive.product.entity_id,const,const 1 0.99 100.00 100.00
# explain: 1 SIMPLE e eq_ref PRIMARY,CATALOG_PRODUCT_ENTITY_SKU PRIMARY 4 db_edomainnlive.product.entity_id 1 1.00 100.00 0.00 Using where
# explain: 1 SIMPLE links eq_ref CATALOG_PRODUCT_LINK_LINK_TYPE_ID_PRODUCT_ID_LINKED_PRODUCT_ID,CATALOG_PRODUCT_LINK_PRODUCT_ID,CATALOG_PRODUCT_LINK_LINKED_PRODUCT_ID CATALOG_PRODUCT_LINK_LINK_TYPE_ID_PRODUCT_ID_LINKED_PRODUCT_ID 10 const,const,db_edomainnlive.product.entity_id 1 0.01 100.00 100.00 Using index
# explain: 1 SIMPLE product_entity_table eq_ref PRIMARY PRIMARY 4 db_edomainnlive.links.product_id 1 1.00 100.00 100.00 Using index
# explain: 1 SIMPLE link_attribute_position_int eq_ref CAT_PRD_LNK_ATTR_INT_PRD_LNK_ATTR_ID_LNK_ID,CATALOG_PRODUCT_LINK_ATTRIBUTE_INT_LINK_ID CAT_PRD_LNK_ATTR_INT_PRD_LNK_ATTR_ID_LNK_ID 7 const,db_edomainnlive.links.link_id 1 1.00 100.00 100.00
# explain: 1 SIMPLE link_attribute_qty_decimal eq_ref CAT_PRD_LNK_ATTR_DEC_PRD_LNK_ATTR_ID_LNK_ID,CATALOG_PRODUCT_LINK_ATTRIBUTE_DECIMAL_LINK_ID CAT_PRD_LNK_ATTR_DEC_PRD_LNK_ATTR_ID_LNK_ID 7const,db_edomainnlive.links.link_id 1 0.00 100.00 100.00
#
SET timestamp=1694908610;
SELECT `e`.*, `price_index`.`price`, `price_index`.`tax_class_id`, `price_index`.`final_price`, IF(price_index.tier_price IS NOT NULL, LEAST(price_index.min_price, price_index.tier_price), price_index.min_price) AS `minimal_price`, `price_index`.`min_price`, `price_index`.`max_price`, `price_index`.`tier_price`, `cat_index`.`position` AS `cat_index_position`, `stock_status_index`.`is_salable`, `links`.`link_id`, `links`.`product_id` AS `_linked_to_product_id`, `link_attribute_position_int`.`value` AS `position`, `link_attribute_qty_decimal`.`value` AS `qty` FROM `catalog_product_entity` AS `e`
INNER JOIN `inventory_stock_9` AS `inventory_in_stock` ON e.sku = inventory_in_stock.sku
INNER JOIN `catalog_product_index_price` AS `price_index` ON price_index.entity_id = e.entity_id AND price_index.customer_group_id = 0 AND price_index.website_id = '5'
INNER JOIN `catalog_category_product_index_store10` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=10 AND cat_index.visibility IN(2, 4) AND cat_index.category_id=2
INNER JOIN `catalog_product_entity` AS `product` ON product.entity_id = e.entity_id
INNER JOIN `inventory_stock_9` AS `stock_status_index` ON product.sku = stock_status_index.sku
INNER JOIN `catalog_product_link` AS `links` ON links.linked_product_id = e.entity_id AND links.link_type_id = 1
LEFT JOIN `catalog_product_link_attribute_int` AS `link_attribute_position_int` ON link_attribute_position_int.link_id = links.link_id AND link_attribute_position_int.product_link_attribute_id = '2'
LEFT JOIN `catalog_product_link_attribute_decimal` AS `link_attribute_qty_decimal` ON link_attribute_qty_decimal.link_id = links.link_id AND link_attribute_qty_decimal.product_link_attribute_id = '6'
INNER JOIN `catalog_product_entity` AS `product_entity_table` ON links.product_id = product_entity_table.entity_id WHERE (inventory_in_stock.is_salable = 1) AND (stock_status_index.is_salable = 1) AND (links.product_id in ('181305')) AND (`e`.`entity_id` != '181305') ORDER BY `position` ASC;
If I'm wrong please correct me here but
inventory_stock_9
table is joined twice there's no need for the second join as I see it. catalog_product_entity
is joined twice price_index.website_id = '5'
should be price_index.website_id = 5
is_salable
used in where without an indexThe inventory_stock_9 table should have an index on is_salable
column
I've added the indexes on the inventory indexer for is_salable and sku column and it seems to mitigate the issue for the time being. I'll report back at the end of this week as I monitor more closely to see if more occurrences will appear
Affected Module: magento/module-inventory-indexer
Index: Indexer/IndexStructure.php
IDEA additional info:
Subsystem: com.intellij.openapi.diff.impl.patch.CharsetEP
<+>UTF-8
===================================================================
diff --git a/Indexer/IndexStructure.php b/Indexer/IndexStructure.php
--- a/Indexer/IndexStructure.php
+++ b/Indexer/IndexStructure.php (date 1694910176253)
@@ -121,7 +121,15 @@
'index_sku_qty',
[self::SKU, self::QUANTITY],
['type' => AdapterInterface::INDEX_TYPE_INDEX]
- );
+ )->addIndex('index_is_salable',
+ [self::IS_SALABLE],
+ ['type' => AdapterInterface::INDEX_TYPE_INDEX]
+ )
+ ->addIndex('index_sku',
+ [self::SKU],
+ ['type' => AdapterInterface::INDEX_TYPE_INDEX]
+ )
+ ;
$connection->createTable($table);
}
Mitigated but not solved. Happens less frequently now. One occurrence of rename table taking 240 seconds to finish.
# Time: 230918 11:53:21
# User@Host: db_edomainnlive[db_edomainnlive] @ localhost []
# Thread_id: 2122903 Schema: db_edomainnlive QC_hit: No
# Query_time: 240.000779 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0
# Rows_affected: 0 Bytes_sent: 67
SET timestamp=1695030801;
RENAME TABLE catalog_product_index_price TO catalog_product_index_price_outdated,catalog_product_index_price_replica TO catalog_product_index_price,catalog_product_index_price_outdated TO catalog_product_index_price_replica;
The query again in question
# Time: 230918 12:29:52
# User@Host: db_edomainnlive[db_edomainnlive] @ localhost []
# Thread_id: 2128153 Schema: db_edomainnlive QC_hit: No
# Query_time: 2667.097652 Lock_time: 0.000119 Rows_sent: 0 Rows_examined: 1139192931
# Rows_affected: 0 Bytes_sent: 0
# Tmp_tables: 1 Tmp_disk_tables: 0 Tmp_table_sizes: 127296
# Full_scan: No Full_join: No Tmp_table: Yes Tmp_table_on_disk: No
# Filesort: No Filesort_on_disk: No Merge_passes: 0 Priority_queue: No
#
# explain: id select_type table type possible_keys key key_len ref rows r_rows filtered r_filtered Extra
# explain: 1 SIMPLE inventory_in_stock ref PRIMARY,index_sku_qty,index_is_salable,index_sku index_is_salable 1 const 1 17935.00 100.00 100.00 Using index; Using temporary; Using filesort
# explain: 1 SIMPLE stock_status_index ref PRIMARY,index_sku_qty,index_is_salable,index_sku index_is_salable 1 const 1 22145.96 100.00 100.00 Using index
# explain: 1 SIMPLE product ref PRIMARY,CATALOG_PRODUCT_ENTITY_SKU CATALOG_PRODUCT_ENTITY_SKU 195 db_edomainnlive.stock_status_index.sku 1 1.00 100.00 100.00 Using index
# explain: 1 SIMPLE cat_index eq_ref PRIMARY,CAT_CTGR_PRD_IDX_STORE10_PRD_ID_STORE_ID_CTGR_ID_VISIBILITY,IDX_F8ACF7CDE70069E0E1260FAB3C7FAF7E PRIMARY 10 const,db_edomainnlive.product.entity_id,const 1 0.29 100.00 99.91 Using where
# explain: 1 SIMPLE price_index eq_ref PRIMARY,CATALOG_PRODUCT_INDEX_PRICE_CUSTOMER_GROUP_ID,CAT_PRD_IDX_PRICE_WS_ID_CSTR_GROUP_ID_MIN_PRICE PRIMARY 10 db_edomainnlive.product.entity_id,const,const 1 0.99 100.00 100.00
# explain: 1 SIMPLE e eq_ref PRIMARY,CATALOG_PRODUCT_ENTITY_SKU PRIMARY 4 db_edomainnlive.product.entity_id 1 1.00 100.00 0.00 Using where
# explain: 1 SIMPLE links eq_ref CATALOG_PRODUCT_LINK_LINK_TYPE_ID_PRODUCT_ID_LINKED_PRODUCT_ID,CATALOG_PRODUCT_LINK_PRODUCT_ID,CATALOG_PRODUCT_LINK_LINKED_PRODUCT_ID CATALOG_PRODUCT_LINK_LINK_TYPE_ID_PRODUCT_ID_LINKED_PRODUCT_ID 10 const,const,db_edomainnlive.product.entity_id 1 0.00 100.00 100.00 Using index
# explain: 1 SIMPLE product_entity_table eq_ref PRIMARY PRIMARY 4 db_edomainnlive.links.product_id 1 1.00 100.00 100.00 Using index
# explain: 1 SIMPLE link_attribute_position_int eq_ref CAT_PRD_LNK_ATTR_INT_PRD_LNK_ATTR_ID_LNK_ID,CATALOG_PRODUCT_LINK_ATTRIBUTE_INT_LINK_ID CAT_PRD_LNK_ATTR_INT_PRD_LNK_ATTR_ID_LNK_ID 7 const,db_edomainnlive.links.link_id 1 1.00 100.00 100.00
# explain: 1 SIMPLE link_attribute_qty_decimal eq_ref CAT_PRD_LNK_ATTR_DEC_PRD_LNK_ATTR_ID_LNK_ID,CATALOG_PRODUCT_LINK_ATTRIBUTE_DECIMAL_LINK_ID CAT_PRD_LNK_ATTR_DEC_PRD_LNK_ATTR_ID_LNK_ID 7const,db_edomainnlive.links.link_id 1 0.00 100.00 100.00
#
SET timestamp=1695032992;
SELECT `e`.*, `price_index`.`price`, `price_index`.`tax_class_id`, `price_index`.`final_price`, IF(price_index.tier_price IS NOT NULL, LEAST(price_index.min_price, price_index.tier_price), price_index.min_price) AS `minimal_price`, `price_index`.`min_price`, `price_index`.`max_price`, `price_index`.`tier_price`, `cat_index`.`position` AS `cat_index_position`, `stock_status_index`.`is_salable`, `links`.`link_id`, `links`.`product_id` AS `_linked_to_product_id`, `link_attribute_position_int`.`value` AS `position`, `link_attribute_qty_decimal`.`value` AS `qty` FROM `catalog_product_entity` AS `e`
INNER JOIN `inventory_stock_9` AS `inventory_in_stock` ON e.sku = inventory_in_stock.sku
INNER JOIN `catalog_product_index_price` AS `price_index` ON price_index.entity_id = e.entity_id AND price_index.customer_group_id = 0 AND price_index.website_id = '5'
INNER JOIN `catalog_category_product_index_store10` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=10 AND cat_index.visibility IN(2, 4) AND cat_index.category_id=2
INNER JOIN `catalog_product_entity` AS `product` ON product.entity_id = e.entity_id
INNER JOIN `inventory_stock_9` AS `stock_status_index` ON product.sku = stock_status_index.sku
INNER JOIN `catalog_product_link` AS `links` ON links.linked_product_id = e.entity_id AND links.link_type_id = 1
LEFT JOIN `catalog_product_link_attribute_int` AS `link_attribute_position_int` ON link_attribute_position_int.link_id = links.link_id AND link_attribute_position_int.product_link_attribute_id = '2'
LEFT JOIN `catalog_product_link_attribute_decimal` AS `link_attribute_qty_decimal` ON link_attribute_qty_decimal.link_id = links.link_id AND link_attribute_qty_decimal.product_link_attribute_id = '6'
INNER JOIN `catalog_product_entity` AS `product_entity_table` ON links.product_id = product_entity_table.entity_id WHERE (inventory_in_stock.is_salable = 1) AND (stock_status_index.is_salable = 1) AND (links.product_id in ('152938')) AND (`e`.`entity_id` != '152938') ORDER BY `position` ASC;
Rows_examined: 1139192931
This is a lot. However, have you been able to check the index for each join table?
Have you used READ COMMITTED from MySQL isolation level?
Preconditions and environment
Steps to reproduce
I don't have the exact steps, other than the fact that reindexing the price rules takes too long. However in my case I see hundreds of queries like this
Which take too long to finish and drop our website
Expected result
The site is still working and queries are much faster and won't bring the site down.
Actual result
The website is down with a lot of queries in queue. Over 2k siilar to this
Additional information
No response
Release note
No response
Triage and priority