Bug #95573 InnoDB: Failing assertion: (block)->index || os_atomic_increment_ulint(&(block)
Submitted: 30 May 2019 9:17 Modified: 9 Jul 2019 11:58
Reporter: Manish Chawla Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: DDL Severity:S6 (Debug Builds)
Version:5.7.26 OS:Red Hat
Assigned to: CPU Architecture:Any

[30 May 2019 9:17] Manish Chawla
Description:
2019-05-28 09:47:13 0x7f61b156d700 InnoDB: Assertion failure in thread 140057563813632 in file btr0sea.cc line 1823
InnoDB: Failing assertion: (block)->index || os_atomic_increment_ulint(&(block)->n_pointers, 0) == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
13:47:13 UTC - 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=100
max_threads=151
thread_count=52
connection_count=52
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68261 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x7f619eaac000
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 = 7f61b156cde0 thread_stack 0x40000
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(my_print_stacktrace+0x35)[0x188022d]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(handle_fatal_signal+0x3e4)[0xed3f03]
/lib64/libpthread.so.0(+0x12d80)[0x7f61c57dfd80]
/lib64/libc.so.6(gsignal+0x10f)[0x7f61c374a93f]
/lib64/libc.so.6(abort+0x127)[0x7f61c3734c95]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld[0x1afb30d]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_Z32btr_search_update_hash_on_insertP9btr_cur_t+0x131)[0x1b459a9]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_Z25btr_cur_optimistic_insertmP9btr_cur_tPPmPP16mem_block_info_tP8dtuple_tPPhPP9big_rec_tmP9que_thr_tP5mtr_t+0xa24)[0x1b2c708]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_Z27row_ins_sec_index_entry_lowmmP12dict_index_tP16mem_block_info_tS2_P8dtuple_tmP9que_thr_tb+0xcd7)[0x1a034fb]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_Z23row_ins_sec_index_entryP12dict_index_tP8dtuple_tP9que_thr_tb+0x1b9)[0x1a03ff4]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld[0x1a041a1]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld[0x1a046e0]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld[0x1a04a4f]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_Z12row_ins_stepP9que_thr_t+0x2c8)[0x1a04eac]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld[0x1a22942]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_Z20row_insert_for_mysqlPKhP14row_prebuilt_t+0x4c)[0x1a22ea9]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_ZN11ha_innobase9write_rowEPh+0x6e0)[0x18d0756]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_ZN7handler12ha_write_rowEPh+0x215)[0xf5d4b9]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_Z12write_recordP3THDP5TABLEP9COPY_INFOS4_+0xe70)[0x176ce1f]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_ZN14Sql_cmd_insert12mysql_insertEP3THDP10TABLE_LIST+0xdea)[0x176a03e]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_ZN14Sql_cmd_insert7executeEP3THD+0x181)[0x17708cd]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_Z21mysql_execute_commandP3THDb+0x2ad3)[0x154feb0]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x583)[0x155580e]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0xbec)[0x154b01c]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(_Z10do_commandP3THD+0x4ba)[0x1549f38]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(handle_connection+0x1ee)[0x1678cad]
/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld(pfs_spawn_thread+0x173)[0x1cfd3c0]
/lib64/libpthread.so.0(+0x82de)[0x7f61c57d52de]
/lib64/libc.so.6(clone+0x43)[0x7f61c380fa63]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f6196011030): INSERT INTO sbtest6 (id, k, c, pad) VALUES (0, 5032, '09439550403-46907002116-61048646652-63795927679-78160718375-81131985842-36952696415-72054556452-07861164547-94138591170', '87207526034-98243251596-52225469788-57867772548-96814204414')
Connection ID (thread ID): 708
Status: NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file

How to repeat:
1. Create a debug build of MS5.7.26 version.

2. Initialize and start MS as:

/home/cloud-user/MS280519_5_7_26_debug/bin/mysqld  --core-file --basedir=/home/cloud-user/MS280519_5_7_26_debug --tmpdir=/home/cloud-user/MS280519_5_7_26_debug/data --datadir=/home/cloud-user/MS280519_5_7_26_debug/data   --socket=/home/cloud-user/MS280519_5_7_26_debug/socket.sock --port=15793 --log-error=/home/cloud-user/MS280519_5_7_26_debug/log/master.err --server-id=100 --log-bin=binlog 2>&1 &

3. Create the test database.

4. Create data in the test database:

num_tables=10
table_size=1000
sysbench /usr/share/sysbench/oltp_insert.lua --tables=${num_tables} --table-size=${table_size} --mysql-db=test --mysql-user=root --threads=100 --db-driver=mysql --mysql-socket=${mysqldir}/socket.sock prepare

5. Run the following scenario:

    echo "Create a database test1_innodb, add data and then drop it"
    ( for ((i=1; i<=3; i++)); do
        # Check if database is up otherwise exit the loop
        ${mysqldir}/bin/mysqladmin ping --user=root --socket=${mysqldir}/socket.sock 2>/dev/null 1>&2
        if [ "$?" -ne 0 ]; then
            break
        fi
        ${mysqldir}/bin/mysql -uroot -S${mysqldir}/socket.sock -e "CREATE DATABASE IF NOT EXISTS test1_innodb;" >/dev/null 2>&1
        sysbench /usr/share/sysbench/oltp_insert.lua --tables=1 --table-size=1000 --mysql-db=test1_innodb --mysql-user=root --threads=10 --db-driver=mysql --mysql-socket=${mysqldir}/socket.sock prepare >/dev/null 2>&1
        ${mysqldir}/bin/mysql -uroot -S${mysqldir}/socket.sock -e "ALTER TABLE test1_innodb.sbtest1 ADD COLUMN b JSON AS('{"k1": "value", "k2": [10, 20]}');" >/dev/null 2>&1
        ${mysqldir}/bin/mysql -uroot -S${mysqldir}/socket.sock -e "ALTER TABLE test1_innodb.sbtest1 DROP COLUMN b;" >/dev/null 2>&1
        ${mysqldir}/bin/mysql -uroot -S${mysqldir}/socket.sock -e "DROP DATABASE test1_innodb;" >/dev/null 2>&1
    done ) &

6. Simultaneously add data in the test database:

sysbench /usr/share/sysbench/oltp_insert.lua --tables=${num_tables} --mysql-db=test --mysql-user=root --threads=50 --db-driver=mysql --mysql-socket=${mysqldir}/socket.sock --time=20 run >/dev/null 2>&1 &

7. MS crashes with above assertion error.

Note: The issue is reproducible, though it may take some tries to get the crash.
[30 May 2019 9:20] Manish Chawla
Updating the MS version to 5.7.26.
[30 May 2019 14:28] MySQL Verification Team
Hi Mr. Chawla,

Thank you for your bug report.

I have executed your test case 30 times so far.  I have run sysbench prepare with the exact options, while in parallel I ran your set of SQL commands in the batch mode.

All tests finished with "Table .... does not exist". No crashes, no asserts, no nothing ...

It finished without any problems.

I have tested everything on my iMac. Hence, if your test is Windows specific, do let us know.
[30 May 2019 15:14] Manish Chawla
Hi Sinisa,
Thanks for testing the scenario. The issue was found on a RHEL8 server, however it may not be limited to a particular OS. I think this cannot be reproduced on an iMac as it is slow to run the queries. Please try on a fast server if possible, which can run a heavy load. Thanks.
[30 May 2019 15:17] Manish Chawla
One more information, only the steps 5 and 6 have to be run in parallel.
[31 May 2019 12:44] MySQL Verification Team
Hi,

Yes, I have run only steps 5 and 6 in parallel.

And my iMac is quite fast. It has 6-core CPU running at 4.5 GHz with 3 Tb of SSD.

I will try it five more times, but if you do not hear from me, it means that I can't repeat your problem.
[31 May 2019 13:30] Manish Chawla
Please increase the sysbench --threads to 100-200 in step 6, so that there is heavy load when you are running the queries in step 5.
[31 May 2019 17:19] MySQL Verification Team
Hello Mr. Chawla,

I have tested with 100 threads and 200 threads. I have used your script and sysbench run command to the last letter. Each test took 20 to 30 seconds. I ran additional 30 tests, half with 100 threads and half with 200 threads.

No luck. The best that I managed to get is a broken connection error. That is due to dropping test database while sysbench run is still on.

Can't repeat.
[9 Jul 2019 11:58] MySQL Verification Team
Thank you for the report and feedback.
Verified as described with 5.7.26 debug build.

regards,
Umesh
[9 Jul 2019 11:59] MySQL Verification Team
Test results - 5.7.26

Attachment: 95573_5.7.26.results (application/octet-stream, text), 53.13 KiB.