| Bug #15791 | can't get requested lock after starting alter table disable keys | ||
|---|---|---|---|
| Submitted: | 15 Dec 2005 21:26 | Modified: | 8 Mar 2006 7:56 |
| Reporter: | Bruce Bristol | Email Updates: | |
| Status: | No Feedback | Impact on me: | |
| Category: | MySQL Server | Severity: | S2 (Serious) |
| Version: | 4.1.12 | OS: | Linux (Linux) |
| Assigned to: | CPU Architecture: | Any | |
[15 Dec 2005 21:26]
Bruce Bristol
[16 Dec 2005 12:02]
Valeriy Kravchuk
Thank you for a problem report. Please, add some exact INSERT DELAYED statements you executed on those se_keyword_current table. Is this problem repeatable on a small amount of data?
[3 Jan 2006 19:37]
Bruce Bristol
Here it's happened again today. Included is a show processlist with the process in 'start' status and some sample DELAYED INSERTs. We can also send you a ps -aux, pstree and vmstat. This has been moved from non-critical to serious. We appreciate you prompt attention to this matter! Current: mysql> show processlist; +--------+---------+-----------------------------+-------+----------------+-------+--------------------------+------------------------------------------------------------------------------------------------------+ | Id | User | Host | db | Command | Time | State | Info | +--------+---------+-----------------------------+-------+----------------+-------+--------------------------+------------------------------------------------------------------------------------------------------+ | 150344 | dev | process7.rev.internal:39139 | stats | Query | 11549 | Waiting for tables | INSERT delayed INTO site_country_current (publisher_id,pplacement_id,product_id,site_id,day,country, | | 150349 | dev | process8.rev.internal:39077 | stats | Query | 7632 | waiting for handler open | INSERT delayed INTO site_country_current (publisher_id,pplacement_id,product_id,site_id,day,country, | | 150353 | dev | process5.rev.internal:46943 | stats | Query | 11444 | Waiting for table | INSERT delayed INTO site_country_current (publisher_id,pplacement_id,product_id,site_id,day,country, | | 150355 | dev | process3.rev.internal:57118 | stats | Query | 11444 | Locked | SELECT DISTINCT table_ext FROM site_country_dates WHERE table_ext != 'ARCHIVED' | | 150356 | dev | process4.rev.internal:57184 | stats | Query | 11030 | Waiting for table | INSERT delayed INTO site_country_current (publisher_id,pplacement_id,product_id,site_id,day,country, | | 150357 | dev | process3.rev.internal:57119 | stats | Query | 11444 | setup | alter table site_country_current disable keys | | 150642 | dev | process2.rev.internal:57155 | stats | Query | 10938 | Waiting for table | INSERT delayed INTO site_country_current (publisher_id,pplacement_id,product_id,site_id,day,country, | | 150643 | dev | process2.rev.internal:57156 | stats | Query | 11578 | Waiting for tables | INSERT delayed INTO site_country_current (publisher_id,pplacement_id,product_id,site_id,day,country, | | 150667 | DELAYED | | stats | Killed | 11578 | upgrading lock | | | 150941 | dev | process1.rev.internal:53068 | stats | Query | 10109 | Locked | show table status | | 151342 | DELAYED | | stats | Killed | 7649 | NULL | | | 151350 | DELAYED | | stats | Killed | 7644 | NULL | | | 151351 | DELAYED | | stats | Killed | 7635 | NULL | | | 151352 | DELAYED | | stats | Killed | 7634 | NULL | | | 151353 | DELAYED | | stats | Delayed insert | 7632 | Waiting for table | | | 151572 | flusher | hermit.internal:57475 | NULL | Query | 6629 | Waiting to get readlock | FLUSH TABLES WITH READ LOCK | | 151579 | dev | process1.rev.internal:53114 | stats | Query | 6509 | Locked | show table status | | 152276 | dev | process1.rev.internal:53160 | stats | Query | 2909 | Locked | show table status | | 152713 | root | localhost | meta | Query | 0 | NULL | show processlist | | 152714 | dev | web3.rev.internal:41683 | meta | Sleep | 0 | | NULL | +--------+---------+-----------------------------+-------+----------------+-------+--------------------------+------------------------------------------------------------------------------------------------------+
[4 Jan 2006 10:30]
Valeriy Kravchuk
As all your INSERT DELAYED statements are into the site_country_current table, please, send the results of SHOW CREATE TABLE site_country_current. Send also your my.cnf content (should ask about it initially). Is it possible for you to upgrade? Your 4.1.12 is a bit old and many bugs may be fixed already.
[10 Jan 2006 20:38]
Bruce Bristol
Okay, we've upgraded to MySQL 4.1.16. Here is the create statement: CREATE TABLE `site_country_current` ( `country` char(2) default NULL, `site_id` int(11) NOT NULL default '0', `publisher_id` int(11) NOT NULL default '0', `day` date default NULL, `pplacement_id` int(11) NOT NULL default '0', `product_id` int(11) NOT NULL default '0', `v` int(11) NOT NULL default '0', `c` int(11) NOT NULL default '0', `p` int(11) NOT NULL default '0', `p2` int(11) NOT NULL default '0', `p3` int(11) NOT NULL default '0', `commission` float(14,7) NOT NULL default '0.0000000', `revenue` float(14,7) NOT NULL default '0.0000000', KEY `country` (`country`), KEY `site_id` (`site_id`), KEY `pplacement_id` (`pplacement_id`), KEY `product_id` (`product_id`), KEY `publisher_id` (`publisher_id`,`pplacement_id`,`site_id`,`day`,`country`) ) ENGINE=MyISAM DEFAULT CHARSET=latin1 and this is the contents of our /etc/my.cnf file. db1:/home/bbristol>cat /etc/my.cnf [mysqld] datadir=/var/lib/mysql/data/ socket=/var/lib/mysql/mysql.sock key_buffer=1536M sort_buffer=16M record_buffer=4M read_buffer_size=4M # changed to 300 on 2005/12/15 as we maxed out at 200 - Bruce max_connections=300 #max_connections=200 query_cache_type=1 query_cache_size=256M thread_concurrency=4 thread_cache=32 tmp_table_size = 1024M delayed_queue_size=500000 delayed_insert_limit=20000 delayed_insert_timeout=900 read_rnd_buffer_size=6M net_buffer_length = 2M back_log=256 table_cache=1536 tmpdir=/var/lib/mysql/tmp # Default to using old password format for compatibility with mysql 3.x # clients (those using the mysqlclient10 compatibility package). #old_passwords=1 log-error=/var/lib/mysql/log-error log-slow-queries = /var/lib/mysql/slow-queries #[mysql.server] #user=mysql #basedir=/var/lib #[mysqld_safe] #err-log=/var/log/mysqld.log #pid-file=/var/run/mysqld/mysqld.pid ####################### ### REPLICATION CONFIG ####################### server-id=40 log-bin = /var/lib/mysql/mysql-bin.log binlog-do-db=meta binlog-ignore-db=stats binlog-ignore-db=scanner #master-host=db1.rev.internal #master-user=dbXX #master-password=slave_id_41 #master-port=3306 #replicate-ignore-db=mysql #log-slave-updates ##skip-slave-start
[12 Jan 2006 17:22]
Valeriy Kravchuk
Sorry, but I was not able to repeat the problem with the following simple sequence of actions with 4.1.17 on Linux:
mysql> CREATE TABLE `site_country_current` (
-> `country` char(2) default NULL,
-> `site_id` int(11) NOT NULL default '0',
-> `publisher_id` int(11) NOT NULL default '0',
-> `day` date default NULL,
-> `pplacement_id` int(11) NOT NULL default '0',
-> `product_id` int(11) NOT NULL default '0',
-> `v` int(11) NOT NULL default '0',
-> `c` int(11) NOT NULL default '0',
-> `p` int(11) NOT NULL default '0',
-> `p2` int(11) NOT NULL default '0',
-> `p3` int(11) NOT NULL default '0',
-> `commission` float(14,7) NOT NULL default '0.0000000',
-> `revenue` float(14,7) NOT NULL default '0.0000000',
-> KEY `country` (`country`),
-> KEY `site_id` (`site_id`),
-> KEY `pplacement_id` (`pplacement_id`),
-> KEY `product_id` (`product_id`),
-> KEY `publisher_id` (`publisher_id`,`pplacement_id`,`site_id`,`day`,`country`)
-> ) ENGINE=MyISAM DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.04 sec)
mysql> alter table `site_country_current` disable keys;
Query OK, 0 rows affected (0.00 sec)
mysql> INSERT delayed INTO site_country_current
-> (publisher_id,pplacement_id,product_id,site_id,day,country)
-> VALUES (1,1,1,1,'2006/01/01','UA');
Query OK, 1 row affected (0.00 sec)
mysql> INSERT delayed INTO site_country_current
-> (publisher_id,pplacement_id,product_id,site_id,day,country)
-> VALUES (1,1,1,2,'2006/01/02','UA');
Query OK, 1 row affected (0.00 sec)
mysql> INSERT delayed INTO site_country_current
-> (publisher_id,pplacement_id,product_id,site_id,day,country)
-> VALUES (1,1,1,3,'2006/01/03','UA');
Query OK, 1 row affected (0.00 sec)
mysql> INSERT delayed INTO site_country_current
-> (publisher_id,pplacement_id,product_id,site_id,day,country)
-> VALUES (1,1,1,4,'2006/01/04','UA');
Query OK, 1 row affected (0.01 sec)
mysql> INSERT delayed INTO site_country_current
-> (publisher_id,pplacement_id,product_id,site_id,day,country)
-> VALUES (1,1,1,2,'2006/01/02','RU');
Query OK, 1 row affected (0.00 sec)
mysql> show processlist;
+----+---------+-----------+------+----------------+------+--------------------+
------------------+
| Id | User | Host | db | Command | Time | State |
Info |
+----+---------+-----------+------+----------------+------+--------------------+
------------------+
| 1 | root | localhost | test | Query | 0 | NULL |
show processlist |
| 2 | DELAYED | | test | Delayed insert | 9 | Waiting for INSERT |
|
+----+---------+-----------+------+----------------+------+--------------------+
------------------+
2 rows in set (0.00 sec)
mysql> show processlist;
+----+---------+-----------+------+----------------+------+--------------------+
------------------+
| Id | User | Host | db | Command | Time | State |
Info |
+----+---------+-----------+------+----------------+------+--------------------+
------------------+
| 1 | root | localhost | test | Query | 0 | NULL |
show processlist |
| 2 | DELAYED | | test | Delayed insert | 12 | Waiting for INSERT |
|
+----+---------+-----------+------+----------------+------+--------------------+
------------------+
2 rows in set (0.00 sec)
mysql> show processlist;
+----+---------+-----------+------+----------------+------+--------------------+
------------------+
| Id | User | Host | db | Command | Time | State |
Info |
+----+---------+-----------+------+----------------+------+--------------------+
------------------+
| 1 | root | localhost | test | Query | 0 | NULL |
show processlist |
| 2 | DELAYED | | test | Delayed insert | 46 | Waiting for INSERT |
|
+----+---------+-----------+------+----------------+------+--------------------+
------------------+
2 rows in set (0.00 sec)
...
Then I enabled key back, as you described initially:
mysql> alter table `site_country_current` enable keys;
Query OK, 0 rows affected (0.02 sec)
mysql> show processlist;
+----+------+-----------+------+---------+------+-------+------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------+------+---------+------+-------+------------------+
| 1 | root | localhost | test | Query | 0 | NULL | show processlist |
+----+------+-----------+------+---------+------+-------+------------------+
1 row in set (0.00 sec)
mysql> select count(*) from `site_country_current`;
+----------+
| count(*) |
+----------+
| 5 |
+----------+
1 row in set (0.06 sec)
mysql> exit
Bye
[openxs@Fedora 4.1]$ tail var/Fedora.err
060112 15:39:05 InnoDB: Starting shutdown...
060112 15:39:07 InnoDB: Shutdown completed; log sequence number 0 18165469
060112 15:39:07 [Note] /home/openxs/dbs/4.1/libexec/mysqld: Shutdown complete
060112 15:39:07 mysqld ended
060112 19:10:48 mysqld started
060112 19:10:50 InnoDB: Started; log sequence number 0 18165469
/home/openxs/dbs/4.1/libexec/mysqld: ready for connections.
Version: '4.1.17' socket: '/tmp/mysql.sock' port: 3306 Source distribution
So, it works, and there is nothing similar to your error log entries. I understand that I may have to use several concurrent sessions to repeat, but, please, check, is this test case similar to your real situation. Any further ideas on how to repeat are also welcomed.
[7 Feb 2006 21:29]
Bruce Bristol
We've upgraded to 4.1.16, but the problem still exists.
[8 Feb 2006 7:56]
Valeriy Kravchuk
Please, try to repeat with 4.1.18 released today and inform about the results. My test was performed on 4.1.17-BK (our internal version), that was newer than 4.1.16.
[9 Mar 2006 0:00]
Bugs System
No feedback was provided for this bug for over a month, so it is being suspended automatically. If you are able to provide the information that was originally requested, please do so and change the status of the bug back to "Open".
