Description:
Hi,
I just installed MySQL 5.0.45-log Source distribution on my Debian 6.0.6 server.
I installed it under my user home directory like I'm used to doing.
But this time the queries are extremely slow to run.
Running a create table or a database drop takes ages. I can literally watch tv in the meantime.
So I did a profiling of the database drop statement.
mysql> SHOW PROFILES;
+----------+--------------+------------------------------+
| Query_ID | Duration | Query |
+----------+--------------+------------------------------+
| 1 | 369.54719400 | drop database db_madeintouch |
| 2 | 0.00004600 | SELECT DATABASE() |
+----------+--------------+------------------------------+
2 rows in set (0.00 sec)
mysql> SHOW PROFILE FOR QUERY 1;
+----------------------+-----------+
| Status | Duration |
+----------------------+-----------+
| (initialization) | 0.000001 |
| checking permissions | 369.54705 |
| Opening table | 0.000103 |
| System lock | 0.000003 |
| Table lock | 0.000018 |
| query end | 0.000004 |
| freeing items | 0.000004 |
| logging slow query | 0.000002 |
+----------------------+-----------+
8 rows in set (0.00 sec)
We can see the time it takes for the checking of permissions is of 369 seconds.
I also did a show status of the InnoDB engine.
mysql> show engine innodb status\G
*************************** 1. row ***************************
Status:
=====================================
130415 23:11:27 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 9 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 781, signal count 781
Mutex spin waits 0, rounds 8629, OS waits 231
RW-shared spins 379, OS waits 190; RW-excl spins 380, OS waits 342
------------
TRANSACTIONS
------------
Trx id counter 0 7599
Purge done for trx's n:o < 0 7430 undo n:o < 0 0
History list length 3
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 14133, OS thread id 140617364518656
MySQL thread id 16, query id 1305 localhost stephane checking permissions
drop database db_madeintouch
---TRANSACTION 0 0, not started, process no 14133, OS thread id 140617364383488
MySQL thread id 13, query id 1307 localhost stephane
show engine innodb status
---TRANSACTION 0 7597, COMMITTED IN MEMORY, process no 14133, OS thread id 140617364518656 dropping table
COMMITTING , undo log entries 16
MySQL thread id 16, query id 1305 localhost stephane checking permissions
drop database db_madeintouch
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 1; buffer pool: 0
174 OS file reads, 3781 OS file writes, 2099 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2,
0 inserts, 0 merged recs, 0 merges
Hash table size 17393, used cells 122, node heap has 1 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 0 7801057
Log flushed up to 0 7798962
Last checkpoint at 0 7798962
1 pending log writes, 0 pending chkp writes
1535 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 22136914; in additional pool allocated 1048576
Buffer pool size 512
Free buffers 2
Database pages 509
Modified db pages 18
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 183, created 1444, written 6980
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread process no. 14133, id 140617334142720, state: waiting for server activity
Number of rows inserted 0, updated 0, deleted 0, read 0
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
1 row in set (0.00 sec)
The same issue occurs when creating a new table.
And I think it also occurs when doing insert statements.
And of course, the top command displays a mem and cpu idling at 0.1%.
I also compiled and installed the latest release of MySQL mysql-5.6.10 and the show stops at a slightly similar issue. This time the checking permissions is reasonable with a 0.000458 but it is the System lock that goes as high as 588.564794
How to repeat:
Compile this MySQL release in your user home directory following these instructions:
Download the mysql source mysql-5.0.45.tar.gz
Remove the package mysql-common if any
apt-get remove mysql-common
Unpack and create a soft link
ln -s mysql-5.0.45 mysql
Go to the mysql directory
cd mysql
Create some directories
mkdir /home/stephane/programs/mysql/install;
mkdir /home/stephane/programs/mysql/install/data;
mkdir /home/stephane/programs/mysql/install/var;
mkdir /home/stephane/programs/mysql/install/etc;
mkdir /home/stephane/programs/mysql/install/tmp
./configure \
--with-plugins=innobase,innodb_plugin \
--prefix=/home/stephane/programs/mysql/install \
--localstatedir=/home/stephane/programs/mysql/install/data
make
make install
Do the post installation
chmod 755 scripts/mysql_install_db;
scripts/mysql_install_db \
--basedir=/home/stephane/programs/mysql/install/ \
--datadir=/home/stephane/programs/mysql/install/data \
--tmpdir=/home/stephane/programs/mysql/install/tmp
And set up some configuration in the config file
/home/stephane/programs/mysql/install/etc/my.cnf
[mysqld]
socket = /home/stephane/programs/mysql/install/tmp/mysql.sock
innodb_file_per_table
user = stephane
basedir = /home/stephane/programs/mysql/install
datadir = /home/stephane/programs/mysql/install/data
log-bin = /home/stephane/programs/mysql/install/mysql.bin.log
log (or general-log-file) = /home/stephane/programs/mysql/install/mysql.log
log-error = /home/stephane/programs/mysql/install/mysql.error.log
log-slow-queries (or slow-query-log-file) = /home/stephane/programs/mysql/install/mysql.slow.queries.log
[client]
socket = /home/stephane/programs/mysql/install/tmp/mysql.sock
Secure the server
Run the following statements:
show databases;
drop database test;
use mysql;
select * from db where Db like 'test%';
delete from db where Db like 'test%';
show grants for '@localhost';
revoke all on *.* from ''@'localhost';
select * from user where User = '';
delete from user where User = '';
flush privileges;
quit;
