enterprise-support team mailing list archive

[Sveta Smirnova <sveta@xxxxxxxxxxxxx>]

Public bug reported:

Description:
mysqld opens too many descriptors for slow query log if I turn it ON and OFF while concurrent environment is running.

Behavior is not repeatable with version 5.6

How to repeat:
1. Start MTR:

./mtr --start innodb &

2. CREATE DATABASE sbtest;
3. sysbench --test=/home/sveta/src/sysbench/sysbench/tests/db/oltp.lua --mysql-engine-trx=yes --mysql-table-engine=innodb --oltp_table_size=1000 --oltp_tables_count=1 --mysql-user=root --mysql-host=127.0.0.1 --mysql-port=13000 --num-threads=8 prepare
 (Replace path to oltp.lua to correct on your machine)
4. mysql> set global log_output='file';
Query OK, 0 rows affected (0,00 sec)

mysql> set global slow_query_log=0;
Query OK, 0 rows affected (0,00 sec)

mysql> set global long_query_time=0;
Query OK, 0 rows affected (0,00 sec)

mysql> set global slow_query_log=1;
Query OK, 0 rows affected (0,01 sec)

5. Check what you have only 3 descriptors so far:

sveta@Thinkie:~/Lessons/R/stepic-base$ lsof -p 18972 | grep slow
mysqld  18972 sveta   15u   REG               0,43        35 35139893 /home/sveta/build/mysql-5.7/mysql-test/var/mysqld.1/data/mysql/slow_log.CSM
mysqld  18972 sveta   50r   REG               0,43         0 35139868 /home/sveta/build/mysql-5.7/mysql-test/var/mysqld.1/data/mysql/slow_log.CSV
mysqld  18972 sveta   51w   REG               0,43   2240609 35139921 /home/sveta/build/mysql-5.7/mysql-test/var/mysqld.1/mysqld-slow.log

6. Run concurrent environment:

sysbench --test=/home/sveta/src/sysbench/sysbench/tests/db/oltp.lua
--mysql-engine-trx=yes --mysql-table-engine=innodb
--oltp_table_size=1000 --oltp_tables_count=1 --mysql-user=root --mysql-
host=127.0.0.1 --mysql-port=13000 --num-threads=8 --max-requests=1000
run

7. Turn OFF and ON slow log:

mysql> set global slow_query_log=0;
Query OK, 0 rows affected (0,09 sec)

mysql> set global slow_query_log=1;
Query OK, 0 rows affected (0,00 sec)

8. Now you have 4 descriptors:

sveta@Thinkie:~/Lessons/R/stepic-base$ lsof -p 18972 | grep slow
mysqld  18972 sveta   15u   REG               0,43        35 35139893 /home/sveta/build/mysql-5.7/mysql-test/var/mysqld.1/data/mysql/slow_log.CSM
mysqld  18972 sveta   50r   REG               0,43         0 35139868 /home/sveta/build/mysql-5.7/mysql-test/var/mysqld.1/data/mysql/slow_log.CSV
mysqld  18972 sveta   51r   REG               0,43         0 35139868 /home/sveta/build/mysql-5.7/mysql-test/var/mysqld.1/data/mysql/slow_log.CSV
mysqld  18972 sveta   52w   REG               0,43  14143997 35139921 /home/sveta/build/mysql-5.7/mysql-test/var/mysqld.1/mysqld-slow.log

9. Repeat steps 6-8 until you get "Too many files" error

My customer observed same behavior, but duplicate entry created for
mysqld-slow.log, not for slow_log.CSV

Workaround: Stop slow query log, then, if you see many open slow_log.CSV
run FLUSH TABLES, and if many mysqld-slow.log run FLUSH SLOW LOGS

Suggested fix:
Do not keep so many file descriptors open.

** Affects: mysql-server
     Importance: Unknown
         Status: Unknown

** Affects: percona-server
     Importance: Undecided
         Status: Confirmed

** Affects: percona-server/5.7
     Importance: Undecided
         Status: Confirmed


** Tags: i135699

** Also affects: percona-server/5.7
   Importance: Undecided
       Status: Confirmed

** Bug watch added: MySQL Bug System #82870
   http://bugs.mysql.com/bug.php?id=82870

** Also affects: mysql-server via
   http://bugs.mysql.com/bug.php?id=82870
   Importance: Unknown
       Status: Unknown

-- 
You received this bug notification because you are a member of Ubuntu
Server/Client Support Team, which is subscribed to MySQL.
Matching subscriptions: Ubuntu Server/Client Support Team
https://bugs.launchpad.net/bugs/1620752

Title:
  mysqld opens too many descriptors for slow query log

To manage notifications about this bug go to:
https://bugs.launchpad.net/mysql-server/+bug/1620752/+subscriptions