You are here
MyISAM locking and who is the evil?
Wed, 2020-09-23 09:58 — Shinguz
Yes, I know, MyISAM is deprecated and unofficially discontinued by the vendors. But we still have from time to time customers using MyISAM and even evangelize for MyISAM...
And to be honest in some cases MyISAM has even advantages (beside some huge disadvantages) over other Storage Engines (simple file copy, footprint, single-query latency, ...). But most of our customers are not aware of these advantages and are using MyISAM just because they did it since ever...
One of the biggest problems we see at customers is the MyISAM table lock behaviour. They claim things like the database stalls, crashes or stocks beside other non-qualified expressions. Which is typically not the case but the database just runs out of connections because they reach the max_connections fuse. In fact what happens is that one long running writer connection blocks an important and frequently used (MyISAM) table and other writer and reader connections have to wait (Waiting for table level lock) until the writer finishes its work. If you are lucky the system relaxes again afterwards. If not, the database rejects new connections because in the meanwhile other connections have filled up the allowed number of connections up to max_connections.
Instead of finding and solving the problem, customers typically just increase max_connections until it becomes so cumbersome they cannot live any more with it. And then they show up at FromDual consulting services.
Now, how can we find that this scenario happened? The first thing you should do when this situation happens is to gather immediately the output of the command SHOW FULL PROCESSLIST and store it away for later analysis by your preferred spreadsheet tool or editor (please not a screenshot but just copy plain characters from your CLI!).
SELECT thread_id, processlist_id, processlist_user, processlist_host, processlist_db, processlist_time, processlist_state, processlist_info FROM performance_schema.threads WHERE PROCESSLIST_COMMAND != 'Sleep' AND TYPE = 'FOREGROUND' ORDER BY PROCESSLIST_TIME DESC ;
An this is how it looks like if you have a MyISAM table level locking situation:
INSERT INTO ... SELECT * FROM ...
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
| THREAD_ID | PROCESSLIST_ID | PROCESSLIST_USER | PROCESSLIST_HOST | PROCESSLIST_DB | PROCESSLIST_TIME | PROCESSLIST_STATE | PROCESSLIST_INFO |
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
| 39557 | 38968 | root | localhost | test | 12 | Sending data | INSERT INTO test SELECT * FROM vol |
| 49102 | 48489 | root | localhost | test | 11 | Waiting for table level lock | INSERT INTO test (id, data, ts) VALUES (NULL, CONCAT('Test data insert from boss on ', @@hostname), CURRENT_TIMESTAMP()) |
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
or
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
| THREAD_ID | PROCESSLIST_ID | PROCESSLIST_USER | PROCESSLIST_HOST | PROCESSLIST_DB | PROCESSLIST_TIME | PROCESSLIST_STATE | PROCESSLIST_INFO |
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
| 39557 | 38968 | root | localhost | test | 21 | Writing to binlog | INSERT INTO test SELECT * FROM vol |
| 49102 | 48489 | root | localhost | test | 20 | Waiting for table level lock | INSERT INTO test (id, data, ts) VALUES (NULL, CONCAT('Test data insert from boss on ', @@hostname), CURRENT_TIMESTAMP()) |
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
UPDATE ... SET ...
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
| THREAD_ID | PROCESSLIST_ID | PROCESSLIST_USER | PROCESSLIST_HOST | PROCESSLIST_DB | PROCESSLIST_TIME | PROCESSLIST_STATE | PROCESSLIST_INFO |
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
| 39557 | 38968 | root | localhost | test | 47 | Updating | UPDATE test SET data = 'Blub' WHERE id > 1000 |
| 117892 | 117279 | root | localhost | test | 47 | Waiting for table level lock | INSERT INTO test (id, data, ts) VALUES (NULL, CONCAT('Test data insert from boss on ', @@hostname), CURRENT_TIMESTAMP()) |
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
DELETE FROM ...
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
| THREAD_ID | PROCESSLIST_ID | PROCESSLIST_USER | PROCESSLIST_HOST | PROCESSLIST_DB | PROCESSLIST_TIME | PROCESSLIST_STATE | PROCESSLIST_INFO |
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
| 39557 | 38968 | root | localhost | test | 7 | Updating | DELETE FROM test WHERE id > 10 |
| 153272 | 152659 | root | localhost | test | 7 | Waiting for table level lock | INSERT INTO test (id, data, ts) VALUES (NULL, CONCAT('Test data insert from boss on ', @@hostname), CURRENT_TIMESTAMP()) |
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
SELECT ... FROM ...
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
| THREAD_ID | PROCESSLIST_ID | PROCESSLIST_USER | PROCESSLIST_HOST | PROCESSLIST_DB | PROCESSLIST_TIME | PROCESSLIST_STATE | PROCESSLIST_INFO |
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
| 39557 | 38968 | root | localhost | test | 2 | Sending data | SELECT * FROM test |
| 160014 | 159401 | root | localhost | test | 2 | Waiting for table level lock | INSERT INTO test (id, data, ts) VALUES (NULL, CONCAT('Test data insert from boss on ', @@hostname), CURRENT_TIMESTAMP()) |
+-----------+----------------+------------------+------------------+----------------+------------------+------------------------------+--------------------------------------------------------------------------------------------------------------------------+
This means for searching the locker you have to find all connections which are not in processlist command Sleep and which are not in processlist state Waiting for table level lock sort the remaining by processlist time and the one with the longest processlist time is probably the evildoer.
In some cases where you have a Master/Master set-up (or if you have the problem on the slave) data changes can also be induced by the (other) Master. In this situation it looks as follows:
+-------+-------------+-----------+------+-----------+------+-------------------------------------+------------------------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+-------+-------------+-----------+------+-----------+------+-------------------------------------+------------------------------------------------------------------------------------------------------+
| 15 | system user | | NULL | Slave_SQL | 0 | Update_rows_log_event::find_row(-1) | UPDATE test SET data = 'blabla' |
| 16867 | root | localhost | test | Query | 28 | Waiting for table level lock | INSERT INTO test (id, data, ts) VALUES (NULL, CONCAT('Test data insert from boss on ', @@hostname), |
+-------+-------------+-----------+------+-----------+------+-------------------------------------+------------------------------------------------------------------------------------------------------+
The PERFORMANCE_SCHEMA
An other possibility to find possible locker candidates is thePERFORMANCE_SCHEMA. First you have to make sure, the PERFORMANCE_SCHEMA is enabled and the according instrument and consumers are enabled:
SQL> SHOW GLOBAL VARIABLES LIKE 'performance_schema'; +--------------------+-------+ | Variable_name | Value | +--------------------+-------+ | performance_schema | ON | +--------------------+-------+
SQL> SELECT * FROM performance_schema.setup_instruments WHERE name LIKE 'wait/lock/ta%'; +-----------------------------+---------+-------+ | NAME | ENABLED | TIMED | +-----------------------------+---------+-------+ | wait/lock/table/sql/handler | YES | YES | +-----------------------------+---------+-------+
SQL> SELECT * FROM performance_schema.setup_consumers WHERE name LIKE 'events_waits%'; +---------------------------+---------+ | NAME | ENABLED | +---------------------------+---------+ | events_waits_current | YES | | events_waits_history | YES | | events_waits_history_long | YES | +---------------------------+---------+
and then you can check the according PERFORMANCE_SCHEMA views:
SQL> SELECT @uptime := variable_value FROM information_schema.global_status WHERE variable_name = 'Uptime'; SQL> SELECT @start := DATE_SUB(NOW(), INTERVAL @uptime SECOND) AS start;
General statistics:
SQL> SELECT * FROM performance_schema.table_lock_waits_summary_by_table; +-------------+---------------+-----------------------+------------+-----------------+----------------+----------------+-----------------+------------+----------------+----------------+----------------+----------------+-------------+-----------------+-----------------+-----------------+-----------------+-------------------+-----------------------+-----------------------+-----------------------+-----------------------+------------------------------+----------------------------------+----------------------------------+----------------------------------+----------------------------------+--------------------------+------------------------------+------------------------------+------------------------------+------------------------------+----------------------+--------------------------+--------------------------+--------------------------+--------------------------+---------------------+-------------------------+-------------------------+-------------------------+-------------------------+-------------------------+-----------------------------+-----------------------------+-----------------------------+-----------------------------+-------------------------------+-----------------------------------+-----------------------------------+-----------------------------------+-----------------------------------+---------------------+-------------------------+-------------------------+-------------------------+-------------------------+--------------------------+------------------------------+------------------------------+------------------------------+------------------------------+--------------------+------------------------+------------------------+------------------------+------------------------+----------------------+--------------------------+--------------------------+--------------------------+--------------------------+ | OBJECT_TYPE | OBJECT_SCHEMA | OBJECT_NAME | COUNT_STAR | SUM_TIMER_WAIT | MIN_TIMER_WAIT | AVG_TIMER_WAIT | MAX_TIMER_WAIT | COUNT_READ | SUM_TIMER_READ | MIN_TIMER_READ | AVG_TIMER_READ | MAX_TIMER_READ | COUNT_WRITE | SUM_TIMER_WRITE | MIN_TIMER_WRITE | AVG_TIMER_WRITE | MAX_TIMER_WRITE | COUNT_READ_NORMAL | SUM_TIMER_READ_NORMAL | MIN_TIMER_READ_NORMAL | AVG_TIMER_READ_NORMAL | MAX_TIMER_READ_NORMAL | COUNT_READ_WITH_SHARED_LOCKS | SUM_TIMER_READ_WITH_SHARED_LOCKS | MIN_TIMER_READ_WITH_SHARED_LOCKS | AVG_TIMER_READ_WITH_SHARED_LOCKS | MAX_TIMER_READ_WITH_SHARED_LOCKS | COUNT_READ_HIGH_PRIORITY | SUM_TIMER_READ_HIGH_PRIORITY | MIN_TIMER_READ_HIGH_PRIORITY | AVG_TIMER_READ_HIGH_PRIORITY | MAX_TIMER_READ_HIGH_PRIORITY | COUNT_READ_NO_INSERT | SUM_TIMER_READ_NO_INSERT | MIN_TIMER_READ_NO_INSERT | AVG_TIMER_READ_NO_INSERT | MAX_TIMER_READ_NO_INSERT | COUNT_READ_EXTERNAL | SUM_TIMER_READ_EXTERNAL | MIN_TIMER_READ_EXTERNAL | AVG_TIMER_READ_EXTERNAL | MAX_TIMER_READ_EXTERNAL | COUNT_WRITE_ALLOW_WRITE | SUM_TIMER_WRITE_ALLOW_WRITE | MIN_TIMER_WRITE_ALLOW_WRITE | AVG_TIMER_WRITE_ALLOW_WRITE | MAX_TIMER_WRITE_ALLOW_WRITE | COUNT_WRITE_CONCURRENT_INSERT | SUM_TIMER_WRITE_CONCURRENT_INSERT | MIN_TIMER_WRITE_CONCURRENT_INSERT | AVG_TIMER_WRITE_CONCURRENT_INSERT | MAX_TIMER_WRITE_CONCURRENT_INSERT | COUNT_WRITE_DELAYED | SUM_TIMER_WRITE_DELAYED | MIN_TIMER_WRITE_DELAYED | AVG_TIMER_WRITE_DELAYED | MAX_TIMER_WRITE_DELAYED | COUNT_WRITE_LOW_PRIORITY | SUM_TIMER_WRITE_LOW_PRIORITY | MIN_TIMER_WRITE_LOW_PRIORITY | AVG_TIMER_WRITE_LOW_PRIORITY | MAX_TIMER_WRITE_LOW_PRIORITY | COUNT_WRITE_NORMAL | SUM_TIMER_WRITE_NORMAL | MIN_TIMER_WRITE_NORMAL | AVG_TIMER_WRITE_NORMAL | MAX_TIMER_WRITE_NORMAL | COUNT_WRITE_EXTERNAL | SUM_TIMER_WRITE_EXTERNAL | MIN_TIMER_WRITE_EXTERNAL | AVG_TIMER_WRITE_EXTERNAL | MAX_TIMER_WRITE_EXTERNAL | +-------------+---------------+-----------------------+------------+-----------------+----------------+----------------+-----------------+------------+----------------+----------------+----------------+----------------+-------------+-----------------+-----------------+-----------------+-----------------+-------------------+-----------------------+-----------------------+-----------------------+-----------------------+------------------------------+----------------------------------+----------------------------------+----------------------------------+----------------------------------+--------------------------+------------------------------+------------------------------+------------------------------+------------------------------+----------------------+--------------------------+--------------------------+--------------------------+--------------------------+---------------------+-------------------------+-------------------------+-------------------------+-------------------------+-------------------------+-----------------------------+-----------------------------+-----------------------------+-----------------------------+-------------------------------+-----------------------------------+-----------------------------------+-----------------------------------+-----------------------------------+---------------------+-------------------------+-------------------------+-------------------------+-------------------------+--------------------------+------------------------------+------------------------------+------------------------------+------------------------------+--------------------+------------------------+------------------------+------------------------+------------------------+----------------------+--------------------------+--------------------------+--------------------------+--------------------------+ | TABLE | test | test | 994184 | 410880205008924 | 126840 | 413283678 | 101480121005292 | 6 | 7095792 | 300792 | 1182330 | 2797728 | 994178 | 410880197913132 | 126840 | 413285943 | 101480121005292 | 3 | 2583912 | 300792 | 861153 | 1359906 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 3 | 4511880 | 608832 | 1503960 | 2797728 | 0 | 0 | 0 | 0 | 0 | 497080 | 410589058214256 | 126840 | 826001559 | 101480121005292 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 9 | 2890140 | 162174 | 320724 | 953112 | 497089 | 291136808736 | 287202 | 585276 | 69665964 | | TABLE | test | vol | 110 | 113655888 | 94224 | 1032840 | 3911202 | 64 | 30244998 | 94224 | 472479 | 3911202 | 46 | 83410890 | 318912 | 1812906 | 3246198 | 32 | 11410164 | 94224 | 356511 | 558096 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 32 | 18834834 | 96036 | 588447 | 3911202 | 0 | 0 | 0 | 0 | 0 | 23 | 22661778 | 318912 | 985275 | 1338162 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 23 | 60749112 | 1040088 | 2640990 | 3246198 | +-------------+---------------+-----------------------+------------+-----------------+----------------+----------------+-----------------+------------+----------------+----------------+----------------+----------------+-------------+-----------------+-----------------+-----------------+-----------------+-------------------+-----------------------+-----------------------+-----------------------+-----------------------+------------------------------+----------------------------------+----------------------------------+----------------------------------+----------------------------------+--------------------------+------------------------------+------------------------------+------------------------------+------------------------------+----------------------+--------------------------+--------------------------+--------------------------+--------------------------+---------------------+-------------------------+-------------------------+-------------------------+-------------------------+-------------------------+-----------------------------+-----------------------------+-----------------------------+-----------------------------+-------------------------------+-----------------------------------+-----------------------------------+-----------------------------------+-----------------------------------+---------------------+-------------------------+-------------------------+-------------------------+-------------------------+--------------------------+------------------------------+------------------------------+------------------------------+------------------------------+--------------------+------------------------+------------------------+------------------------+------------------------+----------------------+--------------------------+--------------------------+--------------------------+--------------------------+
Locks currently in use (column EXTERNAL_LOCK?):
SQL> SELECT *, DATE_ADD(@start, INTERVAL OBJECT_INSTANCE_BEGIN/1000000000000 SECOND) AS OBJECT_INSTANCE_BEGIN FROM performance_schema.table_handles; +-------------+---------------+-----------------------+-----------------------+-----------------+----------------+-------------------------+----------------+----------------------------+ | OBJECT_TYPE | OBJECT_SCHEMA | OBJECT_NAME | OBJECT_INSTANCE_BEGIN | OWNER_THREAD_ID | OWNER_EVENT_ID | INTERNAL_LOCK | EXTERNAL_LOCK | OBJECT_INSTANCE_BEGIN | +-------------+---------------+-----------------------+-----------------------+-----------------+----------------+-------------------------+----------------+----------------------------+ | TABLE | test | test | 139730319589344 | 331762 | 188378355 | WRITE CONCURRENT INSERT | WRITE EXTERNAL | 2020-09-08 21:51:25.730300 | - INSERT | TABLE | test | vol | 139729782302336 | 331762 | 188378355 | READ | READ EXTERNAL | 2020-09-08 21:51:25.729800 | - SELECT | TABLE | test | vol | 139729782023584 | 0 | 0 | READ | NULL | 2020-09-08 21:51:25.729800 | | TABLE | test | test | 139729782284672 | 497001 | 2 | WRITE CONCURRENT INSERT | WRITE EXTERNAL | 2020-09-08 21:51:25.729800 | - INSERT +-------------+---------------+-----------------------+-----------------------+-----------------+----------------+-------------------------+----------------+----------------------------+
Threads currently locking:
SQL> SELECT thread_id, event_id, end_event_id, event_name
, DATE_ADD(@start, INTERVAL timer_start/1000000000000 SECOND) AS timer_start
, DATE_ADD(@start, INTERVAL timer_end/1000000000000 SECOND) AS timer_end
, ROUND(timer_wait/1000000000000, 3) AS timer_wait_s
, object_schema, REVERSE(SUBSTR(REVERSE(object_name), 1, 32)) AS object_name, object_type
, DATE_ADD(@start, INTERVAL object_instance_begin/1000000000000 SECOND) AS object_instance_begin
, nesting_event_id, nesting_event_type, operation
FROM performance_schema.events_waits_current
;
+-----------+-----------+--------------+-----------------------------+----------------------------+----------------------------+--------------+---------------+----------------------------------+-------------+----------------------------+------------------+--------------------+-------------------------+
| thread_id | event_id | end_event_id | event_name | timer_start | timer_end | timer_wait_s | object_schema | object_name | object_type | object_instance_begin | nesting_event_id | nesting_event_type | operation |
+-----------+-----------+--------------+-----------------------------+----------------------------+----------------------------+--------------+---------------+----------------------------------+-------------+----------------------------+------------------+--------------------+-------------------------+
| 373764 | 3 | NULL | wait/lock/table/sql/handler | 2020-09-10 07:45:20.231500 | 2020-09-10 07:46:53.075100 | 92.844 | test | test | TABLE | 2020-09-08 21:51:25.730300 | NULL | NULL | write concurrent insert |
| 331762 | 178087926 | NULL | wait/io/table/sql/handler | 2020-09-10 07:46:53.075100 | 2020-09-10 07:46:53.075100 | 0.000 | test | test | TABLE | 2020-09-08 21:51:25.729800 | NULL | NULL | delete |
| 331762 | 178087931 | NULL | wait/io/file/myisam/dfile | 2020-09-10 07:46:53.075100 | 2020-09-10 07:46:53.075100 | 0.000 | NULL | w/mariadb-105/data/test/test.MYD | FILE | 2020-09-08 21:51:25.731100 | 178087926 | WAIT | read |
+-----------+-----------+--------------+-----------------------------+----------------------------+----------------------------+--------------+---------------+----------------------------------+-------------+----------------------------+------------------+--------------------+-------------------------+
But I still have not found a direct view to prove who is the locker of a specific locked thread/connection. So some work is still to do...
- Shinguz's blog
- Log in or register to post comments