MySQL Bugs: #66237: Temporary files created by binary log cache are not purged after transaction com

Bug #66237	Temporary files created by binary log cache are not purged after transaction com
Submitted:	7 Aug 2012 6:58	Modified:	19 Sep 2013 6:35
Reporter:	Miguel Angel Nieto	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Row Based Replication ( RBR )	Severity:	S3 (Non-critical)
Version:	5.0, 5.1, 5.5	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	binary log

Description:
When you modify lot of data inside a transaction, for example a big LOAD DATA INFILE, and the size overcomes the binary log cache it will create temporary files in the tmp partition. Those files don't disappear until you close the connection. Therefore, if you are running some kind of persistent connection technique you can run out of disk space on /tmp partition.

Those files are always in "deleted" status, so they're not visible with a simple "ls" on the partition:

# lsof -p 6112|grep ML
mysqld  6112 root   38u   REG                7,0  106594304      18 /tmp/MLjw4ecJ (deleted)
mysqld  6112 root   39u   REG                7,0  237314310      17 /tmp/MLwdWDGW (deleted)
mysqld  6112 root   41u   REG                7,0  107872256      19 /tmp/MLOqxGox (deleted)
mysqld  6112 root   44u   REG                7,0   90832896      20 /tmp/MLr05Ga9 (deleted)
mysqld  6112 root   47u   REG                7,0   79855616      21 /tmp/ML83dV2t (deleted)
mysqld  6112 root   50u   REG                7,0   65077248      22 /tmp/ML5M7KqM (deleted)
mysqld  6112 root   53u   REG                7,0   64094208      23 /tmp/MLSfMSMh (deleted)
mysqld  6112 root   56u   REG                7,0   62259200      24 /tmp/MLnAcfOY (deleted)
mysqld  6112 root   59u   REG                7,0   62521344      25 /tmp/ML4VPBxK (deleted)
mysqld  6112 root   62u   REG                7,0   62390272      26 /tmp/ML19sFCA (deleted)

How to repeat:
1- Master-Slave replication with row based binary log.
2- Create a /tmp partition, for example on tmpfs.
3- Run several LOAD DATA INFILE with persistent connection (or just don't close the session).
4- Check the size of the temporary files with lsof.
5- Finally, you'll fill up the tmp partition.

Suggested fix:
1- Make those files visible, why are they in deleted status?
2- Remove those files just after the commit.

They are deleted so that they will be cleaned up automatically when mysqld exits for any reason, whether it's a normal exit or a crash.

Thank you for the report.

Can you repeat situation when temporary file space is filled up? I can not repeat situation when number of "(deleted)" files is enormous: it is always limited by some number in my environment.

Hi Sveta,

Follow this procedure:

my.cnf:

...
tmpdir                          = /tmp
log-bin
binlog_format=row
...

# dd if=/dev/zero of=tmpfile bs=1 count=0 seek=2G
# mkfs.ext3 tmpfile
# mount -o loop tmpfile /tmp/
…
/dev/loop0 on /tmp type ext3 (rw)
# df -h
…
/dev/loop0           1008M   66M  891M   7% /tmp

mysql> create table t(i int, c char(20), c2 char(20));
mysql> insert into t values (1,'miguel','angel');
mysql> insert into t select * from t;
…
mysql> insert into t select * from t;
Query OK, 16777216 rows affected (4 min 18.92 sec)
mysql> select * from t into outfile '/root/dump';
Query OK, 33554432 rows affected (1 min 13.04 sec)

Then, open new sessions and start importing the file:

session1 > load data infile '/root/dump' into table t;
Query OK, 33554432 rows affected (5 min 42.25 sec)
session2 > load data infile '/root/dump' into table t;
...
after some time...

/dev/loop0           1008M 1008M     0 100% /tmp

mysqld  4875 root   35u   REG                7,0  621356245     18 /tmp/MLnbcEOC (deleted)
mysqld  4875 root   37u   REG                7,0  399581184  24577 /tmp/MLq5uYCe (deleted)

Therefore, after a transaction commit, the ML files don't disappear and you can run out of disk space on tmp partition. This can be a huge problem if you're using persistent connections or connection pooling. After closing the sessions ML files disappeared.

Binlog cache files should be deleted once the transaction is either committed or rolled back. If this behavior is real (which I did not test) then it is a serious bug.

I have verified this behavior on 5.5.27 after it filled up the tmpdir partition for a customer. I had to kill off the sleeping connections to clear out the disk space

Thank you for the feedback.

Verified as described with slight modification to test:

you should either have option autocommit=0 set or run BEGIN prior series of LOAD DATA queries. After ROLLBACK temporary space was not cleaned. One have to exit client. If option autocommit=1 this behavior can not be observed.

Fixed in 5.7. Documented int he 5.7.2 changelog as follows:

        Modifying large amounts of data within a transaction the size
        can cause the creation of temporary files. Such files are
        created when the size of the data modified exceeds the size of
        the binary log cache (max_binlog_cache_size). Previously, such
        files persisted until the client connection was closed, which
        could potentially fill all available disk space in tmpdir. To
        keep this from occurring, the size of a temporary file created
        in this way in a given transaction is reset to 0 when the
        transaction is committed or rolled back.

Closed.

Also fixed in 5.6.17.

5.6$ bzr log -r 5763
------------------------------------------------------------
revno: 5763
committer: Sujatha Sivakumar <sujatha.sivakumar@oracle.com>
branch nick: Bug18021493_mysql-5.6
timestamp: Wed 2014-01-22 11:08:12 +0530
message:
  Bug#18021493: PLEASE BACKPORT FIX FOR 15909788 TO 5.6
  
  Description:
  ------------
  Please backport this bugfix to 5.6.  Running out of tmpdir space can cripple
  a server.
  
  Bug 15909788 - TEMPORARY FILES CREATED BY BINARY LOG CACHE ARE NOT PURGED
  AFTER TRANSACTION COM.

Is this fixed anywhere in 5.5? 
I cannot see any reference in any of the changelogs past 5.5.32 which is the version we are running and it seems we've hit this too.