Details
-
Bug
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
10.6.8, 10.7.3, 10.7.4, 10.8.2, 10.8.3, 10.9.1
-
None
Description
In MariaDB (as well as in MySQL 8), we have no wait event instrumentation for record locks and for table locks.
As such, table and row lock waits are reported incorrectly as "wait/io/table/sql/handler".
This makes performance troubleshooting impossible for customers.
The expected outcome is to create 2 more instruments: row lock and table lock. These 2 types of lock waits can then be measured inside performance_schema. Being able to separate lock waits from IO waits will aid performance tuning, because reducing them will require difference approaches.
Table and row lock instrumentation maybe too resource intensive. In the meantime, the fix in https://github.com/MariaDB/server/pull/2206 marks this kind of wait as wait/lock/table/sql/handler
Steps to reproduce:
- Add the following line into my.cnf before instance start
performance_schema=ON
- Run the following to set up all consumers and instrumentation
UPDATE performance_schema.setup_consumers SET ENABLED = 'YES';
UPDATE performance_schema.setup_instruments SET ENABLED = 'YES', TIMED = 'YES';
set global innodb_lock_wait_timeout=7200;
- Set up test table
create database test;
use test
create table t1 (id1 int(11), col1 varchar (200));
insert into t1 values (1, 'aa');
insert into t1 values (2, 'bb');
- Run 3 concurrent sessions to observe the bug
- Session 1
start transaction;
select id1 from test.t1 where id1=1 for update;
select sleep(100000);
- Session 2
start transaction;
select id1 from test.t1 where id1=1 for update;
- Session 3
MariaDB [test]> select * from performance_schema.threads where type = 'foreground'\G
*************************** Only relevant row displayed below ***************************
THREAD_ID: 12
NAME: thread/sql/one_connection
TYPE: FOREGROUND
PROCESSLIST_ID: 4
PROCESSLIST_USER: haidong
PROCESSLIST_HOST: NULL
PROCESSLIST_DB: NULL
PROCESSLIST_COMMAND: Query
PROCESSLIST_TIME: 9
PROCESSLIST_STATE: Sending data
PROCESSLIST_INFO: select id1 from test.t1 where id1=1 for update
PARENT_THREAD_ID: 1
ROLE: NULL
INSTRUMENTED: YES
HISTORY: YES
CONNECTION_TYPE: Socket
THREAD_OS_ID: 22508
MariaDB [test]> select * from performance_schema.events_waits_current where thread_id=12\G
*************************** 1. row ***************************
THREAD_ID: 12
EVENT_ID: 236
END_EVENT_ID: NULL
EVENT_NAME: wait/io/table/sql/handler <<<Incorrect instrument name
SOURCE:
TIMER_START: 767747433709600
TIMER_END: 791300625915200
TIMER_WAIT: 23553192205600
SPINS: NULL
OBJECT_SCHEMA: test
OBJECT_NAME: t1
INDEX_NAME: NULL
OBJECT_TYPE: TABLE
OBJECT_INSTANCE_BEGIN: 139905003640240
NESTING_EVENT_ID: 235
NESTING_EVENT_TYPE: STAGE
OPERATION: fetch
NUMBER_OF_BYTES: 47
FLAGS: NULL
1 row in set (0.001 sec)
- Session 1
I'm working on a fix.
Attachments
Activity
Field | Original Value | New Value |
---|---|---|
Description |
In MariaDB (as well as in MySQL 8), we have no wait event instrumentation for record locks and for table locks.
As such, table and row lock waits are reported incorrectly as "wait/io/table/sql/handler". This makes performance troubleshooting impossible for customers. h2. Steps to reproduce: # Add the following line into my.cnf before instance start {noformat} performance_schema=ON {noformat} # Run the following to set up all consumers and instrumentation {code:SQL} UPDATE performance_schema.setup_consumers SET ENABLED = 'YES'; UPDATE performance_schema.setup_instruments SET ENABLED = 'YES', TIMED = 'YES'; set global innodb_lock_wait_timeout=7200; {code} # Set up test table {code:SQL} create database test; use test create table t1 (id1 int(11), col1 varchar (200)); insert into t1 values (1, 'aa'); insert into t1 values (2, 'bb'); {code} # Run 3 concurrent sessions to observe the bug ## Session 1 {code:SQL} start transaction; select id1 from test.t1 where id1=1 for update; select sleep(100000); {code} ## Session 2 {code:SQL} start transaction; select id1 from test.t1 where id1=1 for update; {code} ## Session 3 {code:SQL} MariaDB [test]> select * from performance_schema.threads where type = 'foreground'\G *************************** Only relevant row displayed below *************************** THREAD_ID: 12 NAME: thread/sql/one_connection TYPE: FOREGROUND PROCESSLIST_ID: 4 PROCESSLIST_USER: haidong PROCESSLIST_HOST: NULL PROCESSLIST_DB: NULL PROCESSLIST_COMMAND: Query PROCESSLIST_TIME: 9 PROCESSLIST_STATE: Sending data PROCESSLIST_INFO: select id1 from test.t1 where id1=1 for update PARENT_THREAD_ID: 1 ROLE: NULL INSTRUMENTED: YES HISTORY: YES CONNECTION_TYPE: Socket THREAD_OS_ID: 22508 MariaDB [test]> select * from performance_schema.events_waits_current where thread_id=12\G *************************** 1. row *************************** THREAD_ID: 12 EVENT_ID: 236 END_EVENT_ID: NULL EVENT_NAME: wait/io/table/sql/handler <<<Incorrect instrument name SOURCE: TIMER_START: 767747433709600 TIMER_END: 791300625915200 TIMER_WAIT: 23553192205600 SPINS: NULL OBJECT_SCHEMA: test OBJECT_NAME: t1 INDEX_NAME: NULL OBJECT_TYPE: TABLE OBJECT_INSTANCE_BEGIN: 139905003640240 NESTING_EVENT_ID: 235 NESTING_EVENT_TYPE: STAGE OPERATION: fetch NUMBER_OF_BYTES: 47 FLAGS: NULL 1 row in set (0.001 sec) {code} I'm working on a fix. |
In MariaDB (as well as in MySQL 8), we have no wait event instrumentation for record locks and for table locks.
As such, table and row lock waits are reported incorrectly as "wait/io/table/sql/handler". This makes performance troubleshooting impossible for customers. The expected outcome is to create 2 more instruments: row lock and table lock. These 2 types of lock waits can then be measured inside performance_schema. Being able to separate lock waits from IO waits will aid performance tuning, because reducing them will require difference approaches. h2. Steps to reproduce: # Add the following line into my.cnf before instance start {noformat} performance_schema=ON {noformat} # Run the following to set up all consumers and instrumentation {code:SQL} UPDATE performance_schema.setup_consumers SET ENABLED = 'YES'; UPDATE performance_schema.setup_instruments SET ENABLED = 'YES', TIMED = 'YES'; set global innodb_lock_wait_timeout=7200; {code} # Set up test table {code:SQL} create database test; use test create table t1 (id1 int(11), col1 varchar (200)); insert into t1 values (1, 'aa'); insert into t1 values (2, 'bb'); {code} # Run 3 concurrent sessions to observe the bug ## Session 1 {code:SQL} start transaction; select id1 from test.t1 where id1=1 for update; select sleep(100000); {code} ## Session 2 {code:SQL} start transaction; select id1 from test.t1 where id1=1 for update; {code} ## Session 3 {code:SQL} MariaDB [test]> select * from performance_schema.threads where type = 'foreground'\G *************************** Only relevant row displayed below *************************** THREAD_ID: 12 NAME: thread/sql/one_connection TYPE: FOREGROUND PROCESSLIST_ID: 4 PROCESSLIST_USER: haidong PROCESSLIST_HOST: NULL PROCESSLIST_DB: NULL PROCESSLIST_COMMAND: Query PROCESSLIST_TIME: 9 PROCESSLIST_STATE: Sending data PROCESSLIST_INFO: select id1 from test.t1 where id1=1 for update PARENT_THREAD_ID: 1 ROLE: NULL INSTRUMENTED: YES HISTORY: YES CONNECTION_TYPE: Socket THREAD_OS_ID: 22508 MariaDB [test]> select * from performance_schema.events_waits_current where thread_id=12\G *************************** 1. row *************************** THREAD_ID: 12 EVENT_ID: 236 END_EVENT_ID: NULL EVENT_NAME: wait/io/table/sql/handler <<<Incorrect instrument name SOURCE: TIMER_START: 767747433709600 TIMER_END: 791300625915200 TIMER_WAIT: 23553192205600 SPINS: NULL OBJECT_SCHEMA: test OBJECT_NAME: t1 INDEX_NAME: NULL OBJECT_TYPE: TABLE OBJECT_INSTANCE_BEGIN: 139905003640240 NESTING_EVENT_ID: 235 NESTING_EVENT_TYPE: STAGE OPERATION: fetch NUMBER_OF_BYTES: 47 FLAGS: NULL 1 row in set (0.001 sec) {code} I'm working on a fix. |
Summary | No wait event for the record lock and table lock | Wait events do not distinguish waiting-for-I/O and waiting-for-locks |
Component/s | Locking [ 10900 ] | |
Component/s | Performance Schema [ 15627 ] | |
Assignee | Vladislav Lesin [ vlad.lesin ] |
Fix Version/s | 10.6 [ 24028 ] |
Status | Open [ 1 ] | Confirmed [ 10101 ] |
Assignee | Vladislav Lesin [ vlad.lesin ] | Andrew Hutchings [ JIRAUSER52179 ] |
Fix Version/s | 10.4.29 [ 28510 ] | |
Fix Version/s | 10.6 [ 24028 ] | |
Resolution | Fixed [ 1 ] | |
Status | Confirmed [ 10101 ] | Closed [ 6 ] |
Fix Version/s | 10.5.20 [ 28512 ] | |
Fix Version/s | 10.6.13 [ 28514 ] | |
Fix Version/s | 10.8.8 [ 28518 ] | |
Fix Version/s | 10.9.6 [ 28520 ] | |
Fix Version/s | 10.10.4 [ 28522 ] | |
Fix Version/s | 10.11.3 [ 28524 ] |
Description |
In MariaDB (as well as in MySQL 8), we have no wait event instrumentation for record locks and for table locks.
As such, table and row lock waits are reported incorrectly as "wait/io/table/sql/handler". This makes performance troubleshooting impossible for customers. The expected outcome is to create 2 more instruments: row lock and table lock. These 2 types of lock waits can then be measured inside performance_schema. Being able to separate lock waits from IO waits will aid performance tuning, because reducing them will require difference approaches. h2. Steps to reproduce: # Add the following line into my.cnf before instance start {noformat} performance_schema=ON {noformat} # Run the following to set up all consumers and instrumentation {code:SQL} UPDATE performance_schema.setup_consumers SET ENABLED = 'YES'; UPDATE performance_schema.setup_instruments SET ENABLED = 'YES', TIMED = 'YES'; set global innodb_lock_wait_timeout=7200; {code} # Set up test table {code:SQL} create database test; use test create table t1 (id1 int(11), col1 varchar (200)); insert into t1 values (1, 'aa'); insert into t1 values (2, 'bb'); {code} # Run 3 concurrent sessions to observe the bug ## Session 1 {code:SQL} start transaction; select id1 from test.t1 where id1=1 for update; select sleep(100000); {code} ## Session 2 {code:SQL} start transaction; select id1 from test.t1 where id1=1 for update; {code} ## Session 3 {code:SQL} MariaDB [test]> select * from performance_schema.threads where type = 'foreground'\G *************************** Only relevant row displayed below *************************** THREAD_ID: 12 NAME: thread/sql/one_connection TYPE: FOREGROUND PROCESSLIST_ID: 4 PROCESSLIST_USER: haidong PROCESSLIST_HOST: NULL PROCESSLIST_DB: NULL PROCESSLIST_COMMAND: Query PROCESSLIST_TIME: 9 PROCESSLIST_STATE: Sending data PROCESSLIST_INFO: select id1 from test.t1 where id1=1 for update PARENT_THREAD_ID: 1 ROLE: NULL INSTRUMENTED: YES HISTORY: YES CONNECTION_TYPE: Socket THREAD_OS_ID: 22508 MariaDB [test]> select * from performance_schema.events_waits_current where thread_id=12\G *************************** 1. row *************************** THREAD_ID: 12 EVENT_ID: 236 END_EVENT_ID: NULL EVENT_NAME: wait/io/table/sql/handler <<<Incorrect instrument name SOURCE: TIMER_START: 767747433709600 TIMER_END: 791300625915200 TIMER_WAIT: 23553192205600 SPINS: NULL OBJECT_SCHEMA: test OBJECT_NAME: t1 INDEX_NAME: NULL OBJECT_TYPE: TABLE OBJECT_INSTANCE_BEGIN: 139905003640240 NESTING_EVENT_ID: 235 NESTING_EVENT_TYPE: STAGE OPERATION: fetch NUMBER_OF_BYTES: 47 FLAGS: NULL 1 row in set (0.001 sec) {code} I'm working on a fix. |
In MariaDB (as well as in MySQL 8), we have no wait event instrumentation for record locks and for table locks.
As such, table and row lock waits are reported incorrectly as "wait/io/table/sql/handler". This makes performance troubleshooting impossible for customers. -The expected outcome is to create 2 more instruments: row lock and table lock. These 2 types of lock waits can then be measured inside performance_schema. Being able to separate lock waits from IO waits will aid performance tuning, because reducing them will require difference approaches.- Table and row lock instrumentation maybe too resource intensive. In the meantime, the fix h2. Steps to reproduce: # Add the following line into my.cnf before instance start {noformat} performance_schema=ON {noformat} # Run the following to set up all consumers and instrumentation {code:SQL} UPDATE performance_schema.setup_consumers SET ENABLED = 'YES'; UPDATE performance_schema.setup_instruments SET ENABLED = 'YES', TIMED = 'YES'; set global innodb_lock_wait_timeout=7200; {code} # Set up test table {code:SQL} create database test; use test create table t1 (id1 int(11), col1 varchar (200)); insert into t1 values (1, 'aa'); insert into t1 values (2, 'bb'); {code} # Run 3 concurrent sessions to observe the bug ## Session 1 {code:SQL} start transaction; select id1 from test.t1 where id1=1 for update; select sleep(100000); {code} ## Session 2 {code:SQL} start transaction; select id1 from test.t1 where id1=1 for update; {code} ## Session 3 {code:SQL} MariaDB [test]> select * from performance_schema.threads where type = 'foreground'\G *************************** Only relevant row displayed below *************************** THREAD_ID: 12 NAME: thread/sql/one_connection TYPE: FOREGROUND PROCESSLIST_ID: 4 PROCESSLIST_USER: haidong PROCESSLIST_HOST: NULL PROCESSLIST_DB: NULL PROCESSLIST_COMMAND: Query PROCESSLIST_TIME: 9 PROCESSLIST_STATE: Sending data PROCESSLIST_INFO: select id1 from test.t1 where id1=1 for update PARENT_THREAD_ID: 1 ROLE: NULL INSTRUMENTED: YES HISTORY: YES CONNECTION_TYPE: Socket THREAD_OS_ID: 22508 MariaDB [test]> select * from performance_schema.events_waits_current where thread_id=12\G *************************** 1. row *************************** THREAD_ID: 12 EVENT_ID: 236 END_EVENT_ID: NULL EVENT_NAME: wait/io/table/sql/handler <<<Incorrect instrument name SOURCE: TIMER_START: 767747433709600 TIMER_END: 791300625915200 TIMER_WAIT: 23553192205600 SPINS: NULL OBJECT_SCHEMA: test OBJECT_NAME: t1 INDEX_NAME: NULL OBJECT_TYPE: TABLE OBJECT_INSTANCE_BEGIN: 139905003640240 NESTING_EVENT_ID: 235 NESTING_EVENT_TYPE: STAGE OPERATION: fetch NUMBER_OF_BYTES: 47 FLAGS: NULL 1 row in set (0.001 sec) {code} I'm working on a fix. |
Description |
In MariaDB (as well as in MySQL 8), we have no wait event instrumentation for record locks and for table locks.
As such, table and row lock waits are reported incorrectly as "wait/io/table/sql/handler". This makes performance troubleshooting impossible for customers. -The expected outcome is to create 2 more instruments: row lock and table lock. These 2 types of lock waits can then be measured inside performance_schema. Being able to separate lock waits from IO waits will aid performance tuning, because reducing them will require difference approaches.- Table and row lock instrumentation maybe too resource intensive. In the meantime, the fix h2. Steps to reproduce: # Add the following line into my.cnf before instance start {noformat} performance_schema=ON {noformat} # Run the following to set up all consumers and instrumentation {code:SQL} UPDATE performance_schema.setup_consumers SET ENABLED = 'YES'; UPDATE performance_schema.setup_instruments SET ENABLED = 'YES', TIMED = 'YES'; set global innodb_lock_wait_timeout=7200; {code} # Set up test table {code:SQL} create database test; use test create table t1 (id1 int(11), col1 varchar (200)); insert into t1 values (1, 'aa'); insert into t1 values (2, 'bb'); {code} # Run 3 concurrent sessions to observe the bug ## Session 1 {code:SQL} start transaction; select id1 from test.t1 where id1=1 for update; select sleep(100000); {code} ## Session 2 {code:SQL} start transaction; select id1 from test.t1 where id1=1 for update; {code} ## Session 3 {code:SQL} MariaDB [test]> select * from performance_schema.threads where type = 'foreground'\G *************************** Only relevant row displayed below *************************** THREAD_ID: 12 NAME: thread/sql/one_connection TYPE: FOREGROUND PROCESSLIST_ID: 4 PROCESSLIST_USER: haidong PROCESSLIST_HOST: NULL PROCESSLIST_DB: NULL PROCESSLIST_COMMAND: Query PROCESSLIST_TIME: 9 PROCESSLIST_STATE: Sending data PROCESSLIST_INFO: select id1 from test.t1 where id1=1 for update PARENT_THREAD_ID: 1 ROLE: NULL INSTRUMENTED: YES HISTORY: YES CONNECTION_TYPE: Socket THREAD_OS_ID: 22508 MariaDB [test]> select * from performance_schema.events_waits_current where thread_id=12\G *************************** 1. row *************************** THREAD_ID: 12 EVENT_ID: 236 END_EVENT_ID: NULL EVENT_NAME: wait/io/table/sql/handler <<<Incorrect instrument name SOURCE: TIMER_START: 767747433709600 TIMER_END: 791300625915200 TIMER_WAIT: 23553192205600 SPINS: NULL OBJECT_SCHEMA: test OBJECT_NAME: t1 INDEX_NAME: NULL OBJECT_TYPE: TABLE OBJECT_INSTANCE_BEGIN: 139905003640240 NESTING_EVENT_ID: 235 NESTING_EVENT_TYPE: STAGE OPERATION: fetch NUMBER_OF_BYTES: 47 FLAGS: NULL 1 row in set (0.001 sec) {code} I'm working on a fix. |
In MariaDB (as well as in MySQL 8), we have no wait event instrumentation for record locks and for table locks.
As such, table and row lock waits are reported incorrectly as "wait/io/table/sql/handler". This makes performance troubleshooting impossible for customers. -The expected outcome is to create 2 more instruments: row lock and table lock. These 2 types of lock waits can then be measured inside performance_schema. Being able to separate lock waits from IO waits will aid performance tuning, because reducing them will require difference approaches.- Table and row lock instrumentation maybe too resource intensive. In the meantime, the fix in https://github.com/MariaDB/server/pull/2206 marks this kind of wait as wait/lock/table/sql/handler h2. Steps to reproduce: # Add the following line into my.cnf before instance start {noformat} performance_schema=ON {noformat} # Run the following to set up all consumers and instrumentation {code:SQL} UPDATE performance_schema.setup_consumers SET ENABLED = 'YES'; UPDATE performance_schema.setup_instruments SET ENABLED = 'YES', TIMED = 'YES'; set global innodb_lock_wait_timeout=7200; {code} # Set up test table {code:SQL} create database test; use test create table t1 (id1 int(11), col1 varchar (200)); insert into t1 values (1, 'aa'); insert into t1 values (2, 'bb'); {code} # Run 3 concurrent sessions to observe the bug ## Session 1 {code:SQL} start transaction; select id1 from test.t1 where id1=1 for update; select sleep(100000); {code} ## Session 2 {code:SQL} start transaction; select id1 from test.t1 where id1=1 for update; {code} ## Session 3 {code:SQL} MariaDB [test]> select * from performance_schema.threads where type = 'foreground'\G *************************** Only relevant row displayed below *************************** THREAD_ID: 12 NAME: thread/sql/one_connection TYPE: FOREGROUND PROCESSLIST_ID: 4 PROCESSLIST_USER: haidong PROCESSLIST_HOST: NULL PROCESSLIST_DB: NULL PROCESSLIST_COMMAND: Query PROCESSLIST_TIME: 9 PROCESSLIST_STATE: Sending data PROCESSLIST_INFO: select id1 from test.t1 where id1=1 for update PARENT_THREAD_ID: 1 ROLE: NULL INSTRUMENTED: YES HISTORY: YES CONNECTION_TYPE: Socket THREAD_OS_ID: 22508 MariaDB [test]> select * from performance_schema.events_waits_current where thread_id=12\G *************************** 1. row *************************** THREAD_ID: 12 EVENT_ID: 236 END_EVENT_ID: NULL EVENT_NAME: wait/io/table/sql/handler <<<Incorrect instrument name SOURCE: TIMER_START: 767747433709600 TIMER_END: 791300625915200 TIMER_WAIT: 23553192205600 SPINS: NULL OBJECT_SCHEMA: test OBJECT_NAME: t1 INDEX_NAME: NULL OBJECT_TYPE: TABLE OBJECT_INSTANCE_BEGIN: 139905003640240 NESTING_EVENT_ID: 235 NESTING_EVENT_TYPE: STAGE OPERATION: fetch NUMBER_OF_BYTES: 47 FLAGS: NULL 1 row in set (0.001 sec) {code} I'm working on a fix. |
Assignee | Andrew Hutchings [ JIRAUSER52179 ] | |
Resolution | Fixed [ 1 ] | |
Status | Closed [ 6 ] | Stalled [ 10000 ] |
Fix Version/s | 10.5 [ 23123 ] | |
Fix Version/s | 10.6 [ 24028 ] | |
Fix Version/s | 10.10 [ 27530 ] | |
Fix Version/s | 10.11 [ 27614 ] | |
Fix Version/s | 11.0 [ 28320 ] | |
Fix Version/s | 11.1 [ 28549 ] | |
Fix Version/s | 11.2 [ 28603 ] | |
Fix Version/s | 10.4.29 [ 28510 ] | |
Fix Version/s | 10.5.20 [ 28512 ] | |
Fix Version/s | 10.6.13 [ 28514 ] | |
Fix Version/s | 10.8.8 [ 28518 ] | |
Fix Version/s | 10.9.6 [ 28520 ] | |
Fix Version/s | 10.10.4 [ 28522 ] | |
Fix Version/s | 10.11.3 [ 28524 ] |
Status | Stalled [ 10000 ] | Open [ 1 ] |
Fix Version/s | 10.10 [ 27530 ] |
Fix Version/s | 11.0 [ 28320 ] |
Fix Version/s | 11.1 [ 28549 ] |
Fix Version/s | 11.2(EOL) [ 28603 ] |
vlad.lesin can you review pr 2206 please.