Bug #60976 Crash, valgrind warning and memory leak with partitioned archive tables
Submitted: 26 Apr 2011 8:48 Modified: 16 Jun 2011 19:17
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Archive storage engine Severity:S1 (Critical)
Version:5.1, 5.5 OS:Any
Assigned to: CPU Architecture:Any

[26 Apr 2011 8:48] Philip Stoev
Description:
Executing mysqlcheck against the attached database results in the following 3 issues:

A. Memory leak. Thoughout the operation of mysqlcheck, mysqld memory consumption increases steadily, even though tables are small or empty. Valgrind however does not report any leaked memory on server shutdown;

B. Assertion:

mysqld: /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/mysys/my_seek.c:57: my_seek: Assertion `fd != -1' failed.

#8  0x006b0d98 in __assert_fail () from /lib/libc.so.6
#9  0x0842a40b in my_seek (fd=-1, pos=0, whence=0, MyFlags=0) at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/mysys/my_seek.c:57
#10 0x08493d04 in azrewind (s=0x9b04eea0) at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/storage/archive/azio.c:669
#11 0x08490f3d in ha_archive::read_data_header (this=0x9b04ed78, file_to_read=0x9b04eea0)
    at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/storage/archive/ha_archive.cc:298
#12 0x08492906 in ha_archive::check (this=0x9b04ed78, thd=0xa7fa468, check_opt=0xa7fbe64)
    at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/storage/archive/ha_archive.cc:1691
#13 0x082d6acf in handler::ha_check (this=0x9b04ed78, thd=0xa7fa468, check_opt=0xa7fbe64)
    at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/handler.cc:3168
#14 0x08644395 in handle_opt_part (thd=0xa7fa468, check_opt=0xa7fbe64, file=0x9b04ed78, flag=3)
    at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/ha_partition.cc:1013
#15 0x08644890 in ha_partition::handle_opt_partitions (this=0x9b9f9a50, thd=0xa7fa468, check_opt=0xa7fbe64, flag=3)
    at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/ha_partition.cc:1156
#16 0x08644b39 in ha_partition::check (this=0x9b9f9a50, thd=0xa7fa468, check_opt=0xa7fbe64)
    at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/ha_partition.cc:924
#17 0x082d6acf in handler::ha_check (this=0x9b9f9a50, thd=0xa7fa468, check_opt=0xa7fbe64)
    at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/handler.cc:3168
#18 0x08272ca6 in mysql_admin_table (thd=0xa7fa468, tables=0xa530d998, check_opt=0xa7fbe64, operator_name=0x87cf1bc "check", lock_type=TL_READ_NO_INSERT,
    open_for_modify=false, no_warnings_for_error=false, extra_open_options=32, prepare_func=0, operator_func=
    (int (handler::*)(handler *, THD *, HA_CHECK_OPT *)) 0x82d6a50 <handler::ha_check(THD*, HA_CHECK_OPT*)>, view_operator_func=
    0x8234f67 <view_checksum(THD*, TABLE_LIST*)>) at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/sql_admin.cc:581
#19 0x08273eca in Check_table_statement::execute (this=0xa530dd58, thd=0xa7fa468)
    at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/sql_admin.cc:963
#20 0x081b82e2 in mysql_execute_command (thd=0xa7fa468) at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/sql_parse.cc:4321
#21 0x081b8e23 in mysql_parse (thd=0xa7fa468, rawbuf=0xa530d8d8 "CHECK TABLE <The table name has been removed for privacy reasons>", length=23, parser_state=0xa80ff030)
    at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/sql_parse.cc:5509
#22 0x081ba22e in dispatch_command (command=COM_QUERY, thd=0xa7fa468, packet=0xa8665c1 "", packet_length=24)
    at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/sql_parse.cc:1035
#23 0x081bba97 in do_command (thd=0xa7fa468) at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/sql_parse.cc:772
#24 0x0826624d in do_handle_one_connection (thd_arg=0xa7fa468) at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/sql_connect.cc:748
#25 0x08266314 in handle_one_connection (arg=0xa7fa468) at /export/home/pb2/build/sb_0-3071094-1299684307.53/mysql-5.5.10/sql/sql_connect.cc:684
#26 0x00821919 in start_thread () from /lib/libpthread.so.0
#27 0x0076acce in clone () from /lib/libc.so.6

C. Valgrind warning:

==4278== Conditional jump or move depends on uninitialised value(s)
==4278==    at 0x842A3AF: my_seek (my_seek.c:52)
==4278==    by 0x8493D03: azrewind (azio.c:669)
==4278==    by 0x8490F3C: ha_archive::read_data_header(azio_stream*) (ha_archive.cc:298)
==4278==    by 0x8492905: ha_archive::check(THD*, st_ha_check_opt*) (ha_archive.cc:1691)
==4278==    by 0x82D6ACE: handler::ha_check(THD*, st_ha_check_opt*) (handler.cc:3168)
==4278==    by 0x8644394: handle_opt_part(THD*, st_ha_check_opt*, handler*, unsigned int) (ha_partition.cc:1013)
==4278==    by 0x864488F: ha_partition::handle_opt_partitions(THD*, st_ha_check_opt*, unsigned int) (ha_partition.cc:1156)
==4278==    by 0x8644B38: ha_partition::check(THD*, st_ha_check_opt*) (ha_partition.cc:924)
==4278==    by 0x82D6ACE: handler::ha_check(THD*, st_ha_check_opt*) (handler.cc:3168)
==4278==    by 0x8272CA5: mysql_admin_table(THD*, TABLE_LIST*, st_ha_check_opt*, char const*, thr_lock_type, bool, bool, unsigned int, int (*)(THD*, TABLE_LIS
T*, st_ha_check_opt*), int (handler::*)(THD*, st_ha_check_opt*), int (*)(THD*, TABLE_LIST*)) (sql_admin.cc:581)
==4278==    by 0x8273EC9: Check_table_statement::execute(THD*) (sql_admin.cc:963)
==4278==    by 0x81B82E1: mysql_execute_command(THD*) (sql_parse.cc:4321)
==4278==    by 0x81B8E22: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:5509)
==4278==    by 0x81BA22D: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1035)
==4278==    by 0x81BBA96: do_command(THD*) (sql_parse.cc:772)
==4278==    by 0x826624C: do_handle_one_connection(THD*) (sql_connect.cc:748)

How to repeat:
run mysqlcheck on attached datadir
[26 Apr 2011 9:30] MySQL Verification Team
some related archive locking bugs: (but have not confirmed anything with partitions yet):

bug #42784 (archive tables cause 100% cpu usage and hang in show table status)
bug #37280 (check and repair table report table corrupted when run concurrently with inserts)
bug #51252 (archive tables still fail under stress tests: crash, corruption, 4G memory alloc)
[26 Apr 2011 9:36] Valeriy Kravchuk
Verified just as described with current mysql-5.1 on 32-bit Ubuntu 10.04:

...
110426 12:34:01 [Note] /home/openxs/dbs/5.1/libexec/mysqld: ready for connections.
Version: '5.1.57-valgrind-max-debug'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution
mysqld: my_seek.c:58: my_seek: Assertion `fd != -1' failed.
110426 12:34:29 - 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=8384512
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 = 337768 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x9027508
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 = 0xb43b938c thread_stack 0x30000
/home/openxs/dbs/5.1/libexec/mysqld(my_print_stacktrace+0x26)[0x85ff9ba]
/home/openxs/dbs/5.1/libexec/mysqld(handle_segfault+0x2b9)[0x827c4e2]
[0x353400]
/lib/tls/i686/cmov/libc.so.6(abort+0x182)[0x13da82]
/lib/tls/i686/cmov/libc.so.6(__assert_fail+0xf8)[0x133718]
/home/openxs/dbs/5.1/libexec/mysqld(my_seek+0x103)[0x85dd50f]
/home/openxs/dbs/5.1/libexec/mysqld(azrewind+0xfb)[0x84ab814]
/home/openxs/dbs/5.1/libexec/mysqld(_ZN10ha_archive16read_data_headerEP11azio_stream+0x55)[0x84a56dd]
/home/openxs/dbs/5.1/libexec/mysqld(_ZN10ha_archive5checkEP3THDP15st_ha_check_opt+0x12e)[0x84a9922]
/home/openxs/dbs/5.1/libexec/mysqld(_ZN7handler8ha_checkEP3THDP15st_ha_check_opt+0xca)[0x83c48f2]
/home/openxs/dbs/5.1/libexec/mysqld[0x83cb4f1]
/home/openxs/dbs/5.1/libexec/mysqld(_ZN12ha_partition21handle_opt_partitionsEP3THDP15st_ha_check_optj+0x2cc)[0x83cbacc]
/home/openxs/dbs/5.1/libexec/mysqld(_ZN12ha_partition5checkEP3THDP15st_ha_check_opt+0x97)[0x83cb355]
/home/openxs/dbs/5.1/libexec/mysqld(_ZN7handler8ha_checkEP3THDP15st_ha_check_opt+0xca)[0x83c48f2]
/home/openxs/dbs/5.1/libexec/mysqld[0x83ee1f1]
/home/openxs/dbs/5.1/libexec/mysqld(_Z17mysql_check_tableP3THDP10TABLE_LISTP15st_ha_check_opt+0xe0)[0x83f09bc]
/home/openxs/dbs/5.1/libexec/mysqld(_Z21mysql_execute_commandP3THD+0x2d5e)[0x8290ea1]
/home/openxs/dbs/5.1/libexec/mysqld(_Z11mysql_parseP3THDPcjPPKc+0x265)[0x829a683]
/home/openxs/dbs/5.1/libexec/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xc9a)[0x828c3c5]
/home/openxs/dbs/5.1/libexec/mysqld(_Z10do_commandP3THD+0x26c)[0x828b421]
/home/openxs/dbs/5.1/libexec/mysqld(handle_one_connection+0x159)[0x82895b4]
/lib/tls/i686/cmov/libpthread.so.0(+0x596e)[0xd6896e]
/lib/tls/i686/cmov/libc.so.6(clone+0x5e)[0x1dda4e]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x904ee28): CHECK TABLE `4test_com`
...
[16 Jun 2011 19:17] Paul DuBois
Noted in 5.1.58, 5.5.14 changelogs.

Running mysqlcheck or CHECK TABLE on a corrupted table could cause a
server crash.