MySQL Bugs: #59032: InnoDB data files for the same data are much bigger than in previous versions

Bug #59032	InnoDB data files for the same data are much bigger than in previous versions
Submitted:	18 Dec 2010 20:34	Modified:	13 Jan 2011 19:56
Reporter:	Elena Stepanova	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S2 (Serious)
Version:	5.6.1-m5	OS:	Any
Assigned to:	Sunny Bains	CPU Architecture:	Any
Tags:	regression

Description:
For the same data flow, InnoDB data files started growing much bigger than in previous versions. Below are results for three consequent runs of the test case from 'How to repeat' section on each of 5.1/5.5/5.6:

version 5.1.54-enterprise-gpl-advanced-log
(with built-in InnoDB)
  1) InnoDB data file size: 69206016
  2) InnoDB data file size: 77594624
  3) InnoDB data file size: 77594624

version 5.1.54-enterprise-gpl-advanced-log
(with InnoDB plugin) 
innodb_version  1.0.14
  1) InnoDB data file size: 77594624
  2) InnoDB data file size: 94371840
  3) InnoDB data file size: 69206016

version 5.5.8-enterprise-commercial-advanced-log
innodb_version  1.1.4
  1) InnoDB data file size: 85983232
  2) InnoDB data file size: 94371840
  3) InnoDB data file size: 94371840

version 5.6.1-m5-log
innodb_version  1.2.0
  1) InnoDB data file size: 236978176
  2) InnoDB data file size: 236978176
  3) InnoDB data file size: 236978176

This is a severe problem for our stress tests, as even short 2-hour test runs with replication build up over 30 Gb of data, and eventually fail after exhausting the disk space.

How to repeat:
--source include/have_innodb.inc

--disable_warnings
DROP TABLE IF EXISTS test.viewer_tbl1, test_viewer_tbl2;
--enable_warnings

CREATE TABLE test.viewer_tbl1 
(a MEDIUMINT NOT NULL AUTO_INCREMENT, qty INT, 
price INT,PRIMARY KEY(a)) ENGINE=InnoDB;

CREATE TABLE test.viewer_tbl2 (a MEDIUMINT, qty INT, 
price INT, total INT, PRIMARY KEY(a)) ENGINE=InnoDB;

--delimiter |

CREATE PROCEDURE test.viewer_sp()
BEGIN
   DECLARE ins_count INT DEFAULT 100; 
   DELETE FROM test.viewer_tbl2;
   START TRANSACTION;
   WHILE ins_count > 0 DO
      INSERT INTO test.viewer_tbl1 VALUES (NULL,RAND() * 10, RAND() * 100);
      SET ins_count = ins_count - 1;
   END WHILE;
   INSERT INTO test.viewer_tbl2 SELECT a, qty, price, qty*price FROM test.viewer_tbl1; 
END|

--delimiter ;

SET AUTOCOMMIT=0;

let $run=200;
--disable_query_log
while ($run)
{
   CALL test.viewer_sp();
   COMMIT;
   dec $run;
}
--enable_query_log

SHOW VARIABLES LIKE '%version';

let DATADIR = `SELECT @@datadir`;
perl;
print "InnoDB data file size: ", ( -s "$ENV{DATADIR}/ibdata1" ), "\n";
EOF

DROP PROCEDURE test.viewer_sp;
DROP TABLE test.viewer_tbl1, test.viewer_tbl2;

--exit

If this is with innodb_file_per_table=0 and with an auto-extending system tablespace file, then this could be explained by the refactored purge running slower in 5.6, so slow that more garbage will be in the files.

Please check the Data_length and Data_free reported by SHOW TABLE STATUS for some table in this tablespace. If you let the purge thread run until completion (SHOW ENGINE INNODB STATUS says 'History list length 0'), then the Data_length should be constant and the differences in Data_free before and after the regression should explain the file size difference.

If this is the case, we might want to see how to reduce the purge lag. If the Data_length is bigger after purge has completed, then the refactored purge should be leaking (not freeing some delete-marked records and BLOBs that it should).

Hi Marko,

What would be your expectations on how long the completion might take?

In the same test scenario, I added a 10 min wait at the end before DROP TABLE (the test itself takes about 1 min). Both before and after the sleep, SHOW ENGINE INNODB STATUS shows the same History list length 396 or about it. SHOW TABLE STATUS also gives equal Data_length values. Should I try to wait longer?

Right after the test flow:

Trx id counter 820
Purge done for trx's n:o < 509 undo n:o < 27
History list length 396

Data_length     1589248
Data_free       0
Data_length     1589248
Data_free       0

After 10 min waiting:

Trx id counter 820
Purge done for trx's n:o < 509 undo n:o < 63
History list length 396

Data_length     1589248
Data_free       0

Data_length     1589248
Data_free       0

Elena, just in case what does SHOW ENGINE INNODB STATUS say
about ibuf?

Same before waiting and after waiting:

Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
 insert 0, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0

Pushed into mysql-trunk 5.6.2 (revid:vasil.dimov@oracle.com-20110108150732-8qygun7nuaqf9d3u) (version source revid:vasil.dimov@oracle.com-20110108150646-44c9j7ck64ocey31) (merge vers: 5.6.2) (pib:24)

This bug fix has been transferred into the 5.6.1-m5 release build.

Please reset the status to "Patch approved" after documenting it.

Do not understand why: 'reset the status to "Patch approved" after documenting it.'? This bug is in 5.6 only.

I had set it to "documenting" so that the fix might be mentioned in the 5,6,1 docs, if desired.
OTOH, it may well be that the problem never was present in any published version, which means no documentation is needed AIUI.

In any case, it was "patch approved" before my change, and not "patch queued" or even "documenting" - I can't tell why.
I realize the fix is in the main tree already, so "documenting" seems to be correct, and there is no need to set the status back.

Sorry, my fault.