Description:
With profiling i see that it try to 'checking permissions' 90 times and the last one has high DURATION
mysql> SELECT @@version;
+-----------+
| @@version |
+-----------+
| 8.0.12 |
+-----------+
1 row in set (0.00 sec)
mysql>
mysql> DROP TABLE IF EXISTS `bug`;
Query OK, 0 rows affected (0.07 sec)
mysql>
mysql>
mysql> CREATE TABLE `bug` (
-> `bug` tinyint(3) unsigned NOT NULL
-> ) ENGINE=InnoDB DEFAULT CHARSET=latin1 ROW_FORMAT=DYNAMIC;
Query OK, 0 rows affected (0.01 sec)
mysql>
mysql> SET SESSION profiling = 1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
mysql>
mysql> SHOW fields FROM `bug`;
+-------+---------------------+------+-----+---------+-------+
| Field | Type | Null | Key | Default | Extra |
+-------+---------------------+------+-----+---------+-------+
| bug | tinyint(3) unsigned | NO | | NULL | |
+-------+---------------------+------+-----+---------+-------+
1 row in set (0.51 sec)
mysql>
mysql> SHOW PROFILES;
+----------+------------+------------------------+
| Query_ID | Duration | Query |
+----------+------------+------------------------+
| 1 | 0.50274725 | SHOW fields FROM `bug` |
+----------+------------+------------------------+
1 row in set, 1 warning (0.00 sec)
mysql>
mysql> SELECT STATE, SUM(DURATION) AS Total_R, COUNT(*) AS Calls, SUM(DURATION) / COUNT(*) AS "R/Call", SUM(CPU_USER) CPU_USER, SUM(CPU_SYSTEM) CPU_SYSTEM, SUM(CONTEXT_VOLUNTARY) CONTEXT_VOLUNTARY, SUM(CONTEXT_INVOLUNTARY) CONTEXT_INVOLUNTARY, SUM(BLOCK_OPS_IN) BLOCK_OPS_IN, SUM(BLOCK_OPS_OUT) BLOCK_OPS_OUT, SUM(MESSAGES_SENT) MESSAGES_SENT, SUM(MESSAGES_RECEIVED) MESSAGES_RECEIVED, SUM(PAGE_FAULTS_MAJOR) PAGE_FAULTS_MAJOR, SUM(PAGE_FAULTS_MINOR) PAGE_FAULTS_MINOR, SUM(SWAPS) SWAPS FROM INFORMATION_SCHEMA.PROFILING GROUP BY STATE ORDER BY Total_R DESC;
+----------------------+----------+-------+--------------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+
| STATE | Total_R | Calls | R/Call | 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 |
+----------------------+----------+-------+--------------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+
| checking permissions | 0.074314 | 90 | 0.0008257111 | 0.074576 | 0.000000 | 13 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
| removing tmp table | 0.000595 | 2 | 0.0002975000 | 0.000599 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
| Creating sort index | 0.000134 | 1 | 0.0001340000 | 0.000123 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
| freeing items | 0.000099 | 1 | 0.0000990000 | 0.000102 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
| query end | 0.000054 | 3 | 0.0000180000 | 0.000050 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
| closing tables | 0.000037 | 1 | 0.0000370000 | 0.000036 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
| cleaning up | 0.000015 | 1 | 0.0000150000 | 0.000014 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
| end | 0.000015 | 1 | 0.0000150000 | 0.000012 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
+----------------------+----------+-------+--------------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+
8 rows in set, 1 warning (0.00 sec)
mysql>
mysql> SELECT * FROM INFORMATION_SCHEMA.PROFILING;
How to repeat:
SELECT @@version;
DROP TABLE IF EXISTS `bug`;
CREATE TABLE `bug` (
`bug` tinyint(3) unsigned NOT NULL
) ENGINE=InnoDB DEFAULT CHARSET=latin1 ROW_FORMAT=DYNAMIC;
SET SESSION profiling = 1;
SHOW fields FROM `bug`;
SHOW PROFILES;
SELECT STATE, SUM(DURATION) AS Total_R, COUNT(*) AS Calls, SUM(DURATION) / COUNT(*) AS "R/Call", SUM(CPU_USER) CPU_USER, SUM(CPU_SYSTEM) CPU_SYSTEM, SUM(CONTEXT_VOLUNTARY) CONTEXT_VOLUNTARY, SUM(CONTEXT_INVOLUNTARY) CONTEXT_INVOLUNTARY, SUM(BLOCK_OPS_IN) BLOCK_OPS_IN, SUM(BLOCK_OPS_OUT) BLOCK_OPS_OUT, SUM(MESSAGES_SENT) MESSAGES_SENT, SUM(MESSAGES_RECEIVED) MESSAGES_RECEIVED, SUM(PAGE_FAULTS_MAJOR) PAGE_FAULTS_MAJOR, SUM(PAGE_FAULTS_MINOR) PAGE_FAULTS_MINOR, SUM(SWAPS) SWAPS FROM INFORMATION_SCHEMA.PROFILING GROUP BY STATE ORDER BY Total_R DESC;
SELECT * FROM INFORMATION_SCHEMA.PROFILING;
Description: With profiling i see that it try to 'checking permissions' 90 times and the last one has high DURATION mysql> SELECT @@version; +-----------+ | @@version | +-----------+ | 8.0.12 | +-----------+ 1 row in set (0.00 sec) mysql> mysql> DROP TABLE IF EXISTS `bug`; Query OK, 0 rows affected (0.07 sec) mysql> mysql> mysql> CREATE TABLE `bug` ( -> `bug` tinyint(3) unsigned NOT NULL -> ) ENGINE=InnoDB DEFAULT CHARSET=latin1 ROW_FORMAT=DYNAMIC; Query OK, 0 rows affected (0.01 sec) mysql> mysql> SET SESSION profiling = 1; Query OK, 0 rows affected, 1 warning (0.00 sec) mysql> mysql> SHOW fields FROM `bug`; +-------+---------------------+------+-----+---------+-------+ | Field | Type | Null | Key | Default | Extra | +-------+---------------------+------+-----+---------+-------+ | bug | tinyint(3) unsigned | NO | | NULL | | +-------+---------------------+------+-----+---------+-------+ 1 row in set (0.51 sec) mysql> mysql> SHOW PROFILES; +----------+------------+------------------------+ | Query_ID | Duration | Query | +----------+------------+------------------------+ | 1 | 0.50274725 | SHOW fields FROM `bug` | +----------+------------+------------------------+ 1 row in set, 1 warning (0.00 sec) mysql> mysql> SELECT STATE, SUM(DURATION) AS Total_R, COUNT(*) AS Calls, SUM(DURATION) / COUNT(*) AS "R/Call", SUM(CPU_USER) CPU_USER, SUM(CPU_SYSTEM) CPU_SYSTEM, SUM(CONTEXT_VOLUNTARY) CONTEXT_VOLUNTARY, SUM(CONTEXT_INVOLUNTARY) CONTEXT_INVOLUNTARY, SUM(BLOCK_OPS_IN) BLOCK_OPS_IN, SUM(BLOCK_OPS_OUT) BLOCK_OPS_OUT, SUM(MESSAGES_SENT) MESSAGES_SENT, SUM(MESSAGES_RECEIVED) MESSAGES_RECEIVED, SUM(PAGE_FAULTS_MAJOR) PAGE_FAULTS_MAJOR, SUM(PAGE_FAULTS_MINOR) PAGE_FAULTS_MINOR, SUM(SWAPS) SWAPS FROM INFORMATION_SCHEMA.PROFILING GROUP BY STATE ORDER BY Total_R DESC; +----------------------+----------+-------+--------------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+ | STATE | Total_R | Calls | R/Call | 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 | +----------------------+----------+-------+--------------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+ | checking permissions | 0.074314 | 90 | 0.0008257111 | 0.074576 | 0.000000 | 13 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | | removing tmp table | 0.000595 | 2 | 0.0002975000 | 0.000599 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | | Creating sort index | 0.000134 | 1 | 0.0001340000 | 0.000123 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | | freeing items | 0.000099 | 1 | 0.0000990000 | 0.000102 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | | query end | 0.000054 | 3 | 0.0000180000 | 0.000050 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | | closing tables | 0.000037 | 1 | 0.0000370000 | 0.000036 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | | cleaning up | 0.000015 | 1 | 0.0000150000 | 0.000014 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | | end | 0.000015 | 1 | 0.0000150000 | 0.000012 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | +----------------------+----------+-------+--------------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+ 8 rows in set, 1 warning (0.00 sec) mysql> mysql> SELECT * FROM INFORMATION_SCHEMA.PROFILING; How to repeat: SELECT @@version; DROP TABLE IF EXISTS `bug`; CREATE TABLE `bug` ( `bug` tinyint(3) unsigned NOT NULL ) ENGINE=InnoDB DEFAULT CHARSET=latin1 ROW_FORMAT=DYNAMIC; SET SESSION profiling = 1; SHOW fields FROM `bug`; SHOW PROFILES; SELECT STATE, SUM(DURATION) AS Total_R, COUNT(*) AS Calls, SUM(DURATION) / COUNT(*) AS "R/Call", SUM(CPU_USER) CPU_USER, SUM(CPU_SYSTEM) CPU_SYSTEM, SUM(CONTEXT_VOLUNTARY) CONTEXT_VOLUNTARY, SUM(CONTEXT_INVOLUNTARY) CONTEXT_INVOLUNTARY, SUM(BLOCK_OPS_IN) BLOCK_OPS_IN, SUM(BLOCK_OPS_OUT) BLOCK_OPS_OUT, SUM(MESSAGES_SENT) MESSAGES_SENT, SUM(MESSAGES_RECEIVED) MESSAGES_RECEIVED, SUM(PAGE_FAULTS_MAJOR) PAGE_FAULTS_MAJOR, SUM(PAGE_FAULTS_MINOR) PAGE_FAULTS_MINOR, SUM(SWAPS) SWAPS FROM INFORMATION_SCHEMA.PROFILING GROUP BY STATE ORDER BY Total_R DESC; SELECT * FROM INFORMATION_SCHEMA.PROFILING;