Bug #92050 flush-logs command does not work and causes the process to hang

• Submitted: 17 Aug 2018 5:35
• Modified: 20 Aug 2018 15:29
• Reporter: Mikhail Grigoriev
• Status: Can't repeat
• Category: MySQL Server
• Severity: S3 (Non-critical)
• Version: 5.7.23
• OS: Ubuntu (16.04.5 LTS)
• CPU Architecture: x86 (4.4.0-122-generic)
• Tags: mysqadmin, MySQL

[17 Aug 2018 5:35] Mikhail Grigoriev

Description:
Hi, 

at night, a periodic task was started on the server to rotate the logs, and tonight running mysqladmin flush-logs caused the process of re-opening the logs to hang.

Until tonight, the rotation of the logs was normal, the problem occurred on an equal footing.

My OS:

# lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 16.04.5 LTS
Release:        16.04
Codename:       xenial

MySQL version:

[[e-mail]][(none)]> select version();                                                                                                                 +-----------------------------+
| version()                   |
+-----------------------------+
| 5.7.23-0ubuntu0.16.04.1-log |
+-----------------------------+
1 row in set (0,00 sec)

The logrotate settings:

# cat /etc/logrotate.d/mysql-server

/var/log/mysql/error.log /var/log/mysql/slow.log {
        daily
        rotate 7
        missingok
        create 644 mysql adm
        compress
        sharedscripts
        postrotate
                test -x /usr/bin/mysqladmin || exit 0
                MYADMIN="/usr/bin/mysqladmin --defaults-file=/etc/mysql/debian.cnf"
                if [ ! -z "`$MYADMIN ping 2>/dev/null`" ]; then
                  $MYADMIN flush-logs
                fi
        endscript
}

Rotation of logs has passed, but the FLUSH LOGS command has hung up, we observe the following situation:

[[e-mail]][(none)]> SELECT id,user,db,command,time,state,info FROM INFORMATION_SCHEMA.PROCESSLIST WHERE info LIKE '%flush%' and ID != CONNECTION_ID();
+-----------+------------------+------+---------+-------+----------+------------+
| id        | user             | db   | command | time  | state    | info       |
+-----------+------------------+------+---------+-------+----------+------------+
|  97164896 | debian-sys-maint | NULL | Killed  | 28768 | starting | FLUSH LOGS |
|  93517222 | debian-sys-maint | NULL | Killed  | 35968 | starting | FLUSH LOGS |
|  95297159 | debian-sys-maint | NULL | Killed  | 32368 | starting | FLUSH LOGS |
+-----------+------------------+------+---------+-------+----------+------------+
4 rows in set (0,00 sec)

These threads can not be killed by the kill command and they hang endlessly for more than 6 hours.

I tried to start mysqladmin flush-logs and it hung, the same process appeared:

[[e-mail]][(none)]> SELECT id,user,db,command,time,state,info FROM INFORMATION_SCHEMA.PROCESSLIST WHERE info like '%flush%' and ID != CONNECTION_ID();
+-----------+------------------+------+---------+-------+----------+------------+
| id        | user             | db   | command | time  | state    | info       |
+-----------+------------------+------+---------+-------+----------+------------+
|  97164896 | debian-sys-maint | NULL | Killed  | 29156 | starting | FLUSH LOGS |
|  93517222 | debian-sys-maint | NULL | Killed  | 36356 | starting | FLUSH LOGS |
|  95297159 | debian-sys-maint | NULL | Killed  | 32756 | starting | FLUSH LOGS |
| 108662422 | root             | NULL | Killed  |  1689 | starting | FLUSH LOGS |
+-----------+------------------+------+---------+-------+----------+------------+
4 rows in set (0,00 sec)

# ls -ld /var/log/mysql
drwxr-xr-x 2 mysql adm 4096 авг 17 02:17 /var/log/mysql

# ls -l /var/log/mysql
total 28
-rw-r--r-- 1 mysql adm     0 aug 17 02:17 error.log
-rw-r--r-- 1 mysql adm     0 aug 17 01:17 error.log.1
-rw-r--r-- 1 mysql adm   614 aug 15 23:52 error.log.4.gz
-rw-r--r-- 1 mysql adm 10318 aug 14 23:12 error.log.5.gz
-rw-r--r-- 1 mysql adm   722 aug 13 22:47 error.log.6.gz
-rw-r--r-- 1 mysql adm   413 aug 13 00:03 error.log.7.gz
-rw-r--r-- 1 mysql adm   543 aug 11 22:59 error.log.8.gz

How to repeat:
I do not know how to repeat such a problem.

I want to understand why it can not work out the flush-logs process and how to kill the hung threads without restarting mysqld.

[20 Aug 2018 15:29] MySQL Verification Team

HI,

Thank you for your report.

First of all, logrotate is not our program, but it is part of Ubuntu. Hence, we advise you to report this bug to them.

Next, our mysqladmin can flush logs, but it does not kill those processes. Hence, you have to find out what kills those processes.

Last, but not least, when KILL command is issued, a statement can not be killed immediately. It can not behave like Unix `kill` command, because Unix' `kill` kills the entire process which automatically frees all resources. MySQL's KILL statement just raises a flag that statement should be killed. Each statement has only 2 - 4 places where it checks that flag, because it has to free all resources and do garbage collection , which is doable in very few places in the code.