Bug #92387 SHOW SESSION VARIABLES stuck in state "Opening tables"
Submitted: 12 Sep 2018 14:10 Modified: 31 Oct 2019 19:28
Reporter: Tobias Grave Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Information schema Severity:S2 (Serious)
Version:5.7, 5.7.26, 5.7.27 OS:Ubuntu (16.04)
Assigned to: CPU Architecture:x86 (x86_64)

[12 Sep 2018 14:10] Tobias Grave
Description:
The popular MySQL database manager phpMyAdmin issues the command "SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS'" after connecting to a database. This command is usually executed as expected, but sometimes, under unknown circumstances, the corresponding MySQL proccess remains stuck in state "Opening tables" forever, and all subsequent queries for the affected database are blocked (state "Waiting for table metadata lock"). The stuck session variable process has to be killed in order to restore regular access to the database.

I usually see this issue a few times a week on a database server hosting about a thousand databases for common web applications like WordPress.

I use the latest 64 bit MySQL 5.7 version for Ubuntu 16.04 (5.7.23-1ubuntu16.04).

How to repeat:
I was unable to reproduce this issue in a testing environment, it seems to be a race condition that is only triggered under specific circumstances.
[12 Sep 2018 17:04] MySQL Verification Team
Thank you for the bug report. We need a repeatable test case so development could fix the issue. Comment here when you will able to provide the case so this bug report will open again. Thanks.
[27 Sep 2018 8:37] Paolo Ciucani
Hi,
I am able to reproduce this issue in my enviroment (MySQL 5.7.23-0ubuntu0.18.04.1, phpmyadmin 4.8.3).
I have this issue while importing an SQL file containing an export from mysqldump command. The same file imported by 'mysql' command works fine.

phpMyAdmin stucks until I restart mysql server and then phpMyAdmin shows a connection error and a Backtrace like this:

-------------------------------------
./libraries/classes/Dbi/DbiMysqli.php#213: mysqli_query(
,
string 'SET FOREIGN_KEY_CHECKS = ON;',
integer 0,
)
./libraries/classes/DatabaseInterface.php#319: PhpMyAdmin\Dbi\DbiMysqli->realQuery(
string 'SET FOREIGN_KEY_CHECKS = ON;',
,
integer 0,
)
./libraries/classes/DatabaseInterface.php#169: PhpMyAdmin\DatabaseInterface->tryQuery(
string 'SET FOREIGN_KEY_CHECKS = ON;',
integer 256,
integer 0,
boolean true,
)
./libraries/classes/DatabaseInterface.php#1390: PhpMyAdmin\DatabaseInterface->query(
string 'SET FOREIGN_KEY_CHECKS = ON;',
integer 256,
)
./libraries/classes/Util.php#2961: PhpMyAdmin\DatabaseInterface->setVariable(
string 'FOREIGN_KEY_CHECKS',
string 'ON',
)
./libraries/classes/Sql.php#2257: PhpMyAdmin\Util::handleDisableFKCheckCleanup(boolean true)
./import.php#736: PhpMyAdmin\Sql->executeQueryAndGetQueryResponse(
array,
boolean false,
string 'sviluppo',
string '',
NULL,
NULL,
NULL,
NULL,
NULL,
NULL,
string 'db_import.php',
string './themes/pmahomme/img/',
NULL,
NULL,
NULL,
string '/*!40000 ALTER TABLE `xxxxxxx` DISABLE KEYS */',
NULL,
NULL,
)
Warning in ./libraries/classes/Dbi/DbiMysqli.php#213
mysqli_query(): Error reading result set's header

----------------------------------

so I think the problem is right before "INSERT INTO" row: /*!40000 ALTER TABLE `xxxxxxx` DISABLE KEYS */
the foreign key checks is disabled at the beginning of the dump file: /*!40014 SET @OLD_FOREIGN_KEY_CHECKS=@@FOREIGN_KEY_CHECKS, FOREIGN_KEY_CHECKS=0 */
[17 Dec 2018 14:51] Arek M
Here is sometimes stuck on 5.7.22, for example one case and show processlist:

|      24 | bmuser    | db05:56092 | mysql         | Query   | 4381 | Waiting for schema metadata lock | DROP DATABASE `abc_2`                       |         0 |             0 |
| 8861721 | abc_2    | dbadmin:43028      | abc_2    | Query   | 6111 | Opening tables                   | SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS' |         0 |             0 |
[17 Dec 2018 15:41] MySQL Verification Team
When this happens, please collect stack traces of the mysqld process, and indicate which version of mysqld they're from:

gdb -ex "set pagination 0" -ex "thread apply all bt" --batch -p $(pidof mysqld)
[9 Jan 2019 12:22] Nikolay Vizovitin
Full gdb output for MySQL w/ hanging process

Attachment: mysql-opening-tables-gdb.txt (text/plain), 20.86 KiB.

[9 Jan 2019 12:23] Nikolay Vizovitin
I have a container VM with Ubuntu 16.04 where this issue is reproduced (with the same use case).

{code}
mysql> show full processlist;
+-----+------------------+-----------+---------+---------+------+----------------+--------------------------------------------------+
| Id  | User             | Host      | db      | Command | Time | State          | Info                                             |
+-----+------------------+-----------+---------+---------+------+----------------+--------------------------------------------------+
| 104 | admin            | localhost | psa     | Sleep   |  374 |                | NULL                                             |
| 105 | admin            | localhost | psa     | Sleep   |  374 |                | NULL                                             |
| 106 | pma_gsnAmu_CqNnY | localhost | NULL    | Sleep   |   89 |                | NULL                                             |
| 107 | ruslan4          | localhost | ruslan4 | Query   |   68 | Opening tables | SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS' |
| 108 | admin            | localhost | psa     | Query   |    0 | starting       | show full processlist                            |
| 109 | admin            | localhost | psa     | Sleep   |  290 |                | NULL                                             |
| 110 | admin            | localhost | psa     | Sleep   |  290 |                | NULL                                             |
+-----+------------------+-----------+---------+---------+------+----------------+--------------------------------------------------+
7 rows in set (0.00 sec)

mysql> STATUS;
--------------
mysql  Ver 14.14 Distrib 5.7.24, for Linux (x86_64) using  EditLine wrapper

Connection id:          108
Current database:       psa
Current user:           admin@localhost
SSL:                    Not in use
Current pager:          stdout
Using outfile:          ''
Using delimiter:        ;
Server version:         5.7.24-0ubuntu0.16.04.1 (Ubuntu)
Protocol version:       10
Connection:             Localhost via UNIX socket
Server characterset:    latin1
Db     characterset:    utf8
Client characterset:    latin1
Conn.  characterset:    latin1
UNIX socket:            /var/run/mysqld/mysqld.sock
Uptime:                 24 min 37 sec

Threads: 7  Questions: 7081  Slow queries: 0  Opens: 2818  Flush tables: 1  Open tables: 359  Queries per second avg: 4.794
--------------

{code}

(see the attached file mysql-opening-tables-gdb.txt for full gdb output)
{code}
# gdb -ex "set pagination 0" -ex "thread apply all bt" --batch -p $(pidof mysqld)
...

Thread 32 (Thread 0x7f9368703700 (LWP 1154)):
#0  0x0000000000e8ee77 in my_getsystime ()
#1  0x0000000000b9f288 in MDL_context::acquire_lock(MDL_request*, unsigned long) ()
#2  0x0000000000bf4af1 in open_table(THD*, TABLE_LIST*, Open_table_context*) ()
#3  0x0000000000bfb9db in open_tables(THD*, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) ()
#4  0x0000000000bfc189 in open_tables_for_query(THD*, TABLE_LIST*, unsigned int) ()
#5  0x0000000000753b35 in ?? ()
#6  0x0000000000c5195b in mysql_execute_command(THD*, bool) ()
#7  0x0000000000c53ead in mysql_parse(THD*, Parser_state*) ()
#8  0x0000000000c54fea in dispatch_command(THD*, COM_DATA const*, enum_server_command) ()
#9  0x0000000000c564a7 in do_command(THD*) ()
#10 0x0000000000d18848 in handle_connection ()
#11 0x0000000000ec9834 in pfs_spawn_thread ()
#12 0x00007f938a2fc6ba in start_thread (arg=0x7f9368703700) at pthread_create.c:333
#13 0x00007f938979141d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

...
{code}

Thread 32 seems to correspond to the hanging MySQL process. It is stuck in 
  0x0000000000bfb9db in open_tables(THD*, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) ()
(other calls above this function in stack trace tend to change with time - it continually attempts to acquire a table lock and recover from failures).

Please respond if you need any additional information.
[10 Jan 2019 9:04] Nikolay Vizovitin
I've attached a minimized DB dump with only 1 table that could be used to reproduce the issue (visible only to devs).

I've been able to reproduce the issue on the following configuration:
1. Ubuntu 16.04
2. MySQL 5.7.24-0ubuntu0.16.04.1
3. phpMyAdmin 4.8.3 and 4.8.4

# dpkg -l | egrep '\<mysql-|\<libmysql'
ii  libdbd-mysql-perl                  4.033-1ubuntu0.1                        amd64        Perl5 database interface to the MySQL database
ii  libmysqlclient-dev                 5.7.24-0ubuntu0.16.04.1                 amd64        MySQL database development files
ii  libmysqlclient20:amd64             5.7.24-0ubuntu0.16.04.1                 amd64        MySQL database client library
ii  mysql-client-5.7                   5.7.24-0ubuntu0.16.04.1                 amd64        MySQL database client binaries
ii  mysql-client-core-5.7              5.7.24-0ubuntu0.16.04.1                 amd64        MySQL database core client binaries
ii  mysql-common                       5.7.24-0ubuntu0.16.04.1                 all          MySQL database common files, e.g. /etc/mysql/my.cnf
ii  mysql-server                       5.7.24-0ubuntu0.16.04.1                 all          MySQL database server (metapackage depending on the latest version)
ii  mysql-server-5.7                   5.7.24-0ubuntu0.16.04.1                 amd64        MySQL database server binaries and system database setup
ii  mysql-server-core-5.7              5.7.24-0ubuntu0.16.04.1                 amd64        MySQL database server binaries
[31 Jan 2019 15:30] Kyle Pinkley
We have had two reports of customer's experiencing this issue as well. 

The first customer reported this early in December 2018. The server is using MySQL 5.7.24 and phpMyAdmin 4.8.3-2 at the time.

The second customer reported this yesterday (January 30, 2019). The server is using MySQL 5.7.25 and phpMyAdmin 4.8.3-3 at the time.
[12 Feb 2019 16:09] Joerg Kost
MySQL stack trace

Attachment: strace (application/octet-stream, text), 22.46 KiB.

[12 Feb 2019 16:10] Joerg Kost
Saw this too with 5.7.25-0ubuntu0.16.04.2 and phpmyadmin 4.8.5.
[12 Feb 2019 16:26] MySQL Verification Team
Thank you for the feedback I will try with the dump provided.
[12 Feb 2019 16:26] MySQL Verification Team
Thank you for the feedback I will try with the dump provided.
[12 Feb 2019 16:49] MySQL Verification Team
I couldn't repeat with mysql command client and WorkBench, then the issue is with PHPAdmin.
[15 Feb 2019 12:38] Joerg Kost
Did you try out the dumps from  Nikolay?

The workaround to restart the database is indeed a MySQL issue / bug, not a phpmyadmin thing. Maybe it is triggered by phpmyadmin.

https://support.plesk.com/hc/en-us/articles/360004375313-phpMyAdmin-loads-long-time-and-fa...
[15 Feb 2019 15:47] MySQL Verification Team
Yes I tried the dump provided and checked with mysql client and WorkBench, if there are specific circumstances to reproduce it I will appreciate for that info. Thanks.
[15 Feb 2019 15:47] MySQL Verification Team
Yes I tried the dump provided and checked with mysql client and WorkBench, if there are specific circumstances to reproduce it I will appreciate for that info. Thanks.
[8 Mar 2019 20:27] Kyle Pinkley
Had another report of this yesterday with a different customer, using phpMyAdmin 4.8.3-7 and MySQL Ver 14.14 Distrib 5.7.25.
[28 May 2019 7:11] Menno Zonneveld
I just wanted to add that I see this happening on a CentOS 7 server as well, running cPanel if it matters.

Running mariadb.x86_64 version 1:5.5.60-1.el7_5 and cpanel-phpmyadmin.noarch version 4.8.3-7.cp1176

I was able to reproduce it and find steps around it, though I'm not sure why it happens.

Bottom line is that if I omit '/*!40000 ALTER TABLE `articles` DISABLE KEYS */;' in the sql dumps it works fine.

The sql dumps don't contain 'SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS';', this is done by phpmyadmin.

This hangs until I kill the mysql query.

<code>
mysql> DROP TABLE IF EXISTS `articles`;
Query OK, 0 rows affected (0.01 sec)

mysql> CREATE TABLE `articles` (
    ->   `article_id` int(11) NOT NULL AUTO_INCREMENT,
    ->   `article_url` varchar(255) NOT NULL,
    ->   `article_title` varchar(255) NOT NULL,
    ->   `article_content` text NOT NULL,
    ->   `article_timestamp` int(11) NOT NULL,
    ->   PRIMARY KEY (`article_id`)
    -> ) ENGINE=InnoDB DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.03 sec)

mysql> LOCK TABLES `articles` WRITE;
Query OK, 0 rows affected (0.00 sec)

mysql> /*!40000 ALTER TABLE `articles` DISABLE KEYS */;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> INSERT INTO `articles` (`article_id`, `article_url`, `article_title`, `article_content`, `article_timestamp`) VALUES (1,'http://www.','www','text',1443080313);
Query OK, 1 row affected (0.00 sec)

# This hangs until I kill the query in mysql.
mysql> SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS';
# And this is the output because I killed the query.
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> 
</code>

This works as expected.

<code>
mysql> DROP TABLE IF EXISTS `articles`;
Query OK, 0 rows affected (0.01 sec)

mysql> CREATE TABLE `articles` (
    ->   `article_id` int(11) NOT NULL AUTO_INCREMENT,
    ->   `article_url` varchar(255) NOT NULL,
    ->   `article_title` varchar(255) NOT NULL,
    ->   `article_content` text NOT NULL,
    ->   `article_timestamp` int(11) NOT NULL,
    ->   PRIMARY KEY (`article_id`)
    -> ) ENGINE=InnoDB DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.06 sec)

mysql> LOCK TABLES `articles` WRITE;
Query OK, 0 rows affected (0.01 sec)

mysql> INSERT INTO `articles` (`article_id`, `article_url`, `article_title`, `article_content`, `article_timestamp`) VALUES (1,'http://www.','www','text',1443080313);
Query OK, 1 row affected (0.00 sec)

mysql> SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS';
+--------------------+-------+
| Variable_name      | Value |
+--------------------+-------+
| foreign_key_checks | ON    |
+--------------------+-------+
1 row in set (0.00 sec)

mysql> UNLOCK TABLES;
Query OK, 0 rows affected (0.00 sec)
</code>
[28 May 2019 9:07] MySQL Verification Team
Thank you,  Menno Zonneveld.
Verified as described on 5.7.26 build with the provided test case.

regards,
Umesh
[28 May 2019 9:10] MySQL Verification Team
- 5.7.26

rm -rf 95541
bin/mysqld --initialize-insecure --basedir=$PWD --datadir=$PWD/95541 --log-error-verbosity=3
bin/mysqld --no-defaults --basedir=$PWD --datadir=$PWD/95541 --core-file --socket=/tmp/mysql_ushastry.sock --port=3333 --log-error=$PWD/95541/log.err --log-error-verbosity=3 2>&1 &

 create database if not exists test;
 use test;
 DROP TABLE IF EXISTS `articles`;
 CREATE TABLE `articles` (
   `article_id` int(11) NOT NULL AUTO_INCREMENT,
   `article_url` varchar(255) NOT NULL,
   `article_title` varchar(255) NOT NULL,
   `article_content` text NOT NULL,
   `article_timestamp` int(11) NOT NULL,
   PRIMARY KEY (`article_id`)
 ) ENGINE=InnoDB DEFAULT CHARSET=latin1;

 LOCK TABLES `articles` WRITE;
 /*!40000 ALTER TABLE `articles` DISABLE KEYS */;
INSERT INTO `articles` (`article_id`, `article_url`, `article_title`, `article_content`, `article_timestamp`) VALUES (1,'http://www.','www','text',1443080313);
# This hangs until I kill the query in mysql.
 SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS';

-
 bin/mysql -uroot -S /tmp/mysql_ushastry.sock
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.7.26 MySQL Community Server (GPL)

Copyright (c) 2000, 2019, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> use test
Database changed
mysql>
mysql>  DROP TABLE IF EXISTS `articles`;
INSERT INTO `articles` (`article_id`, `article_url`, `article_title`, `article_content`, `article_timestamp`) VALUES (1,'http://www.','www','text',1443080313);
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql>  CREATE TABLE `articles` (
    ->    `article_id` int(11) NOT NULL AUTO_INCREMENT,
    ->    `article_url` varchar(255) NOT NULL,
    ->    `article_title` varchar(255) NOT NULL,
    ->    `article_content` text NOT NULL,
    ->    `article_timestamp` int(11) NOT NULL,
    ->    PRIMARY KEY (`article_id`)
    ->  ) ENGINE=InnoDB DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.00 sec)

mysql>
mysql>  LOCK TABLES `articles` WRITE;
Query OK, 0 rows affected (0.01 sec)

mysql>  /*!40000 ALTER TABLE `articles` DISABLE KEYS */;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> INSERT INTO `articles` (`article_id`, `article_url`, `article_title`, `article_content`, `article_timestamp`) VALUES (1,'http://www.','www','text',1443080313);
Query OK, 1 row affected (0.00 sec)

mysql> # This hangs until I kill the query in mysql.
mysql>  SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS';

^^ hanging

- another session

 bin/mysql -uroot -S /tmp/mysql_ushastry.sock
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.7.26 MySQL Community Server (GPL)

Copyright (c) 2000, 2019, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> show processlist;
+----+------+-----------+------+---------+------+----------------+--------------------------------------------------+
| Id | User | Host      | db   | Command | Time | State          | Info                                             |
+----+------+-----------+------+---------+------+----------------+--------------------------------------------------+
|  2 | root | localhost | test | Query   |   36 | Opening tables | SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS' |
|  3 | root | localhost | NULL | Query   |    0 | starting       | show processlist                                 |
+----+------+-----------+------+---------+------+----------------+--------------------------------------------------+
2 rows in set (0.00 sec)

mysql> show processlist;
+----+------+-----------+------+---------+------+----------------+--------------------------------------------------+
| Id | User | Host      | db   | Command | Time | State          | Info                                             |
+----+------+-----------+------+---------+------+----------------+--------------------------------------------------+
|  2 | root | localhost | test | Query   |  243 | Opening tables | SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS' |
|  3 | root | localhost | NULL | Query   |    0 | starting       | show processlist                                 |
+----+------+-----------+------+---------+------+----------------+--------------------------------------------------+
2 rows in set (0.00 sec)

mysql>
[8 Jul 2019 17:10] Support SimpleRezo
Having the same issue on FreeBSD 11.2, running mySQL 5.7.23 and using phpMyAdmin 4.9.0.1.
[23 Aug 2019 7:15] MySQL Verification Team
- 5.7.27 affected as well

 bin/mysql -uroot -S /tmp/mysql_ushastry.sock
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.7.27 MySQL Community Server (GPL)

Copyright (c) 2000, 2019, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql>  create database if not exists test;
Query OK, 1 row affected (0.00 sec)

mysql>  use test;
Database changed
mysql>  DROP TABLE IF EXISTS `articles`;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql>  CREATE TABLE `articles` (
    ->    `article_id` int(11) NOT NULL AUTO_INCREMENT,
    ->    `article_url` varchar(255) NOT NULL,
    ->    `article_title` varchar(255) NOT NULL,
    ->    `article_content` text NOT NULL,
    ->    `article_timestamp` int(11) NOT NULL,
    ->    PRIMARY KEY (`article_id`)
    ->  ) ENGINE=InnoDB DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.00 sec)

mysql>
mysql>  LOCK TABLES `articles` WRITE;
Query OK, 0 rows affected (0.01 sec)

mysql>  /*!40000 ALTER TABLE `articles` DISABLE KEYS */;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> INSERT INTO `articles` (`article_id`, `article_url`, `article_title`, `article_content`, `article_timestamp`) VALUES (1,'http://www.','www','text',1443080313);
Query OK, 1 row affected (0.00 sec)

mysql> # This hangs until I kill the query in mysql.
mysql>  SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS';

^^ hangs indefinately

- second session

 bin/mysql -uroot -S /tmp/mysql_ushastry.sock
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.7.27 MySQL Community Server (GPL)

Copyright (c) 2000, 2019, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
mysql> show processlist;
+----+------+-----------+------+---------+------+----------------+--------------------------------------------------+
| Id | User | Host      | db   | Command | Time | State          | Info                                             |
+----+------+-----------+------+---------+------+----------------+--------------------------------------------------+
|  2 | root | localhost | test | Query   |  165 | Opening tables | SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS' |
|  3 | root | localhost | NULL | Query   |    0 | starting       | show processlist                                 |
+----+------+-----------+------+---------+------+----------------+--------------------------------------------------+
2 rows in set (0.00 sec)

mysql>
mysql> system cat docs/INFO_SRC
commit: 8ccfc51ab8d361be94168fe04b6818d0b234c9c0
date: 2019-06-10 20:06:14 +0530
build-date: 2019-06-10 16:43:41 +0200
short: 8ccfc51
branch: mysql-5.7.27-release

MySQL source 5.7.27
- backtrace

Fri Aug 23 09:14:42 CEST 2019
     10 __io_getevents_0_4(libaio.so.1),LinuxAIOHandler::collect(os0file.cc:2506),LinuxAIOHandler::poll(os0file.cc:2666),os_aio_linux_handler(os0file.cc:2722),os_aio_handler(os0file.cc:2722),fil_aio_wait(fil0fil.cc:5854),io_handler_thread(srv0start.cc:311),start_thread(libpthread.so.0),clone(libc.so.6)
      3 pthread_cond_wait,wait(os0event.cc:171),os_event::wait_low(os0event.cc:171),srv_worker_thread(srv0srv.cc:2519),start_thread(libpthread.so.0),clone(libc.so.6)
      1 sigwait(libpthread.so.0),signal_hand(mysqld.cc:2125),pfs_spawn_thread(pfs.cc:2190),start_thread(libpthread.so.0),clone(libc.so.6)
      1 sigwaitinfo(libc.so.6),timer_notify_thread_func(posix_timers.c:77),pfs_spawn_thread(pfs.cc:2190),start_thread(libpthread.so.0),clone(libc.so.6)
      1 pthread_cond_wait,wait(os0event.cc:171),os_event::wait_low(os0event.cc:171),srv_purge_coordinator_suspend(srv0srv.cc:2675),srv_purge_coordinator_thread(srv0srv.cc:2675),start_thread(libpthread.so.0),clone(libc.so.6)
      1 pthread_cond_wait,wait(os0event.cc:171),os_event::wait_low(os0event.cc:171),buf_resize_thread(buf0buf.cc:3019),start_thread(libpthread.so.0),clone(libc.so.6)
      1 pthread_cond_wait,wait(os0event.cc:171),os_event::wait_low(os0event.cc:171),buf_dump_thread(buf0dump.cc:784),start_thread(libpthread.so.0),clone(libc.so.6)
      1 pthread_cond_wait,native_cond_wait(thr_cond.h:140),my_cond_wait(thr_cond.h:140),inline_mysql_cond_wait(thr_cond.h:140),compress_gtid_table(thr_cond.h:140),pfs_spawn_thread(pfs.cc:2190),start_thread(libpthread.so.0),clone(libc.so.6)
      1 pthread_cond_timedwait,os_event::timed_wait(os0event.cc:308),os_event::wait_time_low(os0event.cc:480),srv_monitor_thread(srv0srv.cc:1584),start_thread(libpthread.so.0),clone(libc.so.6)
      1 pthread_cond_timedwait,os_event::timed_wait(os0event.cc:308),os_event::wait_time_low(os0event.cc:480),srv_error_monitor_thread(srv0srv.cc:1750),start_thread(libpthread.so.0),clone(libc.so.6)
      1 pthread_cond_timedwait,os_event::timed_wait(os0event.cc:308),os_event::wait_time_low(os0event.cc:480),pc_sleep_if_needed(buf0flu.cc:2692),buf_flush_page_cleaner_coordinator(buf0flu.cc:2692),start_thread(libpthread.so.0),clone(libc.so.6)
      1 pthread_cond_timedwait,os_event::timed_wait(os0event.cc:308),os_event::wait_time_low(os0event.cc:480),lock_wait_timeout_thread(lock0wait.cc:489),start_thread(libpthread.so.0),clone(libc.so.6)
      1 pthread_cond_timedwait,os_event::timed_wait(os0event.cc:308),os_event::wait_time_low(os0event.cc:480),ib_wqueue_timedwait(ut0wqueue.cc:160),fts_optimize_thread(fts0opt.cc:2902),start_thread(libpthread.so.0),clone(libc.so.6)
      1 pthread_cond_timedwait,os_event::timed_wait(os0event.cc:308),os_event::wait_time_low(os0event.cc:480),dict_stats_thread(dict0stats_bg.cc:427),start_thread(libpthread.so.0),clone(libc.so.6)
      1 poll(libc.so.6),vio_io_wait(viosocket.c:786),vio_socket_io_wait(viosocket.c:77),vio_read(viosocket.c:132),net_read_raw_loop(net_serv.cc:672),net_read_packet_header(net_serv.cc:756),net_read_packet(net_serv.cc:756),my_net_read(net_serv.cc:899),Protocol_classic::read_packet(protocol_classic.cc:808),Protocol_classic::get_command(protocol_classic.cc:965),do_command(sql_parse.cc:964),handle_connection(connection_handler_per_thread.cc:306),pfs_spawn_thread(pfs.cc:2190),start_thread(libpthread.so.0),clone(libc.so.6)
      1 poll(libc.so.6),Mysqld_socket_listener::listen_for_connection_event(socket_connection.cc:852),connection_event_loop(connection_acceptor.h:66),mysqld_main(connection_acceptor.h:66),__libc_start_main(libc.so.6),_start
      1 nanosleep(libpthread.so.0),os_thread_sleep(os0thread.cc:279),srv_master_sleep(srv0srv.cc:2329),srv_master_thread(srv0srv.cc:2329),start_thread(libpthread.so.0),clone(libc.so.6)
      1 lf_hash_search(libc.so.6),find(mdl.cc:1223),find_or_insert(mdl.cc:1223),MDL_context::try_acquire_lock_impl(mdl.cc:1223),MDL_context::acquire_lock(mdl.cc:3590),open_table_get_mdl_lock(sql_base.cc:2911),open_table(sql_base.cc:2911),open_and_process_table(sql_base.cc:5174),open_tables(sql_base.cc:5174),open_tables_for_query(sql_base.cc:6560),execute_sqlcom_select(sql_parse.cc:5115),mysql_execute_command(sql_parse.cc:2816),mysql_parse(sql_parse.cc:5570),dispatch_command(sql_parse.cc:1484),do_command(sql_parse.cc:1025),handle_connection(connection_handler_per_thread.cc:306),pfs_spawn_thread(pfs.cc:2190),start_thread(libpthread.so.0),clone(libc.so.6)
[5 Oct 2019 0:43] Rex Hatt
In a recent system where I saw this behavior it was PHPMyAdmin version 4.8.5.  The query that got stuck was the following (pulled with mysqladmin proc status)

| 38 | root | localhost | dumptest | Query   | 110  | Opening tables | SHOW SESSION VARIABLES LIKE 'FOREIGN_KEY_CHECKS' |

That output shows the query running for 110 seconds, although it will go indefinitely as it never completes.  A dump from the command line worked properly and in less than a second.

The interesting thing worth noting here is that the dump did actually complete if you manually check the table structure, but MySQL and PHPMyAdmin were locked out, which makes it not useful.

To fix the issue on my test machines where this was happening I needed to manually kill the PHPMyAdmin process, and then restart MySQL.

That was tested in MySQL 5.7.27, although the dump file came from a system running MySQL 8.
[31 Oct 2019 19:28] Paul DuBois
Posted by developer:
 
Fixed in 5.7.29, 8.0.19.

With a LOCK TABLES statement in effect, a metadata change for the
locked table could cause Performance Schema or SHOW queries for
session variables to hang in the opening_tables state.
[31 Oct 2019 19:56] Arek M
Paul, which commit exactly fixes these?
[5 Nov 2019 2:27] Nisha Padmini Gopalakrishnan
Posted by developer:
 
Hello,

Both commit ids need to be applied, the second commit
id was to fix a test case issue.

Pushed into repo mysql branch mysql-5.7 5.7.29
(hash:df622a4e0fd5b919f26ff217047ced988a90e1b4
committer:nisha.gopalakrishnan@oracle.com)
(merge vers:5.7.29)

Pushed into repo mysql branch mysql-5.7 5.7.29
(hash:dc4c221afca22196967252f324431626dafbec06
committer:nisha.gopalakrishnan@oracle.com)
(merge vers:5.7.29) 

Thanks,
Nisha
[5 Nov 2019 8:00] Arek M
Are these in some public repository already? So we could test.
[11 Nov 2019 2:33] Nisha Padmini Gopalakrishnan
Posted by developer:
 
The version 5.7.29 is not available since it has not been released yet.
https://dev.mysql.com/doc/relnotes/mysql/5.7/en/news-5-7-29.html
[13 Jan 2020 13:41] Arek M
I don't see these commits in github repository:

$ git remote -v
origin  https://github.com/mysql/mysql-server.git (fetch)
origin  https://github.com/mysql/mysql-server.git (push)
$ git show df622a4e0fd5b919f26ff217047ced988a90e1b4
fatal: bad object df622a4e0fd5b919f26ff217047ced988a90e1b4
$ git show dc4c221afca22196967252f324431626dafbec06
fatal: bad object dc4c221afca22196967252f324431626dafbec06
[13 Jan 2020 18:30] Arek M
I guess it is:

commit 95e3a1a52dbe8fc21eb0410540853db531254a24
Author: Nisha Gopalakrishnan <nisha.gopalakrishnan@oracle.com>
Date:   Wed Oct 9 07:03:55 2019 +0530

    BUG#29836204: P_S TABLE ACCESS HANGS WHILE IN LOCK TABLES MODE

    Analysis
    ========

    Querying the performance_schema tables like "session variables"
    under LOCK TABLE MODE while there is a meta data change for the
    table locked caused the performance_schema query to hang in
    "opening_tables" state.

    While opening the performance_schema internal temporary table
    in "open_table", the table share version was compared with the
    share version of the opened tables(i.e in this case the table
    which was altered using ALTER TABLE under lock table mode)/
    Since the share version was different, the retry logic for
    opening tables was triggered. This continued in a loop since
    the table share version was always different.

    Fix
    ===
    While opening performance_schema tables, the flag
    'MYSQL_OPEN_IGNORE_FLUSH' is set since FLUSH TABLES/share
    version comparison does not apply for performance_schema tables.
    Querying the P_S tables should be allowed in lock table mode.

    Change-Id: I4ac73dbfb9e67076a6297fcaa184c3d2606ffd40