MySQL Bugs: #98273: Assertion failure upon INSERT into the table with SPATIAL index

Bug #98273	Assertion failure upon INSERT into the table with SPATIAL index
Submitted:	17 Jan 2020 15:56	Modified:	18 Jan 2020 12:47
Reporter:	Valeriy Kravchuk	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S6 (Debug Builds)
Version:	5.7.29, 8.0.19, 8.0.11	OS:	Ubuntu (16.04)
Assigned to:		CPU Architecture:	Any

Description:
I've got the following assertion failure:

...
2020-01-17T15:39:30.272803Z 0 [Note] Event Scheduler: Loaded 0 events
2020-01-17T15:39:30.273537Z 0 [Note] /home/openxs/dbs/5.7d/bin/mysqld: ready for connections.
Version: '5.7.29-debug-log'  socket: '/home/openxs/dbs/5.7d/mysql-test/var/tmp/mysqld.1.sock'  port: 13000  MySQL Community Server (GPL)
2020-01-17T15:39:31.551226Z 3 [ERROR] [FATAL] InnoDB: Data field type 0, len 1072693248
2020-01-17 18:39:31 0x7fab00751700  InnoDB: Assertion failure in thread 140372423808768 in file ut0ut.cc line 918
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.
15:39:31 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=1048576
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 61093 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7faab81201a0
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 = 7fab00750e38 thread_stack 0x40000
/home/openxs/dbs/5.7d/bin/mysqld(my_print_stacktrace+0x47)[0x19871c2]
/home/openxs/dbs/5.7d/bin/mysqld(handle_fatal_signal+0x425)[0xf16956]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7fab079e8390]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x38)[0x7fab06da1428]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7fab06da302a]
/home/openxs/dbs/5.7d/bin/mysqld[0x1c88217]
/home/openxs/dbs/5.7d/bin/mysqld(_ZN2ib5fatalD1Ev+0x71)[0x1c8d0d9]
/home/openxs/dbs/5.7d/bin/mysqld(_Z18dfield_check_typedPK8dfield_t+0x11a)[0x1d20e71]
/home/openxs/dbs/5.7d/bin/mysqld(_Z18dtuple_check_typedPK8dtuple_t+0x4e)[0x1d20f01]
/home/openxs/dbs/5.7d/bin/mysqld[0x1de0554]
/home/openxs/dbs/5.7d/bin/mysqld[0x1de2e19]
/home/openxs/dbs/5.7d/bin/mysqld(_Z25rtr_page_split_and_insertmP9btr_cur_tPPmPP16mem_block_info_tPK8dtuple_tmP5mtr_t+0x3d8)[0x1de5712]
/home/openxs/dbs/5.7d/bin/mysqld(_Z25btr_root_raise_and_insertmP9btr_cur_tPPmPP16mem_block_info_tPK8dtuple_tmP5mtr_t+0x8dd)[0x1ca1a83]
/home/openxs/dbs/5.7d/bin/mysqld(_Z26btr_cur_pessimistic_insertmP9btr_cur_tPPmPP16mem_block_info_tP8dtuple_tPPhPP9big_rec_tmP9que_thr_tP5mtr_t+0x45b)[0x1cbd4df]
/home/openxs/dbs/5.7d/bin/mysqld[0x1de4708]
/home/openxs/dbs/5.7d/bin/mysqld(_Z25rtr_page_split_and_insertmP9btr_cur_tPPmPP16mem_block_info_tPK8dtuple_tmP5mtr_t+0xe28)[0x1de6162]
/home/openxs/dbs/5.7d/bin/mysqld(_Z25btr_page_split_and_insertmP9btr_cur_tPPmPP16mem_block_info_tPK8dtuple_tmP5mtr_t+0xc9)[0x1ca399b]
/home/openxs/dbs/5.7d/bin/mysqld(_Z26btr_cur_pessimistic_insertmP9btr_cur_tPPmPP16mem_block_info_tP8dtuple_tPPhPP9big_rec_tmP9que_thr_tP5mtr_t+0x4a1)[0x1cbd525]
/home/openxs/dbs/5.7d/bin/mysqld(_Z27row_ins_sec_index_entry_lowmmP12dict_index_tP16mem_block_info_tS2_P8dtuple_tmP9que_thr_tb+0xee2)[0x1b7a05c]
/home/openxs/dbs/5.7d/bin/mysqld(_Z23row_ins_sec_index_entryP12dict_index_tP8dtuple_tP9que_thr_tb+0x26e)[0x1b7ab62]
/home/openxs/dbs/5.7d/bin/mysqld[0x1b7ac5a]
/home/openxs/dbs/5.7d/bin/mysqld[0x1b7b1d0]
/home/openxs/dbs/5.7d/bin/mysqld[0x1b7b565]
/home/openxs/dbs/5.7d/bin/mysqld(_Z12row_ins_stepP9que_thr_t+0x2cb)[0x1b7b9d9]
/home/openxs/dbs/5.7d/bin/mysqld[0x1b9b44b]
/home/openxs/dbs/5.7d/bin/mysqld(_Z20row_insert_for_mysqlPKhP14row_prebuilt_t+0x4c)[0x1b9ba37]
/home/openxs/dbs/5.7d/bin/mysqld(_ZN11ha_innobase9write_rowEPh+0x740)[0x1a30ab8]
/home/openxs/dbs/5.7d/bin/mysqld(_ZN7handler12ha_write_rowEPh+0x224)[0xfa8fce]
/home/openxs/dbs/5.7d/bin/mysqld(_Z12write_recordP3THDP5TABLEP9COPY_INFOS4_+0xfee)[0x185cd2e]
/home/openxs/dbs/5.7d/bin/mysqld(_ZN14Sql_cmd_insert12mysql_insertEP3THDP10TABLE_LIST+0xf21)[0x1859b57]
/home/openxs/dbs/5.7d/bin/mysqld(_ZN14Sql_cmd_insert7executeEP3THD+0x19f)[0x1860c6b]
/home/openxs/dbs/5.7d/bin/mysqld(_Z21mysql_execute_commandP3THDb+0x2d7a)[0x1617db1]
/home/openxs/dbs/5.7d/bin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x5d5)[0x161dbfd]
/home/openxs/dbs/5.7d/bin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0xc39)[0x1612b07]
/home/openxs/dbs/5.7d/bin/mysqld(_Z10do_commandP3THD+0x51a)[0x1611996]
/home/openxs/dbs/5.7d/bin/mysqld(handle_connection+0x1ee)[0x17561a1]
/home/openxs/dbs/5.7d/bin/mysqld(pfs_spawn_thread+0x173)[0x1e515e2]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7fab079de6ba]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fab06e7341d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7faab8012710): insert into t1 (b) values (Point(1,1)),(Point(1,1)),(Point(1,1)),(Point(1,1)),(Point(1,1))
Connection ID (thread ID): 3
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
safe_process[7006]: Child process: 7007, killed by signal: 6

while running this test on debug build of MySQL 5.7.29:

openxs@ao756:~/dbs/5.7d/mysql-test$ cat t/marko.test
--source include/have_innodb.inc
--source include/have_debug.inc

SET @save_limit = @@innodb_limit_optimistic_insert_debug;
create table t1(a serial, b geometry not null, spatial index(b)) engine=innodb;
SET GLOBAL innodb_limit_optimistic_insert_debug = 2;
begin;
insert into t1 (b) values (Point(1,1)),(Point(1,1)),(Point(1,1)),(Point(1,1)),(Point(1,1));
rollback;
check table t1;
drop table t1;
SET GLOBAL innodb_limit_optimistic_insert_debug = @save_limit;
openxs@ao756:~/dbs/5.7d/mysql-test$

There is no assertion with 4 rows inserted, FYI.

The test was suggested by Marko. 

How to repeat:
Build 5.7.29 from GitHub source. I've used this cmake:

cmake . -DCMAKE_BUILD_TYPE=RelWithDebInfo -DBUILD_CONFIG=mysql_release -DFEATURE_SET=community -DWITH_EMBEDDED_SERVER=OFF -DDOWNLOAD_BOOST=1 -DWITH_BOOST=/home/openxs/boost -DCMAKE_INSTALL_PREFIX=/home/openxs/dbs/5.7d -DWITH_DEBUG=1

Then make it, make install, create and run the test as shown above. Enjoy.

Suggested fix:
Fix the bug so there is no debug assertion.

Hello Valeriy,

Thank you for the report and test case.
Verified as described on debug builds of 5.7.29/8.0.19.

regards,
Umesh

Test results - 5.7.29

Attachment: 98273_5.7.29.results (application/octet-stream, text), 57.03 KiB.

Test results - 8.0.19

Attachment: 98273_8.0.19.results (application/octet-stream, text), 152.49 KiB.

- Lowest version checked  8.0.11 - affected

 ./mtr --debug-server bug98273
Logging: ./mtr  --debug-server bug98273
2020-01-18T12:49:26.723650Z 0 [System] [MY-010116] [Server] /export/umesh/server/binaries/GABuilds/mysql-8.0.11/bin/mysqld-debug (mysqld 8.0.11-debug) starting as process 1205
MySQL Version 8.0.11
Checking supported features...
 - SSL connections supported
 - binaries are debug compiled
Collecting tests...
Checking leftover processes...
Removing old var directory...
Creating var directory '/export/umesh/server/binaries/GABuilds/mysql-8.0.11/mysql-test/var'...
Installing system database...
Using parallel: 1

==============================================================================

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
main.bug98273                            [ fail ]
        Test ended at 2020-01-18 13:49:48

Server [mysqld.1 - pid: 1262, winpid: 1262, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2020-01-18T12:49:44.781715Z 0 [Warning] [MY-010099] [Server] Insecure configuration for --secure-file-priv: Data directory is accessible through --secure-file-priv. Consider choosing a different directory.
2020-01-18T12:49:44.781809Z 0 [Warning] [MY-010101] [Server] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2020-01-18T12:49:44.781891Z 0 [System] [MY-010116] [Server] /export/umesh/server/binaries/GABuilds/mysql-8.0.11/bin/mysqld-debug (mysqld 8.0.11-debug) starting as process 1263
2020-01-18T12:49:47.542056Z 0 [Warning] [MY-010075] [Server] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 023919de-39f1-11ea-8a93-0010e05f3e06.
2020-01-18T12:49:47.549714Z 0 [Warning] [MY-010068] [Server] CA certificate /export/umesh/server/binaries/GABuilds/mysql-8.0.11/mysql-test/std_data/cacert.pem is self signed.
2020-01-18T12:49:47.715047Z 0 [System] [MY-010931] [Server] /export/umesh/server/binaries/GABuilds/mysql-8.0.11/bin/mysqld-debug: ready for connections. Version: '8.0.11-debug'  socket: '/export/umesh/server/binaries/GABuilds/mysql-8.0.11/mysql-test/var/tmp/mysqld.1.sock'  port: 13000  MySQL Community Server - GPL - Debug.
2020-01-18T12:49:48.417359Z 8 [ERROR] [MY-011825] [InnoDB] InnoDB: [FATAL] Data field type 240, len 10752
2020-01-18T12:49:48.417395Z 8 [ERROR] [MY-000000] [InnoDB] InnoDB: Assertion failure: ut0ut.cc:675

- 5.6.47 No assertion as mtr fails

./mtr --debug-server bug98273
Logging: ./mtr  --debug-server bug98273
2020-01-18 13:51:53 0 [Warning] Insecure configuration for --secure-file-priv: Current value does not restrict location of generated files. Consider setting it to a valid, non-empty path.
2020-01-18 13:51:53 0 [Note] /export/umesh/server/binaries/GABuilds/mysql-5.6.47-linux-glibc2.12-x86_64/bin/mysqld-debug (mysqld 5.6.47-debug) starting as process 1417 ...
2020-01-18 13:51:53 1417 [Note] Plugin 'FEDERATED' is disabled.
2020-01-18 13:51:53 1417 [Note] Binlog end
2020-01-18 13:51:53 1417 [Note] Shutting down plugin 'CSV'
2020-01-18 13:51:53 1417 [Note] Shutting down plugin 'MyISAM'
MySQL Version 5.6.47
Too long tmpdir path '/export/umesh/server/binaries/GABuilds/mysql-5.6.47-linux-glibc2.12-x86_64/mysql-test/var/tmp'  creating a shorter one...
 - using tmpdir: '/tmp/RCVDE36i9s'

Checking supported features...
 - SSL connections supported
 - binaries are debug compiled
Collecting tests...
Removing old var directory...
Creating var directory '/export/umesh/server/binaries/GABuilds/mysql-5.6.47-linux-glibc2.12-x86_64/mysql-test/var'...
Installing system database...
Using parallel: 1

==============================================================================

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
SET @save_limit = @@innodb_limit_optimistic_insert_debug;
main.bug98273                            [ fail ]
        Test ended at 2020-01-18 13:51:57

CURRENT_TEST: main.bug98273
mysqltest: At line 5: query 'create table t1(a serial, b geometry not null, spatial index(b)) engine=innodb' failed: 1464: The used table type doesn't support SPATIAL indexes

 - the logfile can be found in '/export/umesh/server/binaries/GABuilds/mysql-5.6.47-linux-glibc2.12-x86_64/mysql-test/var/log/main.bug98273/bug98273.log'
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 5 seconds executing testcases

Completed: Failed 1/1 tests, 0.00% were successful.

Failing test(s): main.bug98273

The log files in var/log may give you some hint of what went wrong.

If you want to report this error, please read first the documentation
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html

This bug seems fixed in  5.7.32, 8.0.22?