|
I managed to get the 3 files together today
|
|
Thank you. I checked [^mariadbd_full_bt_all_threads-1.txt], and I do not see any sign of an InnoDB hang there. I do see that the adaptive hash index is being used, and I see a few threads that are momentarily waiting for something:
|
mariadb-10.4.31
|
Thread 70 (Thread 0x7fe6708f1700 (LWP 1692605)):
|
#0 buf_page_hash_lock_get (page_id=@0x7fe6708ec3d8: {m_space = 16887, m_page_no = 4}, buf_pool=0x562af6835c30) at ./storage/innobase/include/buf0types.h:176
|
No locals.
|
#1 buf_page_get_low (page_id={m_space = 16887, m_page_no = 4}, zip_size=0, rw_latch=1, guess=0x7feb20101160, mode=10, file=0x562af48db4c0 "/home/buildbot/buildbot/build/mariadb-10.4.31/storage/innobase/row/row0sel.cc", line=4723, mtr=0x7fe6708edae0, err=0x7fe6708ec774) at ./storage/innobase/buf/buf0buf.cc:4017
|
This is waiting for a latch on what would be known as a slice of buf_pool.page_hash in 10.5 or later. I don’t think that the thread is really blocked there.
We also have the purge coordinator thread waiting for srv_worker_thread to complete, but all srv_worker_thread appear to be idle.
Thread 24 (Thread 0x7fe68112d700 (LWP 1654226)):
|
#0 0x00007feec8b8d71b in sched_yield () from target:/lib/x86_64-linux-gnu/libc.so.6
|
No symbol table info available.
|
#1 0x0000562af446f859 in os_thread_yield () at ./storage/innobase/os/os0thread.cc:212
|
No locals.
|
#2 0x0000562af45023fd in trx_purge_wait_for_workers_to_complete () at ./storage/innobase/trx/trx0purge.cc:1240
|
No locals.
|
#3 trx_purge (n_purge_threads=<optimized out>, truncate=<optimized out>) at ./storage/innobase/trx/trx0purge.cc:1299
|
thr = <optimized out>
|
n_pages_handled = <optimized out>
|
That might be related to MDEV-14486 somehow. The code was refactored in 10.5.
I would suggest an upgrade to MariaDB Server 10.6.15 or later.
danblack, so you see any sign of an InnoDB hang in [^mariadbd_full_bt_all_threads.txt] (the file that I did not check)?
|
|
The adaptive hash index was disabled by default in MDEV-20487. It may improve but also degrade performance.
|
|
@Marko Mäkelä @Daniel Black, do you think more thread dumps would help you out more or do you need any additional info that I can provide?
Currently we're at a situation where the issue is occuring daily a couple of times and every time the result is the same, performance degrades and finally no query is being served. So I can grab more dumps if needed. I've implemented a cron job every two minutes so that when more than 10 queries are stuck in a waiting state it will take a report dump of the requested info as well
e.g. I just uploaded one more today all-files-concatenated.txt
With this situation visible
|
|
I've also disabled it to see if it will make a difference
`innodb_adaptive_hash_index = 0`
|
|
Without adaptive hash index it occurred again
lots of queries hanging on waiting for table metadata lock
See file all-files-concatenated-without-adaptive.txt
60012 db_edomainnlive localhost db_edomainnlive Query 158 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 138184) AND (category_id = 529) 0.000
|
60078 db_edomainnlive localhost db_edomainnlive Query 151 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 102023) AND (category_id = 0) 0.000
|
60090 db_edomainnlive localhost db_edomainnlive Query 149 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 151478) AND (category_id = 1029) 0.000
|
60091 db_edomainnlive localhost db_edomainnlive Query 149 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 118163) AND (category_id = 0) 0.000
|
60117 db_edomainnlive localhost db_edomainnlive Query 148 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 74498) AND (category_id = 0) 0.000
|
60119 db_edomainnlive localhost db_edomainnlive Query 148 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 164569) AND (category_id = 853) 0.000
|
60178 db_edomainnlive localhost db_edomainnlive Query 141 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 129000) AND (category_id = 979) 0.000
|
60205 db_edomainnlive localhost db_edomainnlive Query 137 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 43364) AND (category_id = 979) 0.000
|
60221 db_edomainnlive localhost db_edomainnlive Query 135 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 141188) AND (category_id = 896) 0.000
|
60230 db_edomainnlive localhost db_edomainnlive Query 133 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 150292) AND (category_id = 853) 0.000
|
60237 db_edomainnlive localhost db_edomainnlive Query 127 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 164616) AND (category_id = 979) 0.000
|
60330 db_edomainnlive localhost db_edomainnlive Query 112 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 74498) AND (category_id = 0) 0.000
|
60347 db_edomainnlive localhost db_edomainnlive Query 110 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 140209) AND (category_id = 979) 0.000
|
60348 db_edomainnlive localhost db_edomainnlive Query 110 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 146808) AND (category_id = 1014) 0.000
|
60402 db_edomainnlive localhost db_edomainnlive Query 98 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 153928) AND (category_id = 1024) 0.000
|
60475 db_edomainnlive localhost db_edomainnlive Query 85 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 167794) AND (category_id = 272) 0.000
|
60560 db_edomainnlive localhost db_edomainnlive Query 75 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 181305) AND (category_id = 1014) 0.000
|
60582 db_edomainnlive localhost db_edomainnlive Query 71 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 138191) AND (category_id = 900) 0.000
|
60603 db_edomainnlive localhost db_edomainnlive Query 69 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 51985) AND (category_id = 503) 0.000
|
60667 db_edomainnlive localhost db_edomainnlive Query 62 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 166003) AND (category_id = 1024) 0.000
|
60715 db_edomainnlive localhost db_edomainnlive Query 57 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 181415) AND (category_id = 0) 0.000
|
60725 db_edomainnlive localhost db_edomainnlive Query 56 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 172764) AND (category_id = 853) 0.000
|
60840 db_edomainnlive localhost db_edomainnlive Query 40 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 139270) AND (category_id = 529) 0.000
|
60846 db_edomainnlive localhost db_edomainnlive Query 39 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 157006) AND (category_id = 397) 0.000
|
60941 db_edomainnlive localhost db_edomainnlive Query 27 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 150575) AND (category_id = 386) 0.000
|
60944 db_edomainnlive localhost db_edomainnlive Query 27 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 26310) AND (category_id = 1019) 0.000
|
61018 db_edomainnlive localhost db_edomainnlive Query 19 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 143100) AND (category_id = 979) 0.000
|
61028 db_edomainnlive localhost db_edomainnlive Query 15 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 148432) AND (category_id = 768) 0.000
|
61029 db_edomainnlive localhost db_edomainnlive Query 14 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 96167) AND (category_id = 49) 0.000
|
61077 db_edomainnlive localhost db_edomainnlive Query 6 Waiting for table metadata lock SELECT `catalog_category_product_index_store1`.`product_id` FROM `catalog_category_product_index_store1` WHERE (product_id = 121395) AND (category_id = 979) 0.000
|
|
|
ioweb.gr, I checked the [^all-files-concatenated.txt], and I think that may have I found the problem:
55293 db_etennisnlive localhost db_etennisnlive Query 161 Waiting for table metadata lock RENAME TABLE catalog_category_product_index_store1 TO catalog_category_product_index_store1_outdated,…
|
I see many threads waiting in MDL_context::acquire_lock(), most or all of them requesting a lock on db_etennisnlive.catalog_category_product_index_store1.
Based on what I remember from implementing InnoDB online ALTER TABLE in MySQL 5.6.8 in 2012, I believe that the metadata locks behave similarly to the InnoDB rw-latches: When any thread starts waiting for an exclusive latch, it will prevent any further acquisition of a shared latch until the exclusive latch has been acquired and released.
I believe that the MDL_EXCLUSIVE request for the RENAME TABLE operation will block any further statements from acquiring metadata locks (MDL, a lock on database or table name) for accessing the affected tables. Existing transactions may continue to hold shared MDL until the transaction is committed or the single-statement transaction ends. Someone brought up this phenomenon already in 2012. The MDL_EXCLUSIVE phase at the end of ALTER TABLE could fail due to timeout. This could be caused by one “asocial” connection that did BEGIN; SELECT * FROM name_of_table_being_altered LIMIT 0; at an unfortunate moment and remained open indefinitely.
This is basically the same issue as MySQL Bug #71017, and I don’t think it can be fixed easily. I think that the fix would be to implement a multi-versioned data dictionary cache, which would allow each transaction to access database objects by the names that were committed when those transactions started.
I thought that the default MDL timeout used to be 1 year, but I see that currently, the session variable lock_wait_timeout is 1 day by default. The maximum is 365 days (LONG_TIMEOUT in the source code).
|
|
ioweb.gr, there are lots of different files attached. Which one should I look at?
Neither one of the processlist files and neither of the "bt thread full" files show any sign of massive hang that you describe.
I didn't look at all-files-concatenated.txt, because it would've been rather arbitrary, like I'm trying to find at least some evidence that confirms a theory, ignoring numerous evidences that speak against it.
Could you please attach a full processlist taken when "all queries get stuck" and delete attachments that are unrelated to your issue?
|
|
Let me add a different example here.
There are about 20 queries which are stuck in sending state for about 5000seconds.
These queries like this one execute in under <100ms
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 ('179423')) AND (`e`.`entity_id` != '179423') ORDER BY `position` ASC
[2023-09-01 13:54:57] 17 rows retrieved starting from 1 in 303 ms (execution: 92 ms, fetching: 211 ms)
However here they're stuck for hours.
I've added a debug backtrace of this in file `queries stuck in sending state.txt` and screenshot and also process list `processlist-202309011403.txt`
Why are these queries there forever, I can't understand
|
|
@Sergei in order to tackle this more efficiently let's focus on one issue at a time. Currently on the screenshot / processlist / trace that are left in attachments you can see 20+ queries stuck in sending state forever. They will never finish until they timeout or mariadb restarts.
I've removed all excess data to start fresh.
Could you check why this situation is there? Why don't these otherwise fast running queries, never finish?
|
|
As for you request when the queries are stuck in waiting state and mariadb no longer serves requests and we experience downtime here's a pack of
InnoDB status
ProcessList
Dump
File: dump2023-09-01-143646.zip dump2023-09-01-143646.zip
|
|
One more situation where our database server stopped serving requests for 4 minutes approximately.
Find the reference here " dump2023-09-01-163052.zip dump2023-09-01-163052.zip"
|
|
Do you mean, you have two different "stuck" cases? One is where queries are "waiting" and the other when they're "sending data"?
As for dump2023-09-01-143646.zip, it doesn't include the process list. gdb dump shows (summarized):
- 174 threads idle in the thread cache (not serving a connection)
- 54 threads idle waiting for the client to send a new query
- 10 threads doing InnoDB async I/O, waiting for a I/O to finish
- 9 threads working, not idle, inside innodb
- 3 threads idle, innodb internal worker threads waiting for a job
- 3 threads idle, innodb internal page cleaner worker threads waiting for a job
- 39 other threads are working or waiting all in different places
there's no massive number all threads all stuck waiting for the same thing. All your gdb dumps are like that. May be because of missing stack frames due to compiler optimizations.
What is exact MariaDB version you're using? Where did you get binaries from? Could you show
show variables like 'version%';
|
please?
|
|
Hi,
the stuck on sending state I saw it for the first time after adjusting adaptive_hash_index . Previously I was just seeing an abnormal amount of queries stuck in waiting state. Both end up with the same problem though that queries stop being served by degrading performance slowly until nothing works.
My original issue was observed in
Server version: 10.4.28-MariaDB-1:10.4.28+maria~ubu2004-log mariadb.org binary distribution
|
And after following the thread for taking a backtrace https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/#getting-backtraces-from-a-running-mysqld-process-with-gdb-on-linux as a side-effect I had to upgrade to 10.4.31 by recommendation of @Daniel Black https://dba.stackexchange.com/questions/330629/how-can-i-find-out-whats-causing-the-deadlock-in-mariadb?noredirect=1#comment644251_330629
The problem persisted on 10.4.31
~$ mysql -e "show variables like 'version%';"
|
+-------------------------+---------------------------------------------+
|
| Variable_name | Value |
|
+-------------------------+---------------------------------------------+
|
| version | 10.4.31-MariaDB-1:10.4.31+maria~ubu2004-log |
|
| version_comment | mariadb.org binary distribution |
|
| version_compile_machine | x86_64 |
|
| version_compile_os | debian-linux-gnu |
|
| version_malloc_library | system |
|
| version_source_revision | 2aea9387497cecb5668ef605b8f80886f9de812c |
|
| version_ssl_library | OpenSSL 1.1.1f 31 Mar 2020 |
|
+-------------------------+---------------------------------------------+
|
As for the missing processlist, I've added a new one with everything in which occurred today at 7am dump20230902-071200.zip
|
|
Thanks. Now I'm even more confused.
The last mariadbd_full_bt_all_threads.txt, from dump20230902-071200.zip is completely different from all others. All other traces, including those you've already deleted, show lots of threads inside get_internal_charset(), and no threads waiting on the MDL, the last one shows 3 threads waiting on MDL (one update, one delete, and one insert delayed) and no threads inside get_internal_charset(). And values of local variables don't make much sense.
I don't know what else we can try. Would you be open to running a non-optimized mysqld binary? It might provide a more meaningful gdb dump. Also, if you have threads stuck on MDLs, you can try to use https://mariadb.com/kb/en/metadata-lock-info-plugin/ to see all metadata locks and find out what's blocking what. You can use performance_schema too, although in 10.4 its usability is rather limited.
|
|
Hi, at this point we've reached our limit so we're open to any suggestions that can help resolve this. How.do I install the unoptimized binary ?
I'll try installing the plugin also.
Since the problem is happening daily I can grab more dumps for analysis also.
However due to compatibility reasons I don't want to bump the version over 10.4 yet
|
|
There seems to be a problem with the version installed after following the guide https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/#getting-backtraces-from-a-running-mysqld-process-with-gdb-on-linux as I cannot install the metadata_lock_info.
How should I upgrade to the proper version that includes the plugin?
MariaDB [(none)]> INSTALL SONAME 'metadata_lock_info';
ERROR 1126 (HY000): Can't open shared library 'metadata_lock_info.so' (errno: 8, API version for INFORMATION SCHEMA plugin METADATA_LOCK_INFO not supported by this version of the server)
|
|
This error means you have a plugin from a different server version
|
|
serg, the stack traces that I analyzed last week painted a rather clear picture. Can you confirm or refute my claim that starting a wait for MDL_EXCLUSIVE in a DDL statement such as RENAME TABLE would block any further MDL acquisition on the table?
|
|
Of course, I confirm your claim. But I haven't seen any RENAME TABLE in any of the stack traces. I have only seen MDL waits in the very last stack trace, not in any earlier ones. And there were only 9 selects, 1 insert delayed, 1 update, 1 delete. No DDLs.
So, you're right about the effects of RENAME TABLE on MDL locking, but I don't see how it's relevant to the issue at hands.
|
|
Actually this can be a reason. The underlying system (magento 2) is doing this to create some index tables.
1. Create a replica table of the destination table in our case it might be catalog_product_price_index_replica for example
2. Create temp table to store some batch results e.g. catalog_product_price_index_temp123213
By processing data in batches
3. Mass insert to catalog_product_price_index_replica from the _temp table
Finally it will rename table catalog_product_price_index to catalog_product_price_index_old and catalog_product_price_index_replica to catalog_product_price_index to reduce the effect of reindexing all data.
So what @Marko is saying does make a sense in the application logic. Perhaps I'm just catching the it at a bad time when try to take the trace to give a report but I have seen cases where there's a rename table query inside.
Check this image from mytop which I saw originally and described in my stackexchange issue
|
|
Please check this one, it actually has RENAME command inside it
debug_20230904135015.zip
|
|
In the file mariadbd_full_bt_all_threads.txt of the attachment debug_20230904135015.zip, Thread 92 is waiting for MDL deep inside mysql_rename_tables(), which is renaming a large number of tables. The full statement is not visible (set print elements 100000 or set max-value-size 1000000 could help), so I can’t say if all the MDL_wait::timed_wait() in other threads are waiting on one of the affected table names.
|
|
ioweb.gr, I'm all for accepting the RENAME TABLE explanation, as it means I won't need to search for a culprit anymore.
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.
There is no fix for that. You can try to use a short timeout for metadata locks or set max_statement_time for the RENAME TABLE. It'll cause RENAME to be aborted if it'll wait too long and all further DML statements will be able to continue. This means you'll need to keep repeating RENAME until it succeeds. Which magento is likely not able to do.
|
|
I totally understand your explanation. But all the queries before Rename run in less than a second normally. Like when I see them in `mytop` I will take the full query, spawn a terminal, hit mysql, execute it, and it will finish in less than 1second.
So I'm curious about a few things because when I see rename there, I have a few observations that align with what you say except for point 1.
1. Why are the queries that are hanging on mytop for like 600 seconds with id lower than the rename query still running fast on my custom terminal connection?
2. When I start killing them top to bottom in mytop (query id asc ) and reach the rename query, it will get the metadata lock and finish immediately and everything else will process as would be expected based on your explanation
So my question is, if the first queries that run at that time before rename kicks in, always on my secondary connection run extremely fast, sometimes within 95ms and max 1 second, at that point take 600 seconds, that means something is blocking them too right?
What is blocking them then?
I cannot seem to figure it out as they're in some cases for example, only 3 similar queries, and the processlist doesn't have any query pending before them, and all 3 have to finish before rename kicks in and if those 3 die everything else process fast.
This doesn't add up or I'm missing something obvious here.
Check the query which is ID=52998 and some more
```
SELECT `child`.`entity_id`
FROM `catalog_product_entity` AS `parent`
INNER JOIN `catalog_product_relation` AS `link` ON link.parent_id = parent.entity_id
INNER JOIN `catalog_product_entity` AS `child` ON child.entity_id = link.child_id
INNER JOIN `catalog_product_index_price` AS `t` ON t.entity_id = child.entity_id
LEFT JOIN `catalog_product_entity_int` AS `status_global_attr`
ON status_global_attr.entity_id = child.entity_id AND status_global_attr.attribute_id = 84 AND
status_global_attr.store_id = 0
LEFT JOIN `catalog_product_entity_int` AS `status_attr`
ON status_attr.entity_id = child.entity_id AND status_attr.attribute_id = 84 AND
status_attr.store_id = 5
INNER JOIN `inventory_stock_5` AS `stock` ON stock.sku = child.sku
WHERE (parent.entity_id = 174945)
AND (t.website_id = '2')
AND (t.customer_group_id = 0)
AND (IFNULL(status_attr.value, status_global_attr.value) = 1)
AND (stock.is_salable = 1)
ORDER BY `t`.`min_price` ASC, `child`.`entity_id` ASC
LIMIT 1
[2023-09-04 15:01:58] 1 row retrieved starting from 1 in 129 ms (execution: 93 ms, fetching: 36 ms)
```
```
SELECT `child`.`entity_id` FROM `catalog_product_entity` AS `parent` INNER JOIN `catalog_product_relation` AS `link` ON link.parent_id = parent.entity_id INNER JOIN `catalog_product_entity` AS `child` ON child.entity_id = link.child_id INNER JOIN `catalog_product_index_price` AS `t` ON t.entity_id = child.entity_id LEFT JOIN `catalog_product_entity_int` AS `status_global_attr` ON status_global_attr.entity_id = child.entity_id AND status_global_attr.attribute_id = 84 AND status_global_attr.store_id = 0 LEFT JOIN `catalog_product_entity_int` AS `status_attr` ON status_attr.entity_id = child.entity_id AND status_attr.attribute_id = 84 AND status_attr.store_id = 5 INNER JOIN `inventory_stock_5` AS `stock` ON stock.sku = child.sku WHERE (parent.entity_id = 165474) AND (t.website_id = '2') AND (t.customer_group_id = 0) AND (IFNULL(status_attr.value, status_global_attr.value) = 1) AND (stock.is_salable = 1) ORDER BY `t`.`min_price` ASC, `child`.`entity_id` ASC LIMIT 1
[2023-09-04 15:03:01] 1 row retrieved starting from 1 in 98 ms (execution: 81 ms, fetching: 17 ms)
```
```
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 ('141317'))
AND (`e`.`entity_id` != '141317')
ORDER BY `position` ASC
[2023-09-04 15:03:37] 4 rows retrieved starting from 1 in 142 ms (execution: 85 ms, fetching: 57 ms)
```
If they're running in 85ms they shouldn't be blocking the rename or they should finish fast. However they never finish when this situation occurs.
Do you see why I'm puzzled?
|
|
> The full statement is not visible (set print elements 100000 or set max-value-size 1000000 could help)
How do I do this to assist you further the next time the issue arises. ?
|
|
Here's a visual example
The query on top I executed on my local connection during the issue
```
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 ('147133')) AND (`e`.`entity_id` != '147133') ORDER BY `position` ASC
[2023-09-04 15:52:35] 1 row retrieved starting from 1 in 137 ms (execution: 85 ms, fetching: 52 ms)
```
-When it ended everything went ok with the rest. -
-I didn't find it early enough to get the dump or kill it but I'll try again. -
Actually it never ended but the rest proceeded. It's still up there never ending an otherwise fast query
debug_20230904155641.zip
|
|
This is a very small sample just before the rename query kicks in, 6 otherwise fast running queries are stuck entirely for 1700seconds debug_20230904170300.zip
|
|
I've upgraded mariadb to a slightly different version to enable the metadata locks plugin.
This dump contains that information as well and I see a bunch of threads and tables locked by a single thread 34627
Please check
debug_20230905091543.zip
|
|
And here's one from now
debug_20230905142728.zip
It seems there are two threads (117334 and 117364) that aren't blocked by any other threads directly however they seem to block the rename table operation.
However both of these threads queries are really fast to execute so why are they being so slow?
Thread 110871 executing "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" IS LOCKED BY Thread 117364
Thread 110871 executing "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" IS LOCKED BY Thread 117364
Thread 110871 executing "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" IS LOCKED BY Thread 117364
Thread 110871 executing "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" IS LOCKED BY Thread 117364
Thread 110871 executing "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" IS LOCKED BY Thread 117364
Thread 110871 executing "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" IS LOCKED BY Thread 117364
Thread 110871 executing "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" IS LOCKED BY Thread 117364
e.g.
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_7` 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 = '1'
INNER JOIN `catalog_category_product_index_store1` AS `cat_index`
ON cat_index.product_id = e.entity_id AND cat_index.store_id = 1 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_7` 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 ('165126'))
AND (`e`.`entity_id` != '165126')
ORDER BY `position` ASC
[2023-09-05 15:04:03] 20 rows retrieved starting from 1 in 516 ms (execution: 101 ms, fetching: 415 ms)
|
|
Okay, so it means that RENAME TABLE is not guilty, it simply does what it's suppose to do, waits for the lock, blocking all following queries. The actual problem is the query before RENAME that is suddenly being slow. And it's "sending data", so it's not waiting for metadata or table locks.
A possible workaround would be to set max_statement_time, then these slow queries will be automatically killed, unfreezing your application. It's of course not a fix, but perhaps it'll be able to remove a bit of pressure from you.
|
|
Unfortunately I cannot set max_statement_time to enforce a global limit because there are a few queries running on a schedule that export product feeds that would break in that case. They're supposed to take some time 
What could be possible causes that these queries would get stuck in the sending state?
|
|
Is it possible that the lock imposed by the RENAME TABLE action is actually blocking the already running SELECT query which is in sending data phase for some reason?
|
|
No, RENAME cannot start blocking a query that's already executing. All statements take metadata locks at the beginning, if SELECT is "sending data", it already has all metadata locks it needs and won't try to take any more.
|
|
I've looked at the last gdb trace, indeed, there were >150 SELECTs waiting for an MDL, one RENAME waiting for an MDL, and two SELECTs executing. So, basically, the same picture, and the two SELECTs were actually executing, they weren't stuck.
So, we need to figure out why queries are suddenly slow. Do you have a slow log enabled? you can make MariaDB to log the EXPLAIN for slow queries: https://mariadb.com/kb/en/explain-in-the-slow-query-log/
Extended statistics might be helpful too: https://mariadb.com/kb/en/slow-query-log-extended-statistics/
Could you enable that and see what will show up?
|
|
I do have slow log enabled but I also added
log-slow-verbosity=query_plan,explain
I'll try and get a fresh dump and also track the queries in the log next time it occurs
|
|
serg since you've been so kind in trying to troubleshoot this and I really appreciate it, could you also take a look at this use case?
debug_20230907075720.zip
I find something that is very weird for me
Thread 159386 executing
UPDATE `mview_state` SET `status` = 'idle', `updated` = '2023-09-07 04:07:06' WHERE (state_id=9)
|
IS LOCKED BY Thread 160981
And I see in processlist
160981 admin localhost db_edomainnlive Query 1 Writing to net SELECT /*!40001 SQL_NO_CACHE */ `entity_id`, `store_id`, `base_grand_total`, `shipping_tax_amount`, `tax_amount`, `base_tax_amount`, `store_to_order_rate`, `base_shipping_tax_amount`, `base_discount_amount`, `base_to_order_rate`, `grand_total`, `shipping_amount`, `subtotal_incl_tax`, `base_subtotal_incl_tax`, `store_to_base_rate`, `base_shipping_amount`, `total_qty`, `base_to_global_rate`, `subtotal`, `base_subtotal`, `discount_amount`, `billing_address_id`, `is_used_for_refund`, `order_id`, `email_sent`, `send_email`, `can_void_flag`, `state`, `shipping_address_id`, `store_currency_code`, `transaction_id`, `order_currency_code`, `base_currency_code`, `global_currency_code`, `increment_id`, `created_at`, `updated_at`, `discount_tax_compensation_amount`, `base_discount_tax_compensation_amount`, `shipping_discount_tax_compensation_amount`, `base_shipping_discount_tax_compensation_amnt`, `shipping_incl_tax`, `base_shipping_incl_tax`, `base_total_refunded`, `discount_description`, `customer_note`, `customer_note_notify`, `fee_amount`, `base_fee_amount` FROM `sales_invoice` 0.000
|
Which should run in around 7 seconds tops
But the problem is that I don't understand the correlation between those two and why the invoice table select would prevent updating the the mview_state table. I don't see a foreign key or something that would be a problem to update the mview_state table so that the select in the sales_invoice table should prevent it.
create table db_edomainnlive.sales_invoice
|
(
|
entity_id int unsigned auto_increment comment 'Entity ID'
|
primary key,
|
store_id smallint unsigned null comment 'Store ID',
|
base_grand_total decimal(20, 4) null comment 'Base Grand Total',
|
shipping_tax_amount decimal(20, 4) null comment 'Shipping Tax Amount',
|
tax_amount decimal(20, 4) null comment 'Tax Amount',
|
base_tax_amount decimal(20, 4) null comment 'Base Tax Amount',
|
store_to_order_rate decimal(20, 4) null comment 'Store To Order Rate',
|
base_shipping_tax_amount decimal(20, 4) null comment 'Base Shipping Tax Amount',
|
base_discount_amount decimal(20, 4) null comment 'Base Discount Amount',
|
base_to_order_rate decimal(20, 4) null comment 'Base To Order Rate',
|
grand_total decimal(20, 4) null comment 'Grand Total',
|
shipping_amount decimal(20, 4) null comment 'Shipping Amount',
|
subtotal_incl_tax decimal(20, 4) null comment 'Subtotal Incl Tax',
|
base_subtotal_incl_tax decimal(20, 4) null comment 'Base Subtotal Incl Tax',
|
store_to_base_rate decimal(20, 4) null comment 'Store To Base Rate',
|
base_shipping_amount decimal(20, 4) null comment 'Base Shipping Amount',
|
total_qty decimal(12, 4) null comment 'Total Qty',
|
base_to_global_rate decimal(20, 4) null comment 'Base To Global Rate',
|
subtotal decimal(20, 4) null comment 'Subtotal',
|
base_subtotal decimal(20, 4) null comment 'Base Subtotal',
|
discount_amount decimal(20, 4) null comment 'Discount Amount',
|
billing_address_id int null comment 'Billing Address ID',
|
is_used_for_refund smallint unsigned null comment 'Is Used For Refund',
|
order_id int unsigned not null comment 'Order ID',
|
email_sent smallint unsigned null comment 'Email Sent',
|
send_email smallint unsigned null comment 'Send Email',
|
can_void_flag smallint unsigned null comment 'Can Void Flag',
|
state int null comment 'State',
|
shipping_address_id int null comment 'Shipping Address ID',
|
store_currency_code varchar(3) null comment 'Store Currency Code',
|
transaction_id varchar(255) null comment 'Transaction ID',
|
order_currency_code varchar(3) null comment 'Order Currency Code',
|
base_currency_code varchar(3) null comment 'Base Currency Code',
|
global_currency_code varchar(3) null comment 'Global Currency Code',
|
increment_id varchar(50) null comment 'Increment ID',
|
created_at timestamp default current_timestamp() not null comment 'Created At',
|
updated_at timestamp default current_timestamp() not null on update current_timestamp() comment 'Updated At',
|
discount_tax_compensation_amount decimal(20, 4) null comment 'Discount Tax Compensation Amount',
|
base_discount_tax_compensation_amount decimal(20, 4) null comment 'Base Discount Tax Compensation Amount',
|
shipping_discount_tax_compensation_amount decimal(20, 4) null comment 'Shipping Discount Tax Compensation Amount',
|
base_shipping_discount_tax_compensation_amnt decimal(20, 4) null comment 'Base Shipping Discount Tax Compensation Amount',
|
shipping_incl_tax decimal(20, 4) null comment 'Shipping Incl Tax',
|
base_shipping_incl_tax decimal(20, 4) null comment 'Base Shipping Incl Tax',
|
base_total_refunded decimal(20, 4) null comment 'Base Total Refunded',
|
discount_description varchar(255) null comment 'Discount Description',
|
customer_note text null comment 'Customer Note',
|
customer_note_notify smallint unsigned null comment 'Customer Note Notify',
|
fee_amount decimal(12, 4) null comment 'Fee Amount',
|
base_fee_amount decimal(12, 4) null comment 'Base Fee Amount',
|
constraint SALES_INVOICE_INCREMENT_ID_STORE_ID
|
unique (increment_id, store_id),
|
constraint SALES_INVOICE_ORDER_ID_SALES_ORDER_ENTITY_ID
|
foreign key (order_id) references db_edomainnlive.sales_order (entity_id)
|
on delete cascade,
|
constraint SALES_INVOICE_STORE_ID_STORE_STORE_ID
|
foreign key (store_id) references db_edomainnlive.store (store_id)
|
on delete set null
|
)
|
comment 'Sales Flat Invoice';
|
|
create index SALES_INVOICE_CREATED_AT
|
on db_edomainnlive.sales_invoice (created_at);
|
|
create index SALES_INVOICE_EMAIL_SENT
|
on db_edomainnlive.sales_invoice (email_sent);
|
|
create index SALES_INVOICE_GRAND_TOTAL
|
on db_edomainnlive.sales_invoice (grand_total);
|
|
create index SALES_INVOICE_ORDER_ID
|
on db_edomainnlive.sales_invoice (order_id);
|
|
create index SALES_INVOICE_SEND_EMAIL
|
on db_edomainnlive.sales_invoice (send_email);
|
|
create index SALES_INVOICE_STATE
|
on db_edomainnlive.sales_invoice (state);
|
|
create index SALES_INVOICE_STORE_ID
|
on db_edomainnlive.sales_invoice (store_id);
|
|
create index SALES_INVOICE_UPDATED_AT
|
on db_edomainnlive.sales_invoice (updated_at);
|
|
|
|
create table db_edomainnlive.mview_state
|
(
|
state_id int unsigned auto_increment comment 'View State ID'
|
primary key,
|
view_id varchar(255) null comment 'View ID',
|
mode varchar(16) default 'disabled' null comment 'View Mode',
|
status varchar(16) default 'idle' null comment 'View Status',
|
updated datetime null comment 'View updated time',
|
version_id int unsigned null comment 'View Version ID'
|
)
|
comment 'View State';
|
|
create index MVIEW_STATE_MODE
|
on db_edomainnlive.mview_state (mode);
|
|
create index MVIEW_STATE_VIEW_ID
|
on db_edomainnlive.mview_state (view_id);
|
This looks pretty weird to me.
Also the fact that this query is ran by the admin user, makes me think it's related to a backup. Is it possible the database lock in this case is due to a mysqldump command?
|
|
How do I find in the slow log the items that are stuck ?
I see those queries in the process list but I can't find them in the slow log.
216580 db_edomainnlive localhost db_edomainnlive Query 499 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`\n INNER JOIN `inventory_stock_5` AS `inventory_in_stock` ON e.sku = inventory_in_stock.sku\n 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'\n 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\n INNER JOIN `catalog_product_entity` AS `product` ON product.entity_id = e.entity_id\n INNER JOIN `inventory_stock_5` AS `stock_status_index` ON product.sku = stock_status_index.sku\n INNER JOIN `catalog_product_link` AS `links` ON links.linked_product_id = e.entity_id AND links.link_type_id = 1\n 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'\n 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'\n 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 ('170087')) AND (`e`.`entity_id` != '170087') ORDER BY `position` ASC 0.000
|
216584 db_edomainnlive localhost db_edomainnlive Query 499 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`\n INNER JOIN `inventory_stock_5` AS `inventory_in_stock` ON e.sku = inventory_in_stock.sku\n 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'\n 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\n INNER JOIN `catalog_product_entity` AS `product` ON product.entity_id = e.entity_id\n INNER JOIN `inventory_stock_5` AS `stock_status_index` ON product.sku = stock_status_index.sku\n INNER JOIN `catalog_product_link` AS `links` ON links.linked_product_id = e.entity_id AND links.link_type_id = 1\n 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'\n 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'\n 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 ('126070')) AND (`e`.`entity_id` != '126070') ORDER BY `position` ASC 0.000
|
216599 db_edomainnlive localhost db_edomainnlive Query 493 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` FROM `catalog_product_entity` AS `e`\n INNER JOIN `inventory_stock_7` AS `inventory_in_stock` ON e.sku = inventory_in_stock.sku\n 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 = '1'\n INNER JOIN `catalog_category_product_index_store1` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=1 AND cat_index.visibility IN(2, 4) AND cat_index.category_id=2\n INNER JOIN `catalog_product_entity` AS `product` ON product.entity_id = e.entity_id\n INNER JOIN `inventory_stock_7` AS `stock_status_index` ON product.sku = stock_status_index.sku\n INNER JOIN `catalog_product_link` AS `links` ON links.linked_product_id = e.entity_id AND links.link_type_id = 4\n 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 = '3'\n 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 ('181382')) AND (`e`.`entity_id` != '181382') ORDER BY `position` ASC 0.000
|
216603 db_edomainnlive localhost db_edomainnlive Query 491 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`\n INNER JOIN `inventory_stock_7` AS `inventory_in_stock` ON e.sku = inventory_in_stock.sku\n 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 = '1'\n INNER JOIN `catalog_category_product_index_store1` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=1 AND cat_index.visibility IN(2, 4) AND cat_index.category_id=2\n INNER JOIN `catalog_product_entity` AS `product` ON product.entity_id = e.entity_id\n INNER JOIN `inventory_stock_7` AS `stock_status_index` ON product.sku = stock_status_index.sku\n INNER JOIN `catalog_product_link` AS `links` ON links.linked_product_id = e.entity_id AND links.link_type_id = 1\n 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'\n 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'\n 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 ('79444')) AND (`e`.`entity_id` != '79444') ORDER BY `position` ASC 0.000
|
216650 db_edomainnlive localhost db_edomainnlive Query 478 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`\n INNER JOIN `inventory_stock_10` AS `inventory_in_stock` ON e.sku = inventory_in_stock.sku\n 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 = '4'\n INNER JOIN `catalog_category_product_index_store7` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=7 AND cat_index.visibility IN(2, 4) AND cat_index.category_id=562\n INNER JOIN `catalog_product_entity` AS `product` ON product.entity_id = e.entity_id\n INNER JOIN `inventory_stock_10` AS `stock_status_index` ON product.sku = stock_status_index.sku\n INNER JOIN `catalog_product_link` AS `links` ON links.linked_product_id = e.entity_id AND links.link_type_id = 1\n 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'\n 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'\n 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 ('132878')) AND (`e`.`entity_id` != '132878') ORDER BY `position` ASC 0.000
|
I couldn't find the exact ones but I found some slow ones
# Time: 230903 13:29:28
|
# User@Host: db_edomainnlive[db_edomainnlive] @ localhost []
|
# Thread_id: 185313 Schema: db_edomainnlive QC_hit: No
|
# Query_time: 347.890589 Lock_time: 0.000139 Rows_sent: 0 Rows_examined: 84394
|
# Rows_affected: 0 Bytes_sent: 2420
|
SET timestamp=1693740568;
|
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 ('113708')) AND (`e`.`entity_id` != '113708') ORDER BY `position` ASC;
|
# Time: 230903 13:31:12
|
# User@Host: db_edomainnlive[db_edomainnlive] @ localhost []
|
# Thread_id: 181348 Schema: db_edomainnlive QC_hit: No
|
# Query_time: 240.001009 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0
|
# Rows_affected: 0 Bytes_sent: 67
|
SET timestamp=1693740672;
|
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;
|
# Time: 230903 13:35:34
|
# User@Host: db_edomainnlive[db_edomainnlive] @ localhost []
|
# Thread_id: 186519 Schema: db_edomainnlive QC_hit: No
|
# Query_time: 73.412018 Lock_time: 0.000440 Rows_sent: 1 Rows_examined: 448006260
|
# Rows_affected: 0 Bytes_sent: 5010
|
When testing the same queries, they ran really fast at <100ms
[2023-09-07 12:42:03] 0 rows retrieved in 145 ms (execution: 77 ms, fetching: 68 ms)
|
|
This one has an explain with it
# Time: 230907 11:35:51
|
# User@Host: db_edomainnlive[db_edomainnlive] @ localhost []
|
# Thread_id: 216603 Schema: db_edomainnlive QC_hit: No
|
# Query_time: 841.810160 Lock_time: 0.000311 Rows_sent: 0 Rows_examined: 991633941
|
# Rows_affected: 0 Bytes_sent: 2419
|
# Tmp_tables: 1 Tmp_disk_tables: 0 Tmp_table_sizes: 0
|
# Full_scan: Yes Full_join: Yes Tmp_table: Yes Tmp_table_on_disk: No
|
# Filesort: Yes 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 84429.00 100.00 26.37 Using where; Using temporary; Using filesort
|
# explain: 1 SIMPLE stock_status_index ALL PRIMARY,index_sku_qty NULL NULL NULL 1 84429.00 100.00 26.37 Using where; Using join buffer (flat, BNL join)
|
# explain: 1 SIMPLE links 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 6 const,const 1 1.00 100.00 100.00 Using index
|
# explain: 1 SIMPLE cat_index eq_ref PRIMARY,CAT_CTGR_PRD_IDX_STORE1_PRD_ID_STORE_ID_CTGR_ID_VISIBILITY,IDX_216E521C8AD125E066D2B0BAB4A08412 PRIMARY 10 const,db_edomainnlive.links.linked_product_id,const 1 1.00 100.00 100.00 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.links.linked_product_id,const,const 1 0.00 100.00 100.00
|
# explain: 1 SIMPLE e eq_ref PRIMARY,CATALOG_PRODUCT_ENTITY_SKU PRIMARY 4 db_edomainnlive.links.linked_product_id 1 NULL 100.00 NULL Using where
|
# explain: 1 SIMPLE product eq_ref PRIMARY,CATALOG_PRODUCT_ENTITY_SKU PRIMARY 4 db_edomainnlive.links.linked_product_id 1 NULL 100.00 NULL Using where
|
# explain: 1 SIMPLE product_entity_table eq_ref PRIMARY PRIMARY 4 db_edomainnlive.links.product_id 1 NULL 100.00 NULL 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 NULL 100.00 NULL
|
# 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 7 const,db_edomainnlive.links.link_id 1 NULL 100.00 NULL
|
#
|
SET timestamp=1694079351;
|
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_7` 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 = '1'
|
INNER JOIN `catalog_category_product_index_store1` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=1 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_7` 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 ('79444')) AND (`e`.`entity_id` != '79444') ORDER BY `position` ASC;
|
Actual time normally
[2023-09-07 12:46:25] 0 rows retrieved in 119 ms (execution: 75 ms, fetching: 44 ms)
|
|
This time I was able to catch it at the point where 6 SELECT queries that normally run very fast currently are stuck in over 700seconds and also the slow log caught one of them when it finished.
Here it is
# Time: 230910 20:43:29
|
# User@Host: db_edomainnlive[db_edomainnlive] @ localhost []
|
# Thread_id: 18888 Schema: db_edomainnlive QC_hit: No
|
# Query_time: 762.878932 Lock_time: 0.000242 Rows_sent: 0 Rows_examined: 86987
|
# Rows_affected: 0 Bytes_sent: 2306
|
# Tmp_tables: 1 Tmp_disk_tables: 0 Tmp_table_sizes: 0
|
# Full_scan: Yes Full_join: Yes Tmp_table: Yes Tmp_table_on_disk: No
|
# Filesort: Yes 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 86987.00 100.00 33.06 Using where; Using temporary; Using filesort
|
# explain: 1 SIMPLE stock_status_index ALL PRIMARY,index_sku_qty NULL NULL NULL 1 86987.00 100.00 33.06 Using where; Using join buffer (flat, BNL join)
|
# explain: 1 SIMPLE links 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 6 const,const 1 0.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 NULL 100.00 NULL
|
# explain: 1 SIMPLE cat_index eq_ref PRIMARY,CAT_CTGR_PRD_IDX_STORE5_PRD_ID_STORE_ID_CTGR_ID_VISIBILITY,IDX_D66B6557126C2DE627A049511C72BE10 PRIMARY 10 const,db_edomainnlive.links.linked_product_id,const 1 NULL 100.00 NULL 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.links.linked_product_id,const,const 1 NULL 100.00 NULL
|
# explain: 1 SIMPLE e eq_ref PRIMARY,CATALOG_PRODUCT_ENTITY_SKU PRIMARY 4 db_edomainnlive.links.linked_product_id 1 NULL 100.00 NULL Using where
|
# explain: 1 SIMPLE product eq_ref PRIMARY,CATALOG_PRODUCT_ENTITY_SKU PRIMARY 4 db_edomainnlive.links.linked_product_id 1 NULL 100.00 NULL Using where
|
# explain: 1 SIMPLE product_entity_table eq_ref PRIMARY PRIMARY 4 db_edomainnlive.links.product_id 1 NULL 100.00 NULL Using index
|
#
|
SET timestamp=1694371409;
|
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` 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 = 4
|
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 = '3'
|
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 ('163212')) AND (`e`.`entity_id` != '163212') ORDER BY `position` ASC;
|
Attached you can find all the above information I was giving so far in file debug_20230910214351.zip
|
|
Let me add one more example query that normally runs fast but took 2000sec
# Thread_id: 360163 Schema: db_edomainnlive QC_hit: No
|
# Query_time: 2400.601619 Lock_time: 0.000116 Rows_sent: 6 Rows_examined: 1580173995
|
# Rows_affected: 0 Bytes_sent: 3463
|
# 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: Yes 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 85645.00 100.00 33.52 Using where; Using temporary; Using filesort
|
# explain: 1 SIMPLE stock_status_index ALL PRIMARY,index_sku_qty NULL NULL NULL 1 85645.00 100.00 33.52 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,CAT_CTGR_PRD_IDX_STORE5_PRD_ID_STORE_ID_CTGR_ID_VISIBILITY,IDX_D66B6557126C2DE627A049511C72BE10 PRIMARY 10 const,db_edomainnlive.product.entity_id,const 1 0.31 100.00 99.95 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
|
This was caught in the slow log
When I execute it normally it will present a different EXPLAIN and run lightning fast. Why would it do something different when I run it, and different when it runs by itself? I dont' get it here if it's not bug I'm not sure what it is.
+--+-----------+---------------------------+------+-------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------+-------+---------------------------------------------------+----+--------------------------------------------+
|
|id|select_type|table |type |possible_keys |key |key_len|ref |rows|Extra |
|
+--+-----------+---------------------------+------+-------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------+-------+---------------------------------------------------+----+--------------------------------------------+
|
|1 |SIMPLE |links |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|6 |const,const |6 |Using index; Using temporary; Using filesort|
|
|1 |SIMPLE |cat_index |eq_ref|PRIMARY,CAT_CTGR_PRD_IDX_STORE5_PRD_ID_STORE_ID_CTGR_ID_VISIBILITY,IDX_D66B6557126C2DE627A049511C72BE10 |PRIMARY |10 |const,db_edomainnlive.links.linked_product_id,const|1 |Using where |
|
|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.links.linked_product_id,const,const|1 | |
|
|1 |SIMPLE |e |eq_ref|PRIMARY,CATALOG_PRODUCT_ENTITY_SKU |PRIMARY |4 |db_edomainnlive.links.linked_product_id |1 |Using where |
|
|1 |SIMPLE |inventory_in_stock |eq_ref|PRIMARY,index_sku_qty |PRIMARY |194 |db_edomainnlive.e.sku |1 |Using where |
|
|1 |SIMPLE |product |eq_ref|PRIMARY,CATALOG_PRODUCT_ENTITY_SKU |PRIMARY |4 |db_edomainnlive.links.linked_product_id |1 |Using where |
|
|1 |SIMPLE |stock_status_index |eq_ref|PRIMARY,index_sku_qty |PRIMARY |194 |db_edomainnlive.product.sku |1 |Using where |
|
|1 |SIMPLE |product_entity_table |eq_ref|PRIMARY |PRIMARY |4 |db_edomainnlive.links.product_id |1 |Using index |
|
|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 |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 |7 |const,db_edomainnlive.links.link_id |1 | |
|
+--+-----------+---------------------------+------+-------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------+-------+---------------------------------------------------+----+--------------------------------------------+
|
The query in question
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 ('181040'))
|
AND (`e`.`entity_id` != '181040')
|
ORDER BY `position` ASC;
|
|
|
After careful examination of the slow queries I noticed that in each and every case the query plan changes and uses a full table scan make it slow. While whenever I run it separately it doesn't use a full table scan.
I decided to dig deeper into the select queries that run before the rename table query and added an index to the is_salable and sku column of inventory_stock_<No> tables.
Now I have this explain which made me more confused
The query takes 2667seconds to finish, the lock time is very low
There's no full scan, full join, or tmp table on disk
Everything in my eyes appear normal but the time it executes.
What could be the reason it is slow here?
# Time: 230918 12:29:22
|
# User@Host: db_edomainnlive[db_edomainnlive] @ localhost []
|
# Thread_id: 2128135 Schema: db_edomainnlive QC_hit: No
|
# Query_time: 2645.962335 Lock_time: 0.000091 Rows_sent: 0 Rows_examined: 1094333226
|
# 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 17071.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 22144.90 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_STORE1_PRD_ID_STORE_ID_CTGR_ID_VISIBILITY,IDX_216E521C8AD125E066D2B0BAB4A08412 PRIMARY 10 const,db_edomainnlive.product.entity_id,const 1 0.30 100.00 99.88 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 7 const,db_edomainnlive.links.link_id 1 0.00 100.00 100.00
|
#
|
SET timestamp=1695032962;
|
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_7` 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 = '1'
|
INNER JOIN `catalog_category_product_index_store1` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=1 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_7` 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 ('179427')) AND (`e`.`entity_id` != '179427') ORDER BY `position` ASC;
|
|
|
I think these queries never end to be honest. THey can run infinitely until they timeout.
There's no reason for the to run so slow as every time I ran them they run really fast. They use now indexes fully. They don't do full table scans. Disk is not used. At least at some point they should finish executing.
If it was any other application, I would consider this situation something like an infinite loop where it infinitely grows never ending until resources are exhausted.
I'm not sure how it would apply in mariadb but for some reason the behavior appears similar. The longer it runs, the more rows it examines. It never ends stuck in sending data phase.
Memory is neither increasing nor decreasing so that means all data is already in there.
I only see the result in the slow log when it times out or when I kill the query.
Any info on what we can further do to examine why this query never ends while normally it's fast?
|
|
Same here
# Time: 230918 17:20:53
|
# User@Host: db_edomainnlive[db_edomainnlive] @ localhost []
|
# Thread_id: 2186697 Schema: db_edomainnlive QC_hit: No
|
# Query_time: 5338.156936 Lock_time: 0.000128 Rows_sent: 0 Rows_examined: 2051298060
|
# Rows_affected: 0 Bytes_sent: 2421
|
# Tmp_tables: 1 Tmp_disk_tables: 0 Tmp_table_sizes: 0
|
# Full_scan: No Full_join: No Tmp_table: Yes Tmp_table_on_disk: No
|
# Filesort: Yes 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 product_entity_table const PRIMARY PRIMARY 4 const 1 NULL 100.00 NULL Using index; Using temporary; Using filesort
|
# explain: 1 SIMPLE inventory_in_stock ref PRIMARY,index_sku_qty,index_is_salable,index_sku index_is_salable 1 const 1 28495.00 100.00 100.00 Using index
|
# explain: 1 SIMPLE stock_status_index ref PRIMARY,index_sku_qty,index_is_salable,index_sku index_is_salable 1 const 1 28495.00 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 where; Using index
|
# explain: 1 SIMPLE cat_index eq_ref PRIMARY,IDX_C745732E55C32D6FA5D2C9868E174B08,IDX_8E65224CF04CDBE62BE589AFCF1494B1 PRIMARY 10 const,db_edomainnlive.product.entity_id,const 1 0.18 100.00 100.00 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 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 NULL 100.00 NULL
|
# 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 7 const,db_edomainnlive.links.link_id 1 NULL 100.00 NULL
|
#
|
SET timestamp=1695050453;
|
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_12` 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 = '6'
|
INNER JOIN `catalog_category_product_index_store11` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=11 AND cat_index.visibility IN(2, 4) AND cat_index.category_id=1084
|
INNER JOIN `catalog_product_entity` AS `product` ON product.entity_id = e.entity_id
|
INNER JOIN `inventory_stock_12` 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 (70281)) AND (`e`.`entity_id` != 70281) ORDER BY `position` ASC;
|
Query stuck in sending data for 5000+ seconds, and examines double the rows than before for a query that returns a 0 result set.
```
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_12` 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 = '6'
-> INNER JOIN `catalog_category_product_index_store11` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=11 AND cat_index.visibility IN(2, 4) AND cat_index.category_id=1084
-> INNER JOIN `catalog_product_entity` AS `product` ON product.entity_id = e.entity_id
-> INNER JOIN `inventory_stock_12` 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 (70281)) AND (`e`.`entity_id` != 70281) ORDER BY `position` ASC;
Empty set (0.001 sec)
```
|
|
In a last resort I attempted to upgrade to mariadb 10.6 and the issue persists.
Those queries sometimes become very slow for no apparent reason with millions of rows examined.
```
- Time: 230919 15:05:07
- User@Host: db_edomainnlive[db_edomainnlive] @ localhost []
- Thread_id: 44803 Schema: db_edomainnlive QC_hit: No
- Query_time: 388.827478 Lock_time: 0.000285 Rows_sent: 0 Rows_examined: 199043934
- Rows_affected: 0 Bytes_sent: 0
#
- 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 5822.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 17093.62 100.00 100.00 Using index
- explain: 1 SIMPLE e ref PRIMARY,CATALOG_PRODUCT_ENTITY_SKU CATALOG_PRODUCT_ENTITY_SKU 195 db_edomainnlive.inventory_in_stock.sku 1 1.00 100.00 100.00 Using index condition
- 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.e.entity_id 1 0.00 100.00 100.00 Using index
- explain: 1 SIMPLE cat_index eq_ref PRIMARY,IDX_4B965DC45C352D6E4C9DC0FF50B1FCF5,IDX_47AB760CD6A893ACEA69A9C2E0112C60 PRIMARY 10 const,db_edomainnlive.e.entity_id,const 1 NULL 100.00 NULL 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.e.entity_id,const,const 1NULL 100.00 NULL
- explain: 1 SIMPLE product eq_ref PRIMARY,CATALOG_PRODUCT_ENTITY_SKU PRIMARY 4 db_edomainnlive.e.entity_id 1 NULL 100.00 NULL Using where
- explain: 1 SIMPLE product_entity_table eq_ref PRIMARY PRIMARY 4 db_edomainnlive.links.product_id 1 NULL 100.00 NULL 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 NULL 100.00 NULL
- 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 NULL 100.00 NULL
#
SET timestamp=1695128707;
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_7` 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 = '1'
INNER JOIN `catalog_category_product_index_store1` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=1 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_7` 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 ('113815')) AND (`e`.`entity_id` != '113815') ORDER BY `position` ASC;
```
But when executing normally
+--+-----------+---------------------------+------+-------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------+-------+---------------------------------------------------+----+--------------------------------------------+
|
|id|select_type|table |type |possible_keys |key |key_len|ref |rows|Extra |
|
+--+-----------+---------------------------+------+-------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------+-------+---------------------------------------------------+----+--------------------------------------------+
|
|1 |SIMPLE |links |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|6 |const,const |2 |Using index; Using temporary; Using filesort|
|
|1 |SIMPLE |cat_index |eq_ref|PRIMARY,IDX_4B965DC45C352D6E4C9DC0FF50B1FCF5,IDX_47AB760CD6A893ACEA69A9C2E0112C60 |PRIMARY |10 |const,db_edomainnlive.links.linked_product_id,const|1 |Using where |
|
|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.links.linked_product_id,const,const|1 | |
|
|1 |SIMPLE |e |eq_ref|PRIMARY,CATALOG_PRODUCT_ENTITY_SKU |PRIMARY |4 |db_edomainnlive.links.linked_product_id |1 |Using where |
|
|1 |SIMPLE |inventory_in_stock |eq_ref|PRIMARY,index_sku_qty,index_is_salable,index_sku |PRIMARY |194 |db_edomainnlive.e.sku |1 |Using where |
|
|1 |SIMPLE |product |eq_ref|PRIMARY,CATALOG_PRODUCT_ENTITY_SKU |PRIMARY |4 |db_edomainnlive.links.linked_product_id |1 |Using where |
|
|1 |SIMPLE |stock_status_index |eq_ref|PRIMARY,index_sku_qty,index_is_salable,index_sku |PRIMARY |194 |db_edomainnlive.product.sku |1 |Using where |
|
|1 |SIMPLE |product_entity_table |eq_ref|PRIMARY |PRIMARY |4 |db_edomainnlive.links.product_id |1 |Using index |
|
|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 |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 |7 |const,db_edomainnlive.links.link_id |1 | |
|
+--+-----------+---------------------------+------+-------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------+-------+---------------------------------------------------+----+--------------------------------------------+
|
|
db_edomainnlive> 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_7` 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 = '1'
|
INNER JOIN `catalog_category_product_index_store1` AS `cat_index`
|
ON cat_index.product_id = e.entity_id AND cat_index.store_id = 1 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_7` 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 ('113815'))
|
AND (`e`.`entity_id` != '113815')
|
ORDER BY `position` ASC
|
[2023-09-19 16:06:25] 0 rows retrieved in 165 ms (execution: 82 ms, fetching: 83 ms)
|
How can I see the rows examined in my normal query when it executes fast to compare the difference? Any suggestion?
@Sergei ?
|
|
It seems it's the optimizer's fault in the particular query. For some reason sometimes it will plan the query perfectly fine by limiting the rows properly, and sometimes it will do something weird taking ages to finish.
By removing the double join on is_salable, it seems the optimizer plans the query perfectly without issues. However sometimes we may need to have the same table joined twice due to a different condition so I'm not sure why this should be a problem.
Any ideas why it picks different plans for the same query randomly?
|
|
Since you now are on 10.6, can you please give MDEV-31577 a try, by prepending your problematic SELECT statements with ANALYZE FORMAT=JSON? Save the outputs for both fast and slow runs, and compare them. Another useful diagnosis tool could be the optimizer trace.
|
|
CUrrently it's not possible to provide this because I've already updated the query to a format that would not confuse the optimizer to stop the production site from dropping.
However the underlying issue is with the optimizer as it chose different execution plans in specific times leading to downtimes instead of the optimal execution plan
|
debug_20230904135015.zip
processlist-202309011403.txt
queries stuck in sending state.jpg
