Details
-
Bug
-
Status: Closed (View Workflow)
-
Minor
-
Resolution: Fixed
-
10.5.8, 10.2(EOL), 10.3(EOL), 10.4(EOL), 10.5
-
None
Description
MariaDB table_open_cache generates same and excessive number of advisory /proc/locks that causes OTHER programs on machine to waste cpu power ("sys load") when checking for locks. Are those really needed/worth it?
Executing lsof command while there are 100k locks in /proc/locks (made by mariadb with table_open_cache=100k) takes 2 minutes.
I see huge decrease in "sys" load after reducing table_open_cache from 100k to 4k on graphs.
Attachments
Issue Links
- causes
-
MDEV-28495 Corruption due to attempting to start up multiple servers on the same data
-
- Closed
-
-
MDEV-28662 [ERROR] mysqld got signal 11 after updating from 10.4.8 to 10.4.24
-
- Closed
-
-
MDEV-28697 One Node crashed and did not recover
-
- Closed
-
-
MDEV-28976 InnoDB: Missing FILE_CHECKPOINT
-
- Closed
-
- relates to
-
MDEV-31568 innodb protection against dual processes accessing data insufficient
-
- Closed
-
- links to
Activity
Field | Original Value | New Value |
---|---|---|
Description |
Mariadb 10.5.8 seems to be going crazy with making locks to infinity.
I never saw this problem before upgrading from 10.3 to 10.5 kernel version: 5.4.81 Obviously making so many locks has detrimental effects on system performance. Every time so many locks are checked cpu power is wasted (in linux seen as "sys" load). Executing lsof after a day of this while takes a minute. # cat /proc/locks|wc -l 25807 cat /proc/locks ..... 16114: POSIX ADVISORY WRITE 28588 09:03:14329073 0 EOF 16115: POSIX ADVISORY WRITE 28588 09:03:14329071 0 EOF 16116: POSIX ADVISORY WRITE 28588 09:03:14329048 0 EOF 16117: POSIX ADVISORY WRITE 28588 09:03:14329031 0 EOF 16126: POSIX ADVISORY WRITE 28588 09:03:14500929 0 EOF 16127: POSIX ADVISORY WRITE 28588 09:03:14185712 0 EOF 16128: POSIX ADVISORY WRITE 28588 09:03:14185704 0 EOF 16129: POSIX ADVISORY WRITE 28588 09:03:14185702 0 EOF 16130: POSIX ADVISORY WRITE 28588 09:03:14185708 0 EOF 16131: POSIX ADVISORY WRITE 28588 09:03:14185706 0 EOF 16132: POSIX ADVISORY WRITE 28588 09:03:14185700 0 EOF 16133: POSIX ADVISORY WRITE 28588 09:03:14185698 0 EOF 16151: POSIX ADVISORY WRITE 28588 09:03:14331588 0 EOF 16152: POSIX ADVISORY WRITE 28588 09:03:14332583 0 EOF 16153: POSIX ADVISORY WRITE 28588 09:03:14332354 0 EOF 16154: POSIX ADVISORY WRITE 28588 09:03:14332352 0 EOF 16155: POSIX ADVISORY WRITE 28588 09:03:14332348 0 EOF 16156: POSIX ADVISORY WRITE 28588 09:03:14332346 0 EOF 16158: POSIX ADVISORY WRITE 28588 09:03:14470103 0 EOF 16159: POSIX ADVISORY WRITE 28588 09:03:14470094 0 EOF 16160: POSIX ADVISORY WRITE 28588 09:03:14470075 0 EOF 16161: POSIX ADVISORY WRITE 28588 09:03:14460252 0 EOF 16162: POSIX ADVISORY WRITE 28588 09:03:14460248 0 EOF ..... if I kill mysqld all locks are gone in an instant |
Mariadb 10.5.8 seems to be going crazy with making locks to infinity.
I never saw this problem before upgrading from 10.3 to 10.5 kernel version: 5.4.81 , 4.19.162 Obviously making so many locks has detrimental effects on system performance. Every time so many locks are checked cpu power is wasted (in linux seen as "sys" load). Executing lsof after a day of this while takes a minute. # cat /proc/locks|wc -l 25807 cat /proc/locks ..... 16114: POSIX ADVISORY WRITE 28588 09:03:14329073 0 EOF 16115: POSIX ADVISORY WRITE 28588 09:03:14329071 0 EOF 16116: POSIX ADVISORY WRITE 28588 09:03:14329048 0 EOF 16117: POSIX ADVISORY WRITE 28588 09:03:14329031 0 EOF 16126: POSIX ADVISORY WRITE 28588 09:03:14500929 0 EOF 16127: POSIX ADVISORY WRITE 28588 09:03:14185712 0 EOF 16128: POSIX ADVISORY WRITE 28588 09:03:14185704 0 EOF 16129: POSIX ADVISORY WRITE 28588 09:03:14185702 0 EOF 16130: POSIX ADVISORY WRITE 28588 09:03:14185708 0 EOF 16131: POSIX ADVISORY WRITE 28588 09:03:14185706 0 EOF 16132: POSIX ADVISORY WRITE 28588 09:03:14185700 0 EOF 16133: POSIX ADVISORY WRITE 28588 09:03:14185698 0 EOF 16151: POSIX ADVISORY WRITE 28588 09:03:14331588 0 EOF 16152: POSIX ADVISORY WRITE 28588 09:03:14332583 0 EOF 16153: POSIX ADVISORY WRITE 28588 09:03:14332354 0 EOF 16154: POSIX ADVISORY WRITE 28588 09:03:14332352 0 EOF 16155: POSIX ADVISORY WRITE 28588 09:03:14332348 0 EOF 16156: POSIX ADVISORY WRITE 28588 09:03:14332346 0 EOF 16158: POSIX ADVISORY WRITE 28588 09:03:14470103 0 EOF 16159: POSIX ADVISORY WRITE 28588 09:03:14470094 0 EOF 16160: POSIX ADVISORY WRITE 28588 09:03:14470075 0 EOF 16161: POSIX ADVISORY WRITE 28588 09:03:14460252 0 EOF 16162: POSIX ADVISORY WRITE 28588 09:03:14460248 0 EOF ..... if I kill mysqld all locks are gone in an instant |
Description |
Mariadb 10.5.8 seems to be going crazy with making locks to infinity.
I never saw this problem before upgrading from 10.3 to 10.5 kernel version: 5.4.81 , 4.19.162 Obviously making so many locks has detrimental effects on system performance. Every time so many locks are checked cpu power is wasted (in linux seen as "sys" load). Executing lsof after a day of this while takes a minute. # cat /proc/locks|wc -l 25807 cat /proc/locks ..... 16114: POSIX ADVISORY WRITE 28588 09:03:14329073 0 EOF 16115: POSIX ADVISORY WRITE 28588 09:03:14329071 0 EOF 16116: POSIX ADVISORY WRITE 28588 09:03:14329048 0 EOF 16117: POSIX ADVISORY WRITE 28588 09:03:14329031 0 EOF 16126: POSIX ADVISORY WRITE 28588 09:03:14500929 0 EOF 16127: POSIX ADVISORY WRITE 28588 09:03:14185712 0 EOF 16128: POSIX ADVISORY WRITE 28588 09:03:14185704 0 EOF 16129: POSIX ADVISORY WRITE 28588 09:03:14185702 0 EOF 16130: POSIX ADVISORY WRITE 28588 09:03:14185708 0 EOF 16131: POSIX ADVISORY WRITE 28588 09:03:14185706 0 EOF 16132: POSIX ADVISORY WRITE 28588 09:03:14185700 0 EOF 16133: POSIX ADVISORY WRITE 28588 09:03:14185698 0 EOF 16151: POSIX ADVISORY WRITE 28588 09:03:14331588 0 EOF 16152: POSIX ADVISORY WRITE 28588 09:03:14332583 0 EOF 16153: POSIX ADVISORY WRITE 28588 09:03:14332354 0 EOF 16154: POSIX ADVISORY WRITE 28588 09:03:14332352 0 EOF 16155: POSIX ADVISORY WRITE 28588 09:03:14332348 0 EOF 16156: POSIX ADVISORY WRITE 28588 09:03:14332346 0 EOF 16158: POSIX ADVISORY WRITE 28588 09:03:14470103 0 EOF 16159: POSIX ADVISORY WRITE 28588 09:03:14470094 0 EOF 16160: POSIX ADVISORY WRITE 28588 09:03:14470075 0 EOF 16161: POSIX ADVISORY WRITE 28588 09:03:14460252 0 EOF 16162: POSIX ADVISORY WRITE 28588 09:03:14460248 0 EOF ..... if I kill mysqld all locks are gone in an instant |
Mariadb 10.5.8 seems to be going crazy with making locks to infinity.
I never saw this problem before upgrading from 10.3 to 10.5 kernel version: 5.4.81 , 4.19.162 Obviously making so many locks has detrimental effects on system performance. Every time so many locks are checked cpu power is wasted (in linux seen as "sys" load). Executing lsof after a day of this while takes a minute. cat /proc/locks|wc -l 25807 cat /proc/locks ..... 16114: POSIX ADVISORY WRITE 28588 09:03:14329073 0 EOF 16115: POSIX ADVISORY WRITE 28588 09:03:14329071 0 EOF 16116: POSIX ADVISORY WRITE 28588 09:03:14329048 0 EOF 16117: POSIX ADVISORY WRITE 28588 09:03:14329031 0 EOF 16126: POSIX ADVISORY WRITE 28588 09:03:14500929 0 EOF 16127: POSIX ADVISORY WRITE 28588 09:03:14185712 0 EOF 16128: POSIX ADVISORY WRITE 28588 09:03:14185704 0 EOF 16129: POSIX ADVISORY WRITE 28588 09:03:14185702 0 EOF 16130: POSIX ADVISORY WRITE 28588 09:03:14185708 0 EOF 16131: POSIX ADVISORY WRITE 28588 09:03:14185706 0 EOF 16132: POSIX ADVISORY WRITE 28588 09:03:14185700 0 EOF 16133: POSIX ADVISORY WRITE 28588 09:03:14185698 0 EOF 16151: POSIX ADVISORY WRITE 28588 09:03:14331588 0 EOF 16152: POSIX ADVISORY WRITE 28588 09:03:14332583 0 EOF 16153: POSIX ADVISORY WRITE 28588 09:03:14332354 0 EOF 16154: POSIX ADVISORY WRITE 28588 09:03:14332352 0 EOF 16155: POSIX ADVISORY WRITE 28588 09:03:14332348 0 EOF 16156: POSIX ADVISORY WRITE 28588 09:03:14332346 0 EOF 16158: POSIX ADVISORY WRITE 28588 09:03:14470103 0 EOF 16159: POSIX ADVISORY WRITE 28588 09:03:14470094 0 EOF 16160: POSIX ADVISORY WRITE 28588 09:03:14470075 0 EOF 16161: POSIX ADVISORY WRITE 28588 09:03:14460252 0 EOF 16162: POSIX ADVISORY WRITE 28588 09:03:14460248 0 EOF ..... if I kill mysqld all locks are gone in an instant |
Labels | need_feedback |
Labels | need_feedback |
Priority | Critical [ 2 ] | Minor [ 4 ] |
Summary | mariadb 10.5.8 making inifinite number of locks (/proc/locks) | mariadb table_open_cache if making |
Summary | mariadb table_open_cache if making | mariadb table_open_cache is creating a lot of advisory /proc/locks which causes increase "sys" load |
Description |
Mariadb 10.5.8 seems to be going crazy with making locks to infinity.
I never saw this problem before upgrading from 10.3 to 10.5 kernel version: 5.4.81 , 4.19.162 Obviously making so many locks has detrimental effects on system performance. Every time so many locks are checked cpu power is wasted (in linux seen as "sys" load). Executing lsof after a day of this while takes a minute. cat /proc/locks|wc -l 25807 cat /proc/locks ..... 16114: POSIX ADVISORY WRITE 28588 09:03:14329073 0 EOF 16115: POSIX ADVISORY WRITE 28588 09:03:14329071 0 EOF 16116: POSIX ADVISORY WRITE 28588 09:03:14329048 0 EOF 16117: POSIX ADVISORY WRITE 28588 09:03:14329031 0 EOF 16126: POSIX ADVISORY WRITE 28588 09:03:14500929 0 EOF 16127: POSIX ADVISORY WRITE 28588 09:03:14185712 0 EOF 16128: POSIX ADVISORY WRITE 28588 09:03:14185704 0 EOF 16129: POSIX ADVISORY WRITE 28588 09:03:14185702 0 EOF 16130: POSIX ADVISORY WRITE 28588 09:03:14185708 0 EOF 16131: POSIX ADVISORY WRITE 28588 09:03:14185706 0 EOF 16132: POSIX ADVISORY WRITE 28588 09:03:14185700 0 EOF 16133: POSIX ADVISORY WRITE 28588 09:03:14185698 0 EOF 16151: POSIX ADVISORY WRITE 28588 09:03:14331588 0 EOF 16152: POSIX ADVISORY WRITE 28588 09:03:14332583 0 EOF 16153: POSIX ADVISORY WRITE 28588 09:03:14332354 0 EOF 16154: POSIX ADVISORY WRITE 28588 09:03:14332352 0 EOF 16155: POSIX ADVISORY WRITE 28588 09:03:14332348 0 EOF 16156: POSIX ADVISORY WRITE 28588 09:03:14332346 0 EOF 16158: POSIX ADVISORY WRITE 28588 09:03:14470103 0 EOF 16159: POSIX ADVISORY WRITE 28588 09:03:14470094 0 EOF 16160: POSIX ADVISORY WRITE 28588 09:03:14470075 0 EOF 16161: POSIX ADVISORY WRITE 28588 09:03:14460252 0 EOF 16162: POSIX ADVISORY WRITE 28588 09:03:14460248 0 EOF ..... if I kill mysqld all locks are gone in an instant |
table_open_cache is creating a same number of ADVISORY /proc/locks. Higher number of locks = increased "sys" load when other programs running on same machine check for locks. Is it really worth/nececary to create ADVISORY locks which basicly don't affect anything? One might not observe this load if mysql is running on dedicated machine but if there are other programs checking for locks its whole diffrent story.
cat /proc/locks 1022: POSIX ADVISORY WRITE 6160 09:03:25873004 0 EOF 1023: POSIX ADVISORY WRITE 6160 09:03:25873000 0 EOF 1024: POSIX ADVISORY WRITE 6160 09:03:25872998 0 EOF 1025: POSIX ADVISORY WRITE 6160 09:03:25871790 0 EOF 1026: POSIX ADVISORY WRITE 6160 09:03:25871905 0 EOF 1660: POSIX ADVISORY WRITE 6160 09:03:25871636 0 EOF 1907: POSIX ADVISORY WRITE 6160 09:03:25871891 0 EOF 1908: POSIX ADVISORY WRITE 6160 09:03:25871732 0 EOF 1910: POSIX ADVISORY WRITE 6160 09:03:25871824 0 EOF 1911: POSIX ADVISORY WRITE 6160 09:03:25871697 0 EOF 2303: POSIX ADVISORY WRITE 6160 09:03:25871806 0 EOF 3361: POSIX ADVISORY WRITE 6160 09:03:25872818 0 EOF 3362: POSIX ADVISORY WRITE 6160 09:03:25871996 0 EOF 3586: POSIX ADVISORY WRITE 6160 09:03:25871834 0 EOF 3594: POSIX ADVISORY WRITE 6160 09:03:25871706 0 EOF |
Comment |
[ I got same issue on 6 production mariadb servers (running completly diffrent databases) so its not a some query issue). Infinite locks are created as soon as clients start to connect to server (hundrets in minues). Yes I have InnoDB File-Per-Table Tablespaces enabled.
SHOW GLOBAL STATUS LIKE 'Uptime'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | Uptime | 680 | +---------------+-------+ 1 row in set (0.000 sec) MariaDB [(none)]> select @@table_open_cache; +--------------------+ | @@table_open_cache | +--------------------+ | 20480 | +--------------------+ 1 row in set (0.000 sec) MariaDB [(none)]> show global status like 'opened_tables'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | Opened_tables | 2412 | +---------------+-------+ 1 row in set (0.017 sec) MariaDB [(none)]> show global status like 'open_tables'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | Open_tables | 2490 | +---------------+-------+ 1 row in set (0.000 sec) 7311 is a pid of this mysqld cat /proc/locks|grep '7311'|wc -l 2509 Unfortunetly I can't recompile kernel and using mariadb binnaries because those are production servers. If thery were not there would be no issue as issue only appears with multiple clients connecting ] |
Comment |
[ # pidof mysqld
9767 7511 7416 7353 7311 7196 7128 7062 6817 cat /proc/locks 17858: POSIX ADVISORY WRITE 7128 09:03:14606660 0 EOF 17859: POSIX ADVISORY WRITE 7128 09:03:14606650 0 EOF 17860: POSIX ADVISORY WRITE 7128 09:03:14606652 0 EOF 17861: POSIX ADVISORY WRITE 7416 09:03:45251678 0 EOF 17862: POSIX ADVISORY WRITE 7353 09:03:25915346 0 EOF 17863: POSIX ADVISORY WRITE 7353 09:03:25915380 0 EOF 17864: POSIX ADVISORY WRITE 7416 09:03:45104264 0 EOF 17865: POSIX ADVISORY WRITE 7128 09:03:14647786 0 EOF 17866: POSIX ADVISORY WRITE 7416 09:03:45503026 0 EOF 17867: POSIX ADVISORY WRITE 7416 09:03:45502960 0 EOF 17868: POSIX ADVISORY WRITE 7416 09:03:45502962 0 EOF 17869: POSIX ADVISORY WRITE 7416 09:03:45502952 0 EOF 17870: POSIX ADVISORY WRITE 7416 09:03:45503070 0 EOF 17871: POSIX ADVISORY WRITE 7196 09:03:33965774 0 EOF 17872: POSIX ADVISORY WRITE 7416 09:03:45166800 0 EOF 17873: POSIX ADVISORY WRITE 7353 09:03:25544179 0 EOF 17874: POSIX ADVISORY WRITE 7353 09:03:25544181 0 EOF 17875: POSIX ADVISORY WRITE 7128 09:03:14494590 0 EOF 17876: POSIX ADVISORY WRITE 7128 09:03:14323673 0 EOF 17877: POSIX ADVISORY WRITE 7128 09:03:14588760 0 EOF 17878: POSIX ADVISORY WRITE 7128 09:03:14588762 0 EOF 17879: POSIX ADVISORY WRITE 7353 09:03:25547419 0 EOF 17880: POSIX ADVISORY WRITE 7353 09:03:25547473 0 EOF 17881: POSIX ADVISORY WRITE 7353 09:03:25547431 0 EOF 17882: POSIX ADVISORY WRITE 7353 09:03:25547433 0 EOF 17883: POSIX ADVISORY WRITE 7511 09:03:58079260 0 EOF 17884: POSIX ADVISORY WRITE 7511 09:03:58079264 0 EOF 17885: POSIX ADVISORY WRITE 7353 09:03:25775181 0 EOF 17886: POSIX ADVISORY WRITE 7353 09:03:25915693 0 EOF 17887: POSIX ADVISORY WRITE 7353 09:03:25499989 0 EOF 17888: POSIX ADVISORY WRITE 7353 09:03:25775223 0 EOF 17889: POSIX ADVISORY WRITE 7128 09:03:14250852 0 EOF 17890: POSIX ADVISORY WRITE 7353 09:03:25775281 0 EOF 17891: POSIX ADVISORY WRITE 7128 09:03:14250487 0 EOF 17892: POSIX ADVISORY WRITE 7353 09:03:25744648 0 EOF 17893: POSIX ADVISORY WRITE 7353 09:03:25744704 0 EOF 17894: POSIX ADVISORY WRITE 7511 09:03:58189447 0 EOF 17895: POSIX ADVISORY WRITE 7511 09:03:58189449 0 EOF 17896: POSIX ADVISORY WRITE 7511 09:03:58089035 0 EOF 17897: POSIX ADVISORY WRITE 7511 09:03:58204916 0 EOF 17898: POSIX ADVISORY WRITE 7511 09:03:58204922 0 EOF 17899: POSIX ADVISORY WRITE 7196 09:03:34066159 0 EOF 17900: POSIX ADVISORY WRITE 7196 09:03:34066163 0 EOF 17901: POSIX ADVISORY WRITE 7196 09:03:34066118 0 EOF 17902: POSIX ADVISORY WRITE 7511 09:03:58088975 0 EOF 17903: POSIX ADVISORY WRITE 7353 09:03:25749366 0 EOF 17904: POSIX ADVISORY WRITE 7353 09:03:25749132 0 EOF 17905: POSIX ADVISORY WRITE 7128 09:03:14619052 0 EOF 17906: POSIX ADVISORY WRITE 7128 09:03:14619050 0 EOF 17907: POSIX ADVISORY WRITE 7128 09:03:14619066 0 EOF 17908: POSIX ADVISORY WRITE 7353 09:03:25790379 0 EOF 17909: POSIX ADVISORY WRITE 7511 09:03:58349299 0 EOF 17910: POSIX ADVISORY WRITE 7416 09:03:45541532 0 EOF 17911: POSIX ADVISORY WRITE 7416 09:03:45503024 0 EOF 17912: POSIX ADVISORY WRITE 7128 09:03:14321107 0 EOF 17913: POSIX ADVISORY WRITE 7353 09:03:25748979 0 EOF 17914: POSIX ADVISORY WRITE 7062 09:03:22605630 0 EOF 17915: POSIX ADVISORY WRITE 7511 09:03:58215247 0 EOF 17916: POSIX ADVISORY WRITE 7511 09:03:58204997 0 EOF 17917: POSIX ADVISORY WRITE 7511 09:03:58312187 0 EOF 17918: POSIX ADVISORY WRITE 7511 09:03:58312179 0 EOF 17919: POSIX ADVISORY WRITE 7511 09:03:58312183 0 EOF 17920: POSIX ADVISORY WRITE 7511 09:03:58312173 0 EOF 17921: POSIX ADVISORY WRITE 7196 09:03:33770701 0 EOF 17922: POSIX ADVISORY WRITE 7196 09:03:33770699 0 EOF 17923: POSIX ADVISORY WRITE 7196 09:03:33770703 0 EOF 17924: POSIX ADVISORY WRITE 7353 09:03:25790268 0 EOF 17925: POSIX ADVISORY WRITE 7128 09:03:14471942 0 EOF 17926: POSIX ADVISORY WRITE 7128 09:03:14471922 0 EOF 17927: POSIX ADVISORY WRITE 7353 09:03:25749282 0 EOF 17928: POSIX ADVISORY WRITE 7353 09:03:25749286 0 EOF 17929: POSIX ADVISORY WRITE 7062 09:03:21939426 0 EOF 17930: POSIX ADVISORY WRITE 7196 09:03:33630783 0 EOF 17931: POSIX ADVISORY WRITE 7511 09:03:58312171 0 EOF 17932: POSIX ADVISORY WRITE 7511 09:03:58312169 0 EOF 17933: POSIX ADVISORY WRITE 7511 09:03:58312177 0 EOF 17934: POSIX ADVISORY WRITE 7511 09:03:58062520 0 EOF 17935: POSIX ADVISORY WRITE 7511 09:03:58062470 0 EOF 17936: POSIX ADVISORY WRITE 7511 09:03:58059618 0 EOF 17937: POSIX ADVISORY WRITE 7196 09:03:33628622 0 EOF 17938: POSIX ADVISORY WRITE 7416 09:03:45053616 0 EOF 17939: POSIX ADVISORY WRITE 7416 09:03:45053630 0 EOF 17940: POSIX ADVISORY WRITE 7416 09:03:45053632 0 EOF 17941: POSIX ADVISORY WRITE 7128 09:03:14459493 0 EOF 17942: POSIX ADVISORY WRITE 7511 09:03:58076440 0 EOF 17943: POSIX ADVISORY WRITE 7511 09:03:58076434 0 EOF 17944: POSIX ADVISORY WRITE 7511 09:03:58076446 0 EOF 17945: POSIX ADVISORY WRITE 7511 09:03:58076448 0 EOF 17946: POSIX ADVISORY WRITE 7511 09:03:58076452 0 EOF 17947: POSIX ADVISORY WRITE 7511 09:03:58348319 0 EOF 17948: POSIX ADVISORY WRITE 7511 09:03:58348313 0 EOF 17949: POSIX ADVISORY WRITE 7511 09:03:58348311 0 EOF 17950: POSIX ADVISORY WRITE 7511 09:03:58348307 0 EOF 17951: POSIX ADVISORY WRITE 7511 09:03:58348305 0 EOF 17952: POSIX ADVISORY WRITE 7511 09:03:58348297 0 EOF 17953: POSIX ADVISORY WRITE 7511 09:03:58348277 0 EOF 17954: POSIX ADVISORY WRITE 7511 09:03:58348273 0 EOF 17955: POSIX ADVISORY WRITE 7511 09:03:58348273 0 EOF 17956: POSIX ADVISORY WRITE 7511 09:03:58348321 0 EOF 17957: POSIX ADVISORY WRITE 7511 09:03:58100602 0 EOF 17958: POSIX ADVISORY WRITE 7511 09:03:58205363 0 EOF 17959: POSIX ADVISORY WRITE 7511 09:03:58334839 0 EOF 17960: POSIX ADVISORY WRITE 7511 09:03:58334829 0 EOF 17961: POSIX ADVISORY WRITE 7511 09:03:58334827 0 EOF 17962: POSIX ADVISORY WRITE 7511 09:03:58334825 0 EOF 17963: POSIX ADVISORY WRITE 7511 09:03:58334819 0 EOF 17964: POSIX ADVISORY WRITE 7511 09:03:58334817 0 EOF 17965: POSIX ADVISORY WRITE 7511 09:03:58073493 0 EOF 17966: POSIX ADVISORY WRITE 7511 09:03:58073505 0 EOF 17967: POSIX ADVISORY WRITE 7511 09:03:58073503 0 EOF 17968: POSIX ADVISORY WRITE 7511 09:03:58073497 0 EOF 17969: POSIX ADVISORY WRITE 7511 09:03:58073501 0 EOF 17970: POSIX ADVISORY WRITE 7511 09:03:58073499 0 EOF 17971: POSIX ADVISORY WRITE 7511 09:03:58346219 0 EOF 17972: POSIX ADVISORY WRITE 7416 09:03:45165600 0 EOF 17973: POSIX ADVISORY WRITE 7416 09:03:45165602 0 EOF 17974: POSIX ADVISORY WRITE 7416 09:03:45165740 0 EOF 17975: POSIX ADVISORY WRITE 7416 09:03:45165974 0 EOF 17976: POSIX ADVISORY WRITE 7416 09:03:45165972 0 EOF 17977: POSIX ADVISORY WRITE 7196 09:03:33660432 0 EOF 17978: POSIX ADVISORY WRITE 7196 09:03:33660428 0 EOF 17979: POSIX ADVISORY WRITE 7196 09:03:33660420 0 EOF 17980: POSIX ADVISORY WRITE 7196 09:03:33660400 0 EOF 17981: POSIX ADVISORY WRITE 7416 09:03:45542815 0 EOF 17982: POSIX ADVISORY WRITE 7353 09:03:25875390 0 EOF 17983: POSIX ADVISORY WRITE 7196 09:03:33660340 0 EOF 17984: POSIX ADVISORY WRITE 7196 09:03:33660382 0 EOF 17985: POSIX ADVISORY WRITE 7196 09:03:33660352 0 EOF 17986: POSIX ADVISORY WRITE 7196 09:03:33660312 0 EOF 17987: POSIX ADVISORY WRITE 7196 09:03:33660241 0 EOF 17988: POSIX ADVISORY WRITE 7196 09:03:33660265 0 EOF 17989: POSIX ADVISORY WRITE 7416 09:03:45100228 0 EOF 17990: POSIX ADVISORY WRITE 7062 09:03:21966252 0 EOF 17991: POSIX ADVISORY WRITE 7416 09:03:45504062 0 EOF 17992: POSIX ADVISORY WRITE 7416 09:03:45504062 0 EOF 17993: POSIX ADVISORY WRITE 7128 09:03:14449564 0 EOF 17994: POSIX ADVISORY WRITE 7511 09:03:58345803 0 EOF 17995: POSIX ADVISORY WRITE 7511 09:03:58214067 0 EOF 17996: POSIX ADVISORY WRITE 7128 09:03:14449554 0 EOF 17997: POSIX ADVISORY WRITE 7062 09:03:22098993 0 EOF 17998: POSIX ADVISORY WRITE 7416 09:03:45077062 0 EOF 17999: POSIX ADVISORY WRITE 7416 09:03:45077064 0 EOF 18000: POSIX ADVISORY WRITE 7416 09:03:45077060 0 EOF 18001: POSIX ADVISORY WRITE 9767 09:03:41762382 0 EOF 18002: POSIX ADVISORY WRITE 7353 09:03:25891460 0 EOF 18003: POSIX ADVISORY WRITE 7196 09:03:33660424 0 EOF 18004: POSIX ADVISORY WRITE 7196 09:03:33660426 0 EOF 18005: POSIX ADVISORY WRITE 7416 09:03:45556713 0 EOF 18006: POSIX ADVISORY WRITE 7416 09:03:45556711 0 EOF 18007: POSIX ADVISORY WRITE 7128 09:03:14184217 0 EOF 18008: POSIX ADVISORY WRITE 7416 09:03:45576138 0 EOF 18009: POSIX ADVISORY WRITE 7416 09:03:45576302 0 EOF 18010: POSIX ADVISORY WRITE 7416 09:03:45576140 0 EOF 18011: POSIX ADVISORY WRITE 7416 09:03:45099284 0 EOF 18012: POSIX ADVISORY WRITE 7062 09:03:22589227 0 EOF 18013: POSIX ADVISORY WRITE 7416 09:03:45159885 0 EOF 18014: POSIX ADVISORY WRITE 7062 09:03:22589211 0 EOF 18015: POSIX ADVISORY WRITE 7416 09:03:45103270 0 EOF 18016: POSIX ADVISORY WRITE 7416 09:03:45103264 0 EOF 18017: POSIX ADVISORY WRITE 7416 09:03:45103260 0 EOF 18018: POSIX ADVISORY WRITE 7416 09:03:45103250 0 EOF 18019: POSIX ADVISORY WRITE 7416 09:03:45541438 0 EOF 18020: POSIX ADVISORY WRITE 7416 09:03:45048246 0 EOF 18021: POSIX ADVISORY WRITE 7416 09:03:45048266 0 EOF 18022: POSIX ADVISORY WRITE 7416 09:03:45048260 0 EOF 18023: POSIX ADVISORY WRITE 7416 09:03:45048256 0 EOF 18024: POSIX ADVISORY WRITE 7196 09:03:34066327 0 EOF 18025: POSIX ADVISORY WRITE 7196 09:03:33803130 0 EOF 18026: POSIX ADVISORY WRITE 7196 09:03:34024548 0 EOF 18027: POSIX ADVISORY WRITE 7128 09:03:14325441 0 EOF 18028: POSIX ADVISORY WRITE 7128 09:03:14325461 0 EOF 18029: POSIX ADVISORY WRITE 7196 09:03:33777671 0 EOF 18030: POSIX ADVISORY WRITE 7196 09:03:33777665 0 EOF 18031: POSIX ADVISORY WRITE 7416 09:03:45559311 0 EOF 18032: POSIX ADVISORY WRITE 7416 09:03:45065418 0 EOF 18033: POSIX ADVISORY WRITE 7416 09:03:45065377 0 EOF 18034: POSIX ADVISORY WRITE 7416 09:03:45136186 0 EOF 18035: POSIX ADVISORY WRITE 7416 09:03:45136184 0 EOF 18036: POSIX ADVISORY WRITE 7416 09:03:45136144 0 EOF 18037: POSIX ADVISORY WRITE 7416 09:03:45136146 0 EOF 18038: POSIX ADVISORY WRITE 7416 09:03:45136142 0 EOF 18039: POSIX ADVISORY WRITE 7416 09:03:45504055 0 EOF 18040: POSIX ADVISORY WRITE 7416 09:03:45504325 0 EOF 18041: POSIX ADVISORY WRITE 7416 09:03:45504293 0 EOF 18042: POSIX ADVISORY WRITE 7416 09:03:45065437 0 EOF 18043: POSIX ADVISORY WRITE 7416 09:03:45065432 0 EOF 18044: POSIX ADVISORY WRITE 7416 09:03:45065428 0 EOF 18045: POSIX ADVISORY WRITE 7416 09:03:45122740 0 EOF 18046: POSIX ADVISORY WRITE 7416 09:03:45122738 0 EOF 18047: POSIX ADVISORY WRITE 7416 09:03:45122641 0 EOF 18048: POSIX ADVISORY WRITE 7353 09:03:25500219 0 EOF 18049: POSIX ADVISORY WRITE 7353 09:03:25795692 0 EOF 18050: POSIX ADVISORY WRITE 7353 09:03:25795696 0 EOF 18051: POSIX ADVISORY WRITE 7353 09:03:25800239 0 EOF 18052: POSIX ADVISORY WRITE 7353 09:03:25795628 0 EOF 18053: POSIX ADVISORY WRITE 7353 09:03:19830608 0 EOF 18054: POSIX ADVISORY WRITE 7353 09:03:25795702 0 EOF 18055: POSIX ADVISORY WRITE 7128 09:03:14600449 0 EOF 18056: POSIX ADVISORY WRITE 7196 09:03:33885093 0 EOF 18057: POSIX ADVISORY WRITE 7128 09:03:14234201 0 EOF 18058: POSIX ADVISORY WRITE 7353 09:03:25875618 0 EOF 18059: POSIX ADVISORY WRITE 7511 09:03:58060995 0 EOF 18060: POSIX ADVISORY WRITE 7511 09:03:58061001 0 EOF 18061: POSIX ADVISORY WRITE 7511 09:03:58077923 0 EOF 18062: POSIX ADVISORY WRITE 7511 09:03:58320659 0 EOF 18063: POSIX ADVISORY WRITE 7511 09:03:58325143 0 EOF 18064: POSIX ADVISORY WRITE 7511 09:03:58351018 0 EOF 18065: POSIX ADVISORY WRITE 7511 09:03:58351034 0 EOF 18066: POSIX ADVISORY WRITE 7511 09:03:58351020 0 EOF 18067: POSIX ADVISORY WRITE 7511 09:03:58351032 0 EOF 18068: POSIX ADVISORY WRITE 7511 09:03:58321075 0 EOF 18069: POSIX ADVISORY WRITE 7511 09:03:58321073 0 EOF 18070: POSIX ADVISORY WRITE 7511 09:03:58321071 0 EOF 18071: POSIX ADVISORY WRITE 7511 09:03:58321028 0 EOF 18072: POSIX ADVISORY WRITE 7511 09:03:58322488 0 EOF 18073: POSIX ADVISORY WRITE 7511 09:03:58060953 0 EOF 18074: POSIX ADVISORY WRITE 7511 09:03:58089019 0 EOF 18075: POSIX ADVISORY WRITE 7511 09:03:58088981 0 EOF 18076: POSIX ADVISORY WRITE 7511 09:03:58088967 0 EOF 18077: POSIX ADVISORY WRITE 7511 09:03:58088969 0 EOF 18078: POSIX ADVISORY WRITE 7511 09:03:58088997 0 EOF 18079: POSIX ADVISORY WRITE 7511 09:03:58325141 0 EOF 18080: POSIX ADVISORY WRITE 7511 09:03:58318031 0 EOF 18081: POSIX ADVISORY WRITE 7511 09:03:58318020 0 EOF 18082: POSIX ADVISORY WRITE 7511 09:03:58318000 0 EOF 18083: POSIX ADVISORY WRITE 7511 09:03:58214556 0 EOF 18084: POSIX ADVISORY WRITE 7353 09:03:25918413 0 EOF 18085: POSIX ADVISORY WRITE 7128 09:03:14187407 0 EOF 18086: POSIX ADVISORY WRITE 7128 09:03:14187435 0 EOF 18087: POSIX ADVISORY WRITE 7416 09:03:45045833 0 EOF 18088: POSIX ADVISORY WRITE 7416 09:03:45579090 0 EOF 18089: POSIX ADVISORY WRITE 7353 09:03:25798239 0 EOF 18090: POSIX ADVISORY WRITE 7353 09:03:19830534 0 EOF 18091: POSIX ADVISORY WRITE 7353 09:03:19830536 0 EOF 18092: FLOCK ADVISORY WRITE 6771 09:01:4022908 0 EOF ] |
Comment | [ it seems that reducing table_open_cache from 20k to like 500 sets cap to /proc/locks made. Do really setting table_open_cache must cause all those ADVISORY locks? Thery are ADVISORY so basicly worthless and still enough number of them causes a bit higher "sys" load eventualy (which is triggered by other running programs checking kernel locks - not necessary mysqld!). I'm guessing mysqld does not check for these locks so you might not even observe this if you are running dedicated mysql server....Is it necessary/worth it? ] |
Summary | mariadb table_open_cache is creating a lot of advisory /proc/locks which causes increase "sys" load | table_open_cache creates same number of advisory /proc/locks. Is it worth it? |
Labels | need_feedback |
Labels | need_feedback |
Description |
table_open_cache is creating a same number of ADVISORY /proc/locks. Higher number of locks = increased "sys" load when other programs running on same machine check for locks. Is it really worth/nececary to create ADVISORY locks which basicly don't affect anything? One might not observe this load if mysql is running on dedicated machine but if there are other programs checking for locks its whole diffrent story.
cat /proc/locks 1022: POSIX ADVISORY WRITE 6160 09:03:25873004 0 EOF 1023: POSIX ADVISORY WRITE 6160 09:03:25873000 0 EOF 1024: POSIX ADVISORY WRITE 6160 09:03:25872998 0 EOF 1025: POSIX ADVISORY WRITE 6160 09:03:25871790 0 EOF 1026: POSIX ADVISORY WRITE 6160 09:03:25871905 0 EOF 1660: POSIX ADVISORY WRITE 6160 09:03:25871636 0 EOF 1907: POSIX ADVISORY WRITE 6160 09:03:25871891 0 EOF 1908: POSIX ADVISORY WRITE 6160 09:03:25871732 0 EOF 1910: POSIX ADVISORY WRITE 6160 09:03:25871824 0 EOF 1911: POSIX ADVISORY WRITE 6160 09:03:25871697 0 EOF 2303: POSIX ADVISORY WRITE 6160 09:03:25871806 0 EOF 3361: POSIX ADVISORY WRITE 6160 09:03:25872818 0 EOF 3362: POSIX ADVISORY WRITE 6160 09:03:25871996 0 EOF 3586: POSIX ADVISORY WRITE 6160 09:03:25871834 0 EOF 3594: POSIX ADVISORY WRITE 6160 09:03:25871706 0 EOF |
MariaDB table_open_cache generates same and excessive number of advisory /proc/locks that causes OTHER programs on machine to waste cpu power ("sys load") when checking for locks. Are those really needed/worth it?
Executing lsof command while there are 100k locks in /proc/locks (made by mariadb with table_open_cache=100k) takes 2 minutes. I see huge decrease in "sys" load after reducing table_open_cache from 100k to 4k on graphs. |
Labels | need_feedback |
Labels | need_feedback |
Labels | need_feedback |
Labels | need_feedback |
Component/s | Server [ 13907 ] | |
Component/s | Storage Engine - InnoDB [ 10129 ] | |
Fix Version/s | 10.2 [ 14601 ] | |
Fix Version/s | 10.3 [ 22126 ] | |
Fix Version/s | 10.4 [ 22408 ] | |
Fix Version/s | 10.5 [ 23123 ] | |
Affects Version/s | 10.2 [ 14601 ] | |
Affects Version/s | 10.3 [ 22126 ] | |
Affects Version/s | 10.4 [ 22408 ] | |
Affects Version/s | 10.5 [ 23123 ] | |
Assignee | Sergei Golubchik [ serg ] |
Status | Open [ 1 ] | Confirmed [ 10101 ] |
Assignee | Sergei Golubchik [ serg ] | Marko Mäkelä [ marko ] |
Remote Link | This issue links to "MySQL Bug #3608 INNODB allows a new process to start when the database is still shutting down. (Web Link)" [ 31100 ] |
Assignee | Marko Mäkelä [ marko ] | Sergei Golubchik [ serg ] |
Assignee | Sergei Golubchik [ serg ] | Marko Mäkelä [ marko ] |
Status | Confirmed [ 10101 ] | In Progress [ 3 ] |
Assignee | Marko Mäkelä [ marko ] | Sergei Golubchik [ serg ] |
Status | In Progress [ 3 ] | In Review [ 10002 ] |
Assignee | Sergei Golubchik [ serg ] | Marko Mäkelä [ marko ] |
Status | In Review [ 10002 ] | Stalled [ 10000 ] |
Fix Version/s | 10.2.40 [ 26027 ] | |
Fix Version/s | 10.3.31 [ 26028 ] | |
Fix Version/s | 10.4.21 [ 26030 ] | |
Fix Version/s | 10.5.12 [ 26025 ] | |
Fix Version/s | 10.6.4 [ 26033 ] | |
Fix Version/s | 10.2 [ 14601 ] | |
Fix Version/s | 10.3 [ 22126 ] | |
Fix Version/s | 10.4 [ 22408 ] | |
Fix Version/s | 10.5 [ 23123 ] | |
Resolution | Fixed [ 1 ] | |
Status | Stalled [ 10000 ] | Closed [ 6 ] |
Workflow | MariaDB v3 [ 116792 ] | MariaDB v4 [ 158682 ] |
Link |
This issue causes |
Link |
This issue causes |
Link |
This issue causes |
Link |
This issue relates to |
Link |
This issue causes |
Link |
This issue relates to |
Link |
This issue relates to |
While its parially obvious the section of locks here are all mariadb lock (same pid - 28588, The inode of each entry seems unique (14......). Do you have https://mariadb.com/kb/en/innodb-file-per-table-tablespaces/ ? How many table_open_cache records are being used? Is there lots of temporary files open?
Its not obvious that the kernel locks are the issue. With kernel and mariadb debug symbols installed, can you use `perf record -a -g – sleep 5`, can you show with `perf report-g --no-children --stdio -` what sys time is being used? If you look at `perf top` where is CPU time being spend?
Have you eliminated other more obvious causes like slow queries, maybe a query plan of common queries has changed in the version upgrade from previous major version.