Bug #75833 InnoDB: Failing assertion: found in buf0buf.cc line 3856

Submitted: 10 Feb 2015 6:45 Modified: 16 Feb 2015 13:06
Reporter: Roel Van de Paar Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: DML Severity:S3 (Non-critical)
Version:5.7.5-m15, 5.7.6 OS:Any
Assigned to: CPU Architecture:Any

[10 Feb 2015 6:45] Roel Van de Paar 
Description:
2015-02-10T06:38:26.899109Z 0 [Note] /sda/MS-mysql-5.7.5-m15-linux-x86_64-debug/bin/mysqld: ready for connections.
Version: '5.7.5-m15-debug'  socket: '/sda/MS-mysql-5.7.5-m15-linux-x86_64-debug/socket.sock'  port: 16633  MySQL Community Server (GPL)
2015-02-10 17:38:42 0x7fd5273ff700  InnoDB: Assertion failure in thread 140553463265024 in file buf0buf.cc line 3856
InnoDB: Failing assertion: found

(gdb) bt
#0  0x00007f9db5bb5771 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000e15cd8 in my_write_core (sig=6) at /bzr/testbuild/mysql-5.7.5-m15_dbg/mysys/stacktrace.c:247
#2  0x0000000000822044 in handle_fatal_signal (sig=6) at /bzr/testbuild/mysql-5.7.5-m15_dbg/sql/signal_handler.cc:219
#3  <signal handler called>
#4  0x00007f9db47b95c9 in raise () from /lib64/libc.so.6
#5  0x00007f9db47bacd8 in abort () from /lib64/libc.so.6
#6  0x00000000010d4a9b in ut_dbg_assertion_failed (expr=0x14ff777 "found", file=0x14fdbe0 "/bzr/testbuild/mysql-5.7.5-m15_dbg/storage/innobase/buf/buf0buf.cc",line=3856) at /bzr/testbuild/mysql-5.7.5-m15_dbg/storage/innobase/ut/ut0dbg.cc:68
#7  0x0000000001134e9a in buf_page_get_gen (page_id=..., page_size=..., rw_latch=2, guess=0x0, mode=10, file=0x1483768 "/bzr/testbuild/mysql-5.7.5-m15_dbg/storage/innobase/handler/ha_innodb.cc", line=15082, mtr=0x7f9db609b550, dirty_with_no_latch=false) at /bzr/testbuild/mysql-5.7.5-m15_dbg/storage/innobase/buf/buf0buf.cc:3856
#8  0x0000000000f2119d in innodb_make_page_dirty (thd=0x7f9cf801c000, var=0x1d5e280 <mysql_sysvar_fil_make_page_dirty_debug>, var_ptr=0x1e13020 <srv_fil_make_page_dirty_debug>, save=0x7f9cf8027ba8) at /bzr/testbuild/mysql-5.7.5-m15_dbg/storage/innobase/handler/ha_innodb.cc:15080
#9  0x0000000000b6a6e7 in sys_var_pluginvar::global_update (this=0x7f9d95fa7d78, thd=0x7f9cf801c000, var=0x7f9cf8027b88) at /bzr/testbuild/mysql-5.7.5-m15_dbg/sql/sql_plugin.cc:3363
#10 0x0000000000a98593 in sys_var::update (this=0x7f9d95fa7d78, thd=0x7f9cf801c000, var=0x7f9cf8027b88) at /bzr/testbuild/mysql-5.7.5-m15_dbg/sql/set_var.cc:192
#11 0x0000000000a9978a in set_var::update (this=0x7f9cf8027b88, thd=0x7f9cf801c000) at /bzr/testbuild/mysql-5.7.5-m15_dbg/sql/set_var.cc:680
#12 0x0000000000a99354 in sql_set_variables (thd=0x7f9cf801c000, var_list=0x7f9cf801e6e0) at /bzr/testbuild/mysql-5.7.5-m15_dbg/sql/set_var.cc:583
#13 0x0000000000b4ae5e in mysql_execute_command (thd=0x7f9cf801c000) at /bzr/testbuild/mysql-5.7.5-m15_dbg/sql/sql_parse.cc:3672
#14 0x0000000000b4fcc1 in mysql_parse (thd=0x7f9cf801c000, parser_state=0x7f9db609ce60) at /bzr/testbuild/mysql-5.7.5-m15_dbg/sql/sql_parse.cc:5427
#15 0x0000000000b44814 in dispatch_command (command=COM_QUERY, thd=0x7f9cf801c000, packet=0x7f9cf8033011 "set global innodb_fil_make_page_dirty_debug=@space_id", packet_length=53) at /bzr/testbuild/mysql-5.7.5-m15_dbg/sql/sql_parse.cc:1250
#16 0x0000000000b4354d in do_command (thd=0x7f9cf801c000) at /bzr/testbuild/mysql-5.7.5-m15_dbg/sql/sql_parse.cc:834
#17 0x0000000000c4d4ce in handle_connection (arg=0x7f9d97bfff40) at /bzr/testbuild/mysql-5.7.5-m15_dbg/sql/conn_handler/connection_handler_per_thread.cc:298
#18 0x0000000000e394b8 in pfs_spawn_thread (arg=0x7f9d983f8b10) at /bzr/testbuild/mysql-5.7.5-m15_dbg/storage/perfschema/pfs.cc:2137
#19 0x00007f9db5bb0df3 in start_thread () from /lib64/libpthread.so.0
#20 0x00007f9db487a1ad in clone () from /lib64/libc.so.6

How to repeat:
DROP DATABASE test;CREATE DATABASE test;USE test;
create TABLE t0(id int key,fk int,index index_fk (fk)) engine=innodb;
select space from information_schema.innodb_sys_tables where name='test/t0' into @space_id;
DROP TABLE t0;
set global innodb_fil_make_page_dirty_debug=@space_id;

Suggested fix:
1) Fix non-descriptive assertion message
2) Why assert at all when table is already dropped (unless somehow that same page was still changed subsequently?) etc.
[10 Feb 2015 9:16] MySQL Verification Team 
Hello Roel,

Thank you for the report and test case.
Observed that latest 5.7.6 debug build is affected( but I see diff stack traces).

Thanks,
Umesh
[10 Feb 2015 9:17] MySQL Verification Team 
// Startup and build used for tests

bin/mysql_install_db --basedir=/export/umesh/mysql-5.7.6 --datadir=/export/umesh/mysql-5.7.6/75833 -v
bin/mysqld-debug --basedir=/export/umesh/mysql-5.7.6 --datadir=/export/umesh/mysql-5.7.6/75833 --core-file --socket=/tmp/mysql_ushastry.sock  --port=15000 --log-error=/export/umesh/mysql-5.7.6/75833/log.err 2>&1 &

commit: 0cca166312484b18946717d1c0cc02f7d939f3fb
date: 2015-02-09 14:17:56 +0530
build-date: 2015-02-09 10:14:44 +0100
short: 0cca166
branch: mysql-trunk

MySQL source 5.7.6

// Extract from error log

2015-02-10T09:08:26.878258Z 0 [Note] bin/mysqld-debug: ready for connections.
Version: '5.7.6-m16-enterprise-commercial-advanced-debug'  socket: '/tmp/mysql_ushastry.sock'  port: 15000  MySQL Enterprise Server - Advanced Edition Debug (Commercial)
2015-02-10 10:08:39 0x7fe8bcd11700  InnoDB: Assertion failure in thread 140637576959744 in file mtr0mtr.cc line 661
InnoDB: Failing assertion: m_impl.m_user_space

(gdb) bt
#0  0x00007fe8c84e7771 in pthread_kill () from /lib64/libpthread.so.0
#1  0x00000000013d2078 in my_write_core (sig=6) at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/mysys/stacktrace.c:247
#2  0x0000000000be5a8e in handle_fatal_signal (sig=6) at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/sql/signal_handler.cc:220
#3  <signal handler called>
#4  0x00007fe8c70ed5c9 in raise () from /lib64/libc.so.6
#5  0x00007fe8c70eecd8 in abort () from /lib64/libc.so.6
#6  0x00000000016f843f in ut_dbg_assertion_failed (expr=0x1d04f88 "m_impl.m_user_space",
    file=0x1d04a08 "/export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/storage/innobase/mtr/mtr0mtr.cc", line=661)
    at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/storage/innobase/ut/ut0dbg.cc:67
#7  0x00000000015aa791 in mtr_t::lookup_user_space (this=0x7fe8bcd0e440, space_id=24)
    at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/storage/innobase/mtr/mtr0mtr.cc:661
#8  0x000000000151d1ac in mtr_t::set_named_space (this=0x7fe8bcd0e440, space_id=24)
    at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/storage/innobase/include/mtr0mtr.h:330
#9  0x0000000001518ef4 in innodb_make_page_dirty (thd=0x7fe854000bb0, var=0x2705cc0 <mysql_sysvar_fil_make_page_dirty_debug>, var_ptr=0x27f0588 <srv_fil_make_page_dirty_debug>,
    save=0x7fe854005e00) at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/storage/innobase/handler/ha_innodb.cc:15712
#10 0x000000000110579c in sys_var_pluginvar::global_update (this=0x3daac40, thd=0x7fe854000bb0, var=0x7fe854005de0)
    at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/sql/sql_plugin.cc:3430
#11 0x0000000001020d9c in sys_var::update (this=0x3daac40, thd=0x7fe854000bb0, var=0x7fe854005de0)
    at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/sql/set_var.cc:182
#12 0x00000000010223ac in set_var::update (this=0x7fe854005de0, thd=0x7fe854000bb0) at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/sql/set_var.cc:780
#13 0x0000000001021d2d in sql_set_variables (thd=0x7fe854000bb0, var_list=0x7fe854002e58) at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/sql/set_var.cc:651
#14 0x00000000010d5e70 in mysql_execute_command (thd=0x7fe854000bb0) at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:3315
#15 0x00000000010daeb2 in mysql_parse (thd=0x7fe854000bb0, parser_state=0x7fe8bcd0fe40) at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:5129
#16 0x00000000010d0bbc in dispatch_command (command=COM_QUERY, thd=0x7fe854000bb0, packet=0x7fe854009ce1 "set global innodb_fil_make_page_dirty_debug=@space_id", packet_length=53)
    at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:1249
#17 0x00000000010cf8ee in do_command (thd=0x7fe854000bb0) at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:835
#18 0x00000000011f25b9 in handle_connection (arg=0x4a6a610) at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/sql/conn_handler/connection_handler_per_thread.cc:298
#19 0x000000000145ee25 in pfs_spawn_thread (arg=0x4a5d4b0) at /export/home/pb2/build/sb_0-14366248-1423476223.94/mysqlcom-pro-5.7.6-m16/storage/perfschema/pfs.cc:2147
#20 0x00007fe8c84e2df3 in start_thread () from /lib64/libpthread.so.0
#21 0x00007fe8c71ae47d in clone () from /lib64/libc.so.6
[16 Feb 2015 13:06] Daniel Price 
Posted by developer:
 
Fixed as of the upcoming 5.7.7, 5.8.0 release, and here's the changelog entry:

A debug variable used to modify the first page of a tablespace raised an
assertion when set to a nonexistent tablespace ID.

Portions of this website are copyright © 2001, 2002 The PHP Group

Page generated in 0.053 sec. using MySQL 8.4.7-u6-cloud

Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the respective copyright holders.
It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.