Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.5.10, 10.5.15
-
CloudLinux release 8.5
Kernel: 4.18.0-305.17.1.lve.el8.x86_64
MariaDB: 10.5.10-MariaDB-log-cll-lve and 10.5.15-MariaDB-cll-lve-log
/var/lib/mysql filesystem: ZFS
Description
Since updating to 10.5, sometimes performance collapses. Queries that normally take less then a second, can take multiple minutes. The time is spent in state "Sending data"
MariaDB [dbname]> SELECT SQL_CALC_FOUND_ROWS DISTINCT lm_posts.ID FROM lm_posts INNER JOIN lm_postmeta ON ( lm_posts.ID = lm_postmeta.post_id ) LEFT JOIN lm_postmeta espm ON (lm_posts.ID = espm.post_id) WHERE 1=1 AND ( lm_posts.ID NOT IN ( SELECT object_id FROM lm_term_relationships WHERE term_taxonomy_id IN (6) ) ) AND ( ((lm_posts.post_title LIKE '%test%') OR (lm_posts.post_content LIKE '%test%') OR (espm.meta_key = 'ean_artikel' AND espm.meta_value LIKE '%test%') OR (espm.meta_key = 'hwp_product_gtin' AND espm.meta_value LIKE '%test%') OR (espm.meta_key = '_product_attributes' AND espm.meta_value LIKE '%test%'))) AND (lm_posts.post_password = '') AND ( lm_postmeta.meta_key = 'webwinkelnummer' ) AND ((lm_posts.post_type = 'product' AND (lm_posts.post_status = 'publish' OR lm_posts.post_status = 'acf-disabled' OR lm_posts.post_status = 'cwg_mailsent' OR lm_posts.post_status = 'cwg_mailnotsent' OR lm_posts.post_status = 'cwg_subscribed' OR lm_posts.post_status = 'cwg_unsubscribed' OR lm_posts.post_status = 'cwg_converted'))) GROUP BY lm_posts.ID ORDER BY lm_postmeta.meta_value ASC LIMIT 0, 18;
|
+-------+
|
| ID |
|
+-------+
|
| 39617 |
|
| 37285 |
|
| 37288 |
|
| 43343 |
|
| 43624 |
|
+-------+
|
5 rows in set (4.531 sec)
|
 |
MariaDB [dbname]> SHOW PROFILE ALL;
|
+------------------------+----------+-----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------+---------------+-------------+
|
| Status | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Messages_sent | Messages_received | Page_faults_major | Page_faults_minor | Swaps | Source_function | Source_file | Source_line |
|
+------------------------+----------+-----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------+---------------+-------------+
|
| Starting | 0.000216 | 0.001321 | 0.000378 | 22 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | NULL | NULL | NULL |
|
| checking permissions | 0.000010 | 0.000008 | 0.000002 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_parse.cc | 6810 |
|
| Opening tables | 0.001523 | 0.002349 | 0.003055 | 174 | 0 | 119 | 9 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_base.cc | 4207 |
|
| After opening tables | 0.000018 | 0.000015 | 0.000003 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_base.cc | 4464 |
|
| System lock | 0.000006 | 0.000005 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | lock.cc | 337 |
|
| table lock | 0.000007 | 0.000006 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | lock.cc | 342 |
|
| Opening tables | 0.000029 | 0.000104 | 0.000025 | 10 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_base.cc | 4207 |
|
| After opening tables | 0.000007 | 0.000009 | 0.000002 | 0 | 0 | 0 | 8 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_base.cc | 4464 |
|
| System lock | 0.000007 | 0.000005 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | lock.cc | 337 |
|
| table lock | 0.000063 | 0.000186 | 0.000043 | 12 | 0 | 0 | 0 | 0 | 0 | 0 | 1 | 0 | <unknown> | lock.cc | 342 |
|
| Unlocking tables | 0.000010 | 0.000008 | 0.000002 | 0 | 0 | 0 | 8 | 0 | 0 | 0 | 0 | 0 | <unknown> | lock.cc | 429 |
|
| closing tables | 0.000011 | 0.000009 | 0.000002 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_base.cc | 784 |
|
| init | 0.000059 | 0.000085 | 0.000020 | 1 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 4735 |
|
| Optimizing | 0.000043 | 0.000109 | 0.000025 | 10 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 1833 |
|
| Statistics | 0.004121 | 0.008060 | 0.006150 | 245 | 1 | 1458 | 219 | 0 | 0 | 0 | 1 | 0 | <unknown> | sql_select.cc | 2292 |
|
| Preparing | 0.000128 | 0.000847 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 2367 |
|
| Optimizing | 0.000010 | 0.000011 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 1833 |
|
| Statistics | 0.000648 | 0.002006 | 0.000000 | 56 | 0 | 140 | 38 | 0 | 0 | 0 | 2 | 0 | <unknown> | sql_select.cc | 2292 |
|
| Preparing | 0.000024 | 0.000019 | 0.000004 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 2367 |
|
| Creating tmp table | 0.000012 | 0.000010 | 0.000003 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 3773 |
|
| Sorting result | 0.000011 | 0.000008 | 0.000002 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 3654 |
|
| Executing | 0.000004 | 0.000004 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 4303 |
|
| Sending data | 0.001191 | 0.001120 | 0.001020 | 64 | 0 | 405 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 4499 |
|
| Executing | 0.000011 | 0.000023 | 0.000005 | 0 | 0 | 32 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 4303 |
|
| Sending data | 0.614984 | 1.434036 | 0.425445 | 21108 | 613 | 77905 | 7601 | 0 | 0 | 0 | 4917 | 0 | <unknown> | sql_select.cc | 4499 |
|
| Removing tmp table | 0.000062 | 0.000000 | 0.000496 | 7 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 20099 |
|
| Sending data | 3.907354 | 11.211695 | 2.927629 | 167971 | 2303 | 430289 | 64814 | 0 | 0 | 0 | 22580 | 0 | <unknown> | sql_select.cc | 20132 |
|
| Creating sort index | 0.000083 | 0.000178 | 0.000042 | 1 | 0 | 0 | 0 | 0 | 0 | 0 | 1 | 0 | <unknown> | sql_select.cc | 21811 |
|
| Removing tmp table | 0.000102 | 0.000156 | 0.000036 | 1 | 0 | 0 | 16 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 20099 |
|
| Creating sort index | 0.000007 | 0.000006 | 0.000002 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 20132 |
|
| End of update loop | 0.000006 | 0.000006 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 4779 |
|
| Query end | 0.000004 | 0.000002 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_parse.cc | 6117 |
|
| Commit | 0.000007 | 0.000006 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_parse.cc | 6163 |
|
| closing tables | 0.000003 | 0.000003 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_base.cc | 784 |
|
| Unlocking tables | 0.000004 | 0.000003 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | lock.cc | 429 |
|
| closing tables | 0.000014 | 0.000011 | 0.000003 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | lock.cc | 442 |
|
| Starting cleanup | 0.000005 | 0.000004 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_parse.cc | 6229 |
|
| Freeing items | 0.000015 | 0.000012 | 0.000002 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_parse.cc | 8177 |
|
| Removing tmp table | 0.000005 | 0.000004 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 20099 |
|
| Freeing items | 0.000038 | 0.000030 | 0.000008 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_select.cc | 20132 |
|
| Updating status | 0.000012 | 0.000010 | 0.000002 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_parse.cc | 2522 |
|
| Logging slow query | 0.000567 | 0.001816 | 0.000000 | 9 | 0 | 55 | 2 | 0 | 0 | 0 | 7 | 0 | <unknown> | sql_parse.cc | 2671 |
|
| Reset for next command | 0.000017 | 0.000017 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | <unknown> | sql_parse.cc | 2546 |
|
+------------------------+----------+-----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------+---------------+-------------+
|
43 rows in set (0.000 sec)
|
This this on a shared database of a hosting company, with many concurrent accesses. After restarting MariaDB things are a bit better for a while, but not as good as it was with 10.4
It might be a configuration issue, but I couldn't find anything obvious, and the same config was fine with 10.4.
Apart from this, we also see that (some) queries spend a lot more time in "Statistics" state than they used to.
If I can provide any more information, please let me know!
Attachments
Issue Links
- relates to
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-