Bug #49638 binlog_index fails in mysql-trunk-merge
Submitted: 12 Dec 2009 7:00 Modified: 13 Mar 2010 17:46
Reporter: Alexey Kopytov Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Tests Severity:S3 (Non-critical)
Version:5.5.0 OS:Any
Assigned to: Alfranio Correia
Triage: Triaged: D1 (Critical)

[12 Dec 2009 7:00] Alexey Kopytov
Description:
After a merge from mysql-5.1-bugteam binlog_index started failing in mysql-trunk-merge due to assertion failure on some hosts:

binlog.binlog_index 'row'                [ fail ]
        Test ended at 2009-12-12 02:24:24

CURRENT_TEST: binlog.binlog_index
mysqltest: At line 73: query 'purge binary logs TO 'master-bin.000002'' failed with wrong errno 2013: 'Lost connection to MySQL server during query', instead of 1377...

The result from queries just before the failure was:
< snip >
Warning	1612	Being purged log master-bin.000001 was not found
*** must show a list starting from the 'TO' argument of PURGE ***
show binary logs;
Log_name	File_size
master-bin.000004	#
reset master;
flush logs;
flush logs;
flush logs;
*** must be a warning master-bin.000001 was not found ***
Warnings:
Warning	1612	Being purged log master-bin.000001 was not found
*** must show one record, of the active binlog, left in the index file after PURGE ***
show binary logs;
Log_name	File_size
master-bin.000004	#
reset master;
flush logs;
flush logs;
flush logs;

More results from queries before failure can be found in /export/home/pb2/build/sb_0-None-1260567042.33/mysql-trunk-merge-gcov/mysql-test/var/log/binlog_index.log

Server [mysqld.1 - pid: 16182, winpid: 16182, exit: 256] failed during test run
Server log from this test:
091212  4:24:24 [Note] Plugin 'FEDERATED' is disabled.
091212  4:24:24 [Note] Plugin 'InnoDB' is disabled.
091212  4:24:24 [Note] Plugin 'ndbcluster' is disabled.
091212  4:24:24 [Note] Event Scheduler: Loaded 0 events
091212  4:24:24 [Note] /export/home/pb2/build/sb_0-None-1260567042.33/mysql-trunk-merge-gcov/sql/mysqld: ready for connections.
Version: '5.5.0-beta-gcov-debug-log'  socket: '/export/home/pb2/build/sb_0-None-1260567042.33/tmp/G1lkqr2HWS/mysqld.1.sock'  port: 13010  Source distribution
091212  4:24:24 [Note] Failed to execute my_stat on file './master-bin.000001'
091212  4:24:24 [Note] Failed to execute my_stat on file './master-bin.000001'
mysqld: sql_error.cc:599: void push_warning(THD*, MYSQL_ERROR::enum_warning_level, uint, const char*): Assertion `(level != MYSQL_ERROR::WARN_LEVEL_ERROR) || (code == 1005) || (code == 1478)' failed.
091212  4:24:24 - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=1
max_threads=151
threads_connected=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 60575 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x1f3d1e88
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x419d8110 thread_stack 0x40000

How to repeat:
http://pb2.norway.sun.com/web.py?template=mysql_show_test_failure&search=yes&push_id=75654...
[12 Dec 2009 7:05] 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/93775

2945 Alexey Kopytov	2009-12-12
      Disabled binlog.binlog_index, bug#49638.
[14 Dec 2009 7:29] Sveta Smirnova
Thank you for the report.

Verified as described.
[16 Dec 2009 18:58] Alfranio Correia
In the trunk, we have the following assertion in sql/sql_error.cc:

void push_warning(THD *thd, MYSQL_ERROR::enum_warning_level level,
                  uint code, const char *msg):

  /*
    Calling push_warning/push_warning_printf with a
    level of WARN_LEVEL_ERROR *is* a bug.
    Either use my_error(), or WARN_LEVEL_WARN.
    Please fix the calling code, and do *NOT*
    add more work around code in the assert below.
  */
  DBUG_ASSERT(   (level != MYSQL_ERROR::WARN_LEVEL_ERROR)
              || (code == ER_CANT_CREATE_TABLE) /* See Bug#47233 */
              || (code == ER_ILLEGAL_HA_CREATE_OPTION) /* See Bug#47233 */
             );

which is not in the bugteam trees mysql-5.1-bugteam and mysql-pe.

To fix the problem will follow the guidelines in the comments above and push a patch to 5.1-bugteam and mysql-pe.
[16 Dec 2009 19:54] 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/94595

3280 Alfranio Correia	2009-12-16
      BUG#49638 binlog_index fails in mysql-trunk-merge
      
      Calling push_warning/push_warning_printf with a level of
      WARN_LEVEL_ERROR *is* a bug. We should either use my_error(),
      or WARN_LEVEL_WARN.
[17 Dec 2009 18:24] 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/94827

3792 Alfranio Correia	2009-12-17
      Post-fix for BUG#49638
      
      Updated result set in mysql-pe.
[19 Dec 2009 8:27] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091219082307-f3i4fn0tm8trb3c0) (version source revid:alik@sun.com-20091217193315-s3ck6ltg8m1zz6r3) (merge vers: 6.0.14-alpha) (pib:15)
[19 Dec 2009 8:31] Bugs System
Pushed into 5.5.1-m2 (revid:alik@sun.com-20091219082021-f34nq4jytwamozz0) (version source revid:alexey.kopytov@sun.com-20091217171018-6n5pd6i7mgm0sbui) (merge vers: 5.5.0-beta) (pib:15)
[19 Dec 2009 8:34] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20091219082213-nhjjgmphote4ntxj) (version source revid:alik@sun.com-20091217191654-rb9sci536v96viaz) (pib:15)
[15 Jan 2010 9:00] Bugs System
Pushed into 5.1.43 (revid:joro@sun.com-20100115085139-qkh0i0fpohd9u9p5) (version source revid:jimw@mysql.com-20091217191514-t4zu0fd4z9534u1q) (merge vers: 5.1.42) (pib:16)
[16 Jan 2010 2:32] Paul Dubois
Noted in 5.1.43, 5.5.1, 6.0.14 changelogs.

The push_warning_printf() function was being called with an invalid
error level MYSQL_ERROR::WARN_LEVEL_ERROR, causing an assertion
failure. To fix the problem, MYSQL_ERROR::WARN_LEVEL_ERROR has been
replaced by MYSQL_ERROR::WARN_LEVEL_WARN. 

Setting report to NDI pending push to Celosia.
[15 Feb 2010 10:23] Jon Stephens
Discussed with Alfranio; no further merges expected. Closed.
[12 Mar 2010 14:06] Bugs System
Pushed into 5.1.44-ndb-7.0.14 (revid:jonas@mysql.com-20100312135944-t0z8s1da2orvl66x) (version source revid:jonas@mysql.com-20100312115609-woou0te4a6s4ae9y) (merge vers: 5.1.44-ndb-7.0.14) (pib:16)
[12 Mar 2010 14:22] Bugs System
Pushed into 5.1.44-ndb-6.2.19 (revid:jonas@mysql.com-20100312134846-tuqhd9w3tv4xgl3d) (version source revid:jonas@mysql.com-20100312060623-mx6407w2vx76h3by) (merge vers: 5.1.44-ndb-6.2.19) (pib:16)
[12 Mar 2010 14:36] Bugs System
Pushed into 5.1.44-ndb-6.3.33 (revid:jonas@mysql.com-20100312135724-xcw8vw2lu3mijrhn) (version source revid:jonas@mysql.com-20100312103652-snkltsd197l7q2yg) (merge vers: 5.1.44-ndb-6.3.33) (pib:16)