Bug #35543 mysqlbinlog.cc does not properly work with tmp files
Submitted: 25 Mar 2008 9:40 Modified: 26 Aug 2008 21:41
Reporter: Alexander Nozdrin
Status: Closed
Category:Client Severity:S2 (Serious)
Version:6.0-BK OS:Any
Assigned to: Andrei Elkin Target Version:6.0-rc
Triage: D2 (Serious)

[25 Mar 2008 9:40] Alexander Nozdrin
Description:
There are a few complains in this bug:

  - mysqlbinlog.cc leaves temporary files on the disk after shutdown.
    That leads to the pollution of temporary directory.

  - Function create_unique_file(), that is used to create that temporary
    files, tries to create a tmp file 1000 times. If it fails, it supposes
    that something is seriously wrong and returns an error.

  - So, the combination of two first issues leads to the denial of service:
    tmp directory gets full and mysqlbinlog fails.

  - There is also a kind of memory leak on the error path from
    create_unique_file().

Another note: test cases should not pollute the global environment.

See also: Bug#34283.

How to repeat:
https://intranet.mysql.com/secure/pushbuild/xref.pl?testname=binlog.binlog_killed_simulate

binlog.binlog_killed_simulate  [ fail ]

Warning: Not freed memory segments: 2
Warning: Memory that was not free'ed (556 bytes):
	   104 bytes at 0x000558c48, allocated at line 1012 in 'log_event.cc'
	   452 bytes at 0x000530078, allocated at line  201 in 'my_alloc.c'
ERROR: Could not construct local filename /tmp/SQL_LOAD_MB.
Warning: Not freed memory segments: 3
Warning: Memory that was not free'ed (591 bytes):
	    35 bytes at 0x000558b88, allocated at line  424 in 'mysqlbinlog.cc'
	   104 bytes at 0x000558c48, allocated at line 1012 in 'log_event.cc'
	   452 bytes at 0x000530078, allocated at line  201 in 'my_alloc.c'
mysqltest: At line 54: command "$MYSQL_BINLOG --force-if-open --start-position=107
$MYSQLTEST_VARDIR/log/master-bin.000001 >
$MYSQLTEST_VARDIR/tmp/binlog_killed_bug27571.binlog" failed

The result from queries just before the failure was:
< snip >
reset master;
update t1 set a=2 /* will be "killed" after work has been done */;
select
(@a:=load_file("MYSQLTEST_VARDIR/tmp/binlog_killed_bug27571.binlog"))
is not null;
(@a:=load_file("MYSQLTEST_VARDIR/tmp/binlog_killed_bug27571.binlog"))
is not null
1
select 1 /* must return 1 as query completed before got killed*/;
1
1
create table t2 (a int, b int) ENGINE=MyISAM;
reset master;
load data infile '../std_data_ln/rpl_loaddata.dat' into table t2 /* will be "killed" in
the middle */;
ERROR 70100: Query execution was interrupted
show binlog events from <binlog_start>;
Log_name	Pos	Event_type	Server_id	End_log_pos	Info
master-bin.000001	#	Begin_load_query	#	#	;file_id=#;block_len=12
master-bin.000001	#	Execute_load_query	#	#	use `test`; load data infile
'../std_data_ln/rpl_loaddata.dat' into table t2 /* will be "killed" in the middle */
;file_id=#
exec of
'/data0/pushbuild/pb/mysql-6.0-runtime/212/mysql-6.0-runtime-exp/client/mysqlbinlog
--no-defaults --disable-force-if-open --debug-check
--character-sets-dir=/data0/pushbuild/pb/mysql-6.0-runtime/212/mysql-6.0-runtime-exp/sql/share/charsets
--force-if-open --start-position=107 /dev/shm/var-n_mix-130/log/master-bin.000001 >
/dev/shm/var-n_mix-130/tmp/binlog_killed_bug27571.binlog' failed, error: 256, status: 1,
errno: 0

More results from queries before failure can be found in
/dev/shm/var-n_mix-130/log/binlog_killed_simulate.log

Stopping All Servers
Restoring snapshot of databases
[31 Mar 2008 23:09] Sveta Smirnova
Thank you for the report.

Verified as described.
[20 Apr 2008 14:42] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/45714

ChangeSet@1.2634, 2008-04-20 16:42:50+04:00, kostja@bodhi.(none) +1 -0
  Disable binlog_killed_simulate.test, Bug#35543 "mysqlbinlog.cc does 
  not properly work with tmp files"
[20 Apr 2008 15:00] Konstantin Osipov
Putting back to Verified, since the patch only disabled the test.
[20 Apr 2008 15:01] Bugs System
Pushed into 6.0.6-alpha
[30 Apr 2008 14:01] Andrei Elkin
Although the grace of opening belongs to this one, i am setting it as a dup
for one that has an assignee.
[5 May 2008 15:14] Andrei Elkin
Find patch on Bug #35546 mysqlbinlog.cc: Load_log_processor::process_first_event() fails
creating unique
page.
[9 May 2008 15:17] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/46562

ChangeSet@1.2586, 2008-05-09 15:17:10+02:00, msvensson@pilot.(none) +1 -0
  BUG#35543 mysqlbinlog.cc does not properly work with tmp files
   - Backport to 5.0, use --local-load to instruct myqlbinlog where to 
   put the files it generate
[12 May 2008 15:29] Andrei Elkin
fixes pushed with bug#35546 into 6.0-rpl.
[10 Jun 2008 21:48] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/47708

2635 Joerg Bruehe	2008-06-10 [merge]
      Merge two changes of mysql-test-run.pl (bug#34995 + bug#35543)
      and the 5.0.62 release tag.

-- 
MySQL Code Commits Mailing List
For list archives: http://lists.mysql.com/commits
To unsubscribe:    http://lists.mysql.com/commits?unsub=commits@bugs.mysql.com
[11 Jun 2008 16:02] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/47737

2666 Andrei Elkin	2008-06-11
      Post-Bug#35543 fixing reenabling of binlog_killed_simulate.
[28 Jul 2008 15:48] Bugs System
Pushed into 5.0.66  (revid:kgeorge@mysql.com-20080617084217-1u9yw41mpntg7hqk) (pib:2)
(Retry automatic marking, to ensure nothing is missed. cm01)
[28 Jul 2008 18:49] Bugs System
Pushed into 5.1.27  (revid:joerg@mysql.com-20080626161101-h5hsaluwtf05xdr2) (version
source revid:joerg@mysql.com-20080626161101-h5hsaluwtf05xdr2) (pib:3)
[29 Jul 2008 8:23] Jon Stephens
Documented bugfix as follows in the 5.0.66 and 5.1.28 changelogs:

        mysqlbinlog left temporary files on the disk after shutdown, leading to 
        the pollution of the temporary directory, which eventually caused 
        mysqlbinlog to fail. This caused problems in testing and other situations 
        where mysqlbinlog might be invoked many times in a relatively short period 
        of time.

Left in Patch Queued status pending merge to 6.0 (need version number of for 6.0 fix).
[20 Aug 2008 15:33] Chuck Bell
Pushed to 6.0.0.
[21 Aug 2008 21:32] Chuck Bell
Ignore last comment. Developer error.
[21 Aug 2008 21:33] Paul DuBois
Returning report to Patch Queued.
[25 Aug 2008 22:58] Chuck Bell
Released in 6.0.5.
[25 Aug 2008 22:58] Chuck Bell
Released in 6.0.7.
[26 Aug 2008 21:41] Paul DuBois
Noted in 6.0.7 changelog.
[30 Jan 14:26] Bugs System
Pushed into 6.0.10-alpha (revid:luis.soares@sun.com-20090129165607-wiskabxm948yx463)
(version source revid:luis.soares@sun.com-20090129163120-e2ntks4wgpqde6zt) (merge vers:
6.0.10-alpha) (pib:6)
[19 Nov 10:11] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/90926

2856 Bjorn Munch	2009-11-19
      Bug #35543 mysqlbinlog.cc does not properly work with tmp files
      mtr patch ported to v2