Hey list, 

I've got another peculiar thing going on :-) Let me give you a quick summary of 
the situation first: we host a number of Drupal sites, each site and it's db on 
separate VMs for reasons that are not important to this scenario. MySQL is 
5.0.51a-24+lenny4-log (Debian); I don't have the exact Drupal version here but 
it's likely to be a 5.x branch. 

The easy thing to say would of course be "upgrade your versions", but that's 
not an option right now. I don't really care if that means I have no actual 
*fix* for the problem - I know how to work around it. I'm just looking for a 
cause, ideally maybe even a specific known bug. Strangely enough, I'm seeing 
this on three distinct installs; but others with the same versions and setup 
(but different sites) seem to not exhibit the issue. 

So, what I'm seeing is this: Drupal's "variable" table keeps growing, but there 
does not seem to be more data. I understand how record allocation and free 
space in datafiles works, but this is well beyond the normal behaviour. 


http://www.tuxera.be/filestore/heciexohhohj/df-year.png

As you can see here (the lime green line of /data), growth occurs gradually 
(and the issue happened in september, as well), until it seems to reach a 
certain point. At some point, however, performance on that table (notably 
select * - it's a drupal thing) pretty much instantly plummets, and the query 
takes around half a minute to run - whereas now, after reclaiming the free 
space, it takes 0.03 seconds. 

I don't have the exact numbers as I wasn't on-site yesterday evening, but since 
the disk is 5GB, the reclaimed space yesterday must have been around 850MB - 
for a table that is now 30MB. No records were deleted from the table, the 
workaround is as simple as "OPTIMIZE TABLE variable" - simply rebuild the 
table. The logs make no mention of a crashed table, so it's very unlikely that 
this is a borked index. Even if it were, I wouldn't expect a scan of 30MB in 
1202 rows to take half a minute, on a table that is accessed so often that it's 
relevant blocks are bound to be in the filesystem cache. 

The table's structure is fairly simple, too: 



CREATE TABLE `variable` ( 
`name` varchar(128) NOT NULL DEFAULT '', 
`value` longtext NOT NULL, 
PRIMARY KEY (`name`) 
) ENGINE=MyISAM DEFAULT CHARSET=utf8 




I currently have another system that's also growing that table, here's a bit of 
session: 


<blockquote>
mysql> show table status like 'variable'; 
+----------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-----------------+----------+----------------+---------+
 
| Name | Engine | Version | Row_format | Rows | Avg_row_length | Data_length | 
Max_data_length | Index_length | Data_free | Auto_increment | Create_time | 
Update_time | Check_time | Collation | Checksum | Create_options | Comment | 
+----------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-----------------+----------+----------------+---------+
 
| variable | MyISAM | 10 | Dynamic | 1188 | 795 | 493277732 | 281474976710655 | 
41984 | 492332716 | NULL | 2011-12-13 16:18:53 | 2013-02-15 12:35:18 | 
2012-10-17 15:45:11 | utf8_general_ci | NULL | | | 
+----------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-----------------+----------+----------------+---------+
 

12:36:55|root@xendbprod1-1:/data/mysql 0 # mysqlcheck --verbose DBNAME variable 
# Connecting to localhost... 
DBBAME.variable OK 
# Disconnecting from localhost... 

12:37:07|root@xendbprod1-1:/data/mysql 0 # mysqlcheck --verbose -g DBNAME 
variable 
# Connecting to localhost... 
DBNAME.variable OK 
# Disconnecting from localhost... 

mysql> show table status where name like "variable"; 
+----------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-----------------+----------+----------------+---------+
 
| Name | Engine | Version | Row_format | Rows | Avg_row_length | Data_length | 
Max_data_length | Index_length | Data_free | Auto_increment | Create_time | 
Update_time | Check_time | Collation | Checksum | Create_options | Comment | 
+----------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-----------------+----------+----------------+---------+
 
| variable | MyISAM | 10 | Dynamic | 1188 | 497 | 493277732 | 281474976710655 | 
41984 | 492686616 | NULL | 2011-12-13 16:18:53 | 2013-02-15 12:37:35 | 
2013-02-15 12:37:07 | utf8_general_ci | NULL | | | 
+----------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-----------------+----------+----------------+---------+
 
1 row in set (0.00 sec) 

mysql> optimize table variable; 
+-----------------+----------+----------+----------+ 
| Table | Op | Msg_type | Msg_text | 
+-----------------+----------+----------+----------+ 
| DBNAME.variable | optimize | status | OK | 
+-----------------+----------+----------+----------+ 
1 row in set (2.37 sec) 

mysql> show table status where name like "variable"; 
+----------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-----------------+----------+----------------+---------+
 
| Name | Engine | Version | Row_format | Rows | Avg_row_length | Data_length | 
Max_data_length | Index_length | Data_free | Auto_increment | Create_time | 
Update_time | Check_time | Collation | Checksum | Create_options | Comment | 
+----------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-----------------+----------+----------------+---------+
 
| variable | MyISAM | 10 | Dynamic | 1188 | 497 | 590940 | 281474976710655 | 
39936 | 0 | NULL | 2011-12-13 16:18:53 | 2013-02-15 12:39:30 | 2013-02-15 
12:39:30 | utf8_general_ci | NULL | | | 
+----------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-----------------+----------+----------------+---------+
 
1 row in set (0.00 sec) 

</blockquote>


As you can see, the table is almost 500MB. Running mysqlcheck shows that it is 
fine and not in need of a format upgrade. Optimizing the table, however, 
results in it being reduced to half an MB... At any point in this cycle, 
however, no excessive amount of data is inserted in the table. Insert, updates 
and deletes are fairly common, but not to the point where there would have been 
a couple of hundred MB of data in the file. Had I left this one for some more 
time, I'm sure that it would eventually also have reached the tipping point 
where the side suddenly becomes unusably slow. 

The performance degradation isn't perfectly traceable to a single point in 
time; the slowlog does show that query being slow on occasion; however it seems 
that it is intermittent until it reaches a point of no return, when the queries 
get slow enough that a cascade of pending connections happens until we run out 
of free handles and the site just stops responding. 


Now, in my understanding, the size of the file, while unusual, really shouldn't 
have much bearing on the execution time of a full table scan, should it? I 
mean, even a full tablescan is simply going to scan the row index and only read 
the blocks that are actually in use? Hell, even IF every single row would 
somehow have ended up in a different block (which the allocation alghorithm 
should have prevented), that's still only slightly over a thousand blocks, or 
half a meg. 

Thus, my question to the smart people on this list is threefold: 

1) Has anyone seen this behaviour before, and maybe know of a specific bug? 
2) What might cause the file to grow this large? 
3) How could the size of the file impact the speed of a full tablescan if only 
a few blocks in the file are actually in use? 

Am I missing something obvious, here? 

I have now updated those tables to InnoDB, time will tell if the issue 
reasserts itself. In the mean time, though I would very much like to understand 
what's going on. 


Thank you for your thoughts, 
/johan 


-- 

What's tiny and yellow and very, very dangerous? 
A canary with the root password. 

Reply via email to