MySQL Bugs: #35543: mysqlbinlog.cc does not properly work with tmp files

Bug #35543	mysqlbinlog.cc does not properly work with tmp files
Submitted:	25 Mar 2008 8:40	Modified:	17 Jun 2010 22:55
Reporter:	Alexander Nozdrin	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Command-line Clients	Severity:	S2 (Serious)
Version:	6.0-BK	OS:	Any
Assigned to:	Andrei Elkin	CPU Architecture:	Any

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

Thank you for the report.

Verified as described.

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"

Putting back to Verified, since the patch only disabled the test.

Pushed into 6.0.6-alpha

Although the grace of opening belongs to this one, i am setting it as a dup
for one that has an assignee.

Find patch on Bug #35546 mysqlbinlog.cc: Load_log_processor::process_first_event() fails creating unique
page.

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

fixes pushed with bug#35546 into 6.0-rpl.

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

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.

Pushed into 5.0.66  (revid:kgeorge@mysql.com-20080617084217-1u9yw41mpntg7hqk) (pib:2)
(Retry automatic marking, to ensure nothing is missed. cm01)

Pushed into 5.1.27  (revid:joerg@mysql.com-20080626161101-h5hsaluwtf05xdr2) (version source revid:joerg@mysql.com-20080626161101-h5hsaluwtf05xdr2) (pib:3)

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).

Pushed to 6.0.0.

Ignore last comment. Developer error.

Returning report to Patch Queued.

Released in 6.0.5.

Released in 6.0.7.

Noted in 6.0.7 changelog.

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)

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

Pushed into 6.0.14-alpha (revid:alik@sun.com-20100220092844-jh07ayojyxn8uh9p) (version source revid:bjorn.munch@sun.com-20091119111729-sazk6qfk8qbwfq0y) (merge vers: 6.0.14-alpha) (pib:16)

Pushed into 5.5.3-m2 (revid:alik@sun.com-20100220092622-wvhh1vfy5tjq4mhu) (version source revid:bjorn.munch@sun.com-20091119092424-cpc87ef58xms6o9b) (merge vers: 5.5.0-beta) (pib:16)

Pushed into mysql-next-mr (revid:alik@sun.com-20100220092730-paoo5t9gcajs5dq8) (version source revid:bjorn.munch@sun.com-20091119092557-tm3cmjhd1jnlj0qc) (pib:16)

Noted in 5.5.3 changelog.

Pushed into 5.1.45 (revid:joro@sun.com-20100301083827-xnimmrjg6bh33o1o) (version source revid:azundris@mysql.com-20100222175719-viuh0f3gdsrkgv0r) (merge vers: 5.1.45) (pib:16)

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/110637

3103 Martin Skold	2010-06-09 [merge]
      Merged in 5.1.45
      added:
        mysql-test/include/not_binlog_format_row.inc
        mysql-test/r/bug39022.result
        mysql-test/r/no_binlog.result
        mysql-test/r/partition_debug_sync.result
        mysql-test/std_data/bug48449.frm
        mysql-test/suite/rpl/r/rpl_slow_query_log.result
        mysql-test/suite/rpl/t/rpl_slow_query_log-slave.opt
        mysql-test/suite/rpl/t/rpl_slow_query_log.test
        mysql-test/t/bug39022.test
        mysql-test/t/no_binlog.test
        mysql-test/t/partition_debug_sync.test
      renamed:
        mysql-test/r/variables+c.result => mysql-test/r/variables_community.result
        mysql-test/t/variables+c.test => mysql-test/t/variables_community.test
      modified:
        client/mysql.cc
        client/mysql_upgrade.c
        client/mysqladmin.cc
        client/mysqlbinlog.cc
        client/mysqlcheck.c
        client/mysqldump.c
        client/mysqlimport.c
        client/mysqlshow.c
        client/mysqlslap.c
        client/mysqltest.cc
        cmd-line-utils/readline/rlmbutil.h
        cmd-line-utils/readline/text.c
        configure.in
        extra/yassl/include/yassl_error.hpp
        extra/yassl/src/ssl.cpp
        extra/yassl/src/yassl_error.cpp
        mysql-test/include/mtr_warnings.sql
        mysql-test/lib/My/ConfigFactory.pm
        mysql-test/lib/My/SafeProcess.pm
        mysql-test/lib/My/SafeProcess/safe_process_win.cc
        mysql-test/lib/mtr_cases.pm
        mysql-test/lib/mtr_gprof.pl
        mysql-test/lib/mtr_misc.pl
        mysql-test/lib/mtr_report.pm
        mysql-test/lib/mtr_stress.pl
        mysql-test/lib/v1/mtr_stress.pl
        mysql-test/lib/v1/mysql-test-run.pl
        mysql-test/mysql-test-run.pl
        mysql-test/r/archive.result
        mysql-test/r/backup.result
        mysql-test/r/bigint.result
        mysql-test/r/csv.result
        mysql-test/r/default.result
        mysql-test/r/delete.result
        mysql-test/r/fulltext.result
        mysql-test/r/func_gconcat.result
        mysql-test/r/func_time.result
        mysql-test/r/group_by.result
        mysql-test/r/group_min_max.result
        mysql-test/r/having.result
        mysql-test/r/innodb-autoinc.result
        mysql-test/r/innodb_mysql.result
        mysql-test/r/join.result
        mysql-test/r/log_state.result
        mysql-test/r/multi_update.result
        mysql-test/r/myisam.result
        mysql-test/r/mysqltest.result
        mysql-test/r/show_check.result
        mysql-test/r/sp-bugs.result
        mysql-test/r/sp-error.result
        mysql-test/r/sp.result
        mysql-test/r/sp_notembedded.result
        mysql-test/r/sp_trans.result
        mysql-test/r/subselect.result
        mysql-test/r/type_bit.result
        mysql-test/r/type_blob.result
        mysql-test/r/type_timestamp.result
        mysql-test/r/view.result
        mysql-test/r/view_grant.result
        mysql-test/r/warnings.result
        mysql-test/suite/rpl/r/rpl_sp.result
        mysql-test/suite/rpl/t/rpl_loaddata_symlink.test
        mysql-test/suite/sys_vars/r/log_basic.result
        mysql-test/suite/sys_vars/r/log_bin_trust_routine_creators_basic.result
        mysql-test/suite/sys_vars/r/slow_query_log_func.result
        mysql-test/suite/sys_vars/t/slow_query_log_func.test
        mysql-test/t/archive.test
        mysql-test/t/bigint.test
        mysql-test/t/csv.test
        mysql-test/t/delete.test
        mysql-test/t/fulltext.test
        mysql-test/t/func_gconcat.test
        mysql-test/t/group_by.test
        mysql-test/t/group_min_max.test
        mysql-test/t/having.test
        mysql-test/t/innodb-autoinc.test
        mysql-test/t/innodb_mysql.test
        mysql-test/t/join.test
        mysql-test/t/multi_update.test
        mysql-test/t/myisam.test
        mysql-test/t/mysqltest.test
        mysql-test/t/sp-bugs.test
        mysql-test/t/sp_notembedded.test
        mysql-test/t/subselect.test
        mysql-test/t/type_bit.test
        mysql-test/t/view.test
        mysql-test/t/view_grant.test
        mysys/default.c
        scripts/mysqld_multi.sh
        server-tools/instance-manager/options.cc
        sql/field.cc
        sql/ha_partition.cc
        sql/item.cc
        sql/item.h
        sql/item_cmpfunc.h
        sql/item_row.cc
        sql/item_sum.cc
        sql/item_timefunc.cc
        sql/log.cc
        sql/log_event.cc
        sql/log_event_old.cc
        sql/mysql_priv.h
        sql/mysqld.cc
        sql/opt_range.cc
        sql/opt_sum.cc
        sql/share/errmsg.txt
        sql/sp.cc
        sql/sp_cache.cc
        sql/sp_head.cc
        sql/sql_base.cc
        sql/sql_class.cc
        sql/sql_class.h
        sql/sql_lex.cc
        sql/sql_lex.h
        sql/sql_parse.cc
        sql/sql_repl.cc
        sql/sql_select.cc
        sql/sql_select.h
        sql/sql_table.cc
        sql/sql_trigger.cc
        sql/sql_update.cc
        sql/sql_view.cc
        sql/table.cc
        sql/table.h
        storage/archive/ha_archive.cc
        storage/csv/ha_tina.cc
        storage/innobase/buf/buf0buf.c
        storage/innobase/buf/buf0rea.c
        storage/innobase/handler/ha_innodb.cc
        storage/innobase/include/buf0rea.h
        storage/innobase/lock/lock0lock.c
        storage/innobase/os/os0file.c
        storage/myisam/ft_boolean_search.c
        storage/myisam/mi_dynrec.c
        storage/myisam/mi_locking.c
        support-files/mysql.spec.sh

Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)

Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:martin.skold@mysql.com-20100609140708-52rvuyq4q500sxkq) (merge vers: 5.1.45-ndb-6.2.19) (pib:16)

Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)