[MDEV-19485] [FATAL] InnoDB: Data field type 0, len 32 in dfield_check_typed, ASAN global-buffer-overflow in rtree_get_geometry_mbr Created: 2019-05-15  Updated: 2019-05-16  Resolved: 2019-05-16

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Alter Table, GIS, Storage Engine - InnoDB
Affects Version/s: 10.4.0
Fix Version/s: 10.4.5

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: regression

Issue Links:
Problem/Incident
is caused by MDEV-15562 Instant DROP COLUMN or changing the o... Closed
Relates
relates to MDEV-19385 InnoDB: Failing assertion: !cursor->i... Closed

 Description   

Run with --repeat=N, big enough N. It usually fails for me within ~40 attempts, but it's not a guarantee.

--source include/have_innodb.inc
 
 
 
CREATE TABLE t1 (g MULTIPOINT NOT NULL) ENGINE=InnoDB;
 
INSERT INTO t1 VALUES ('');
 
DELETE FROM t1;
 
ALTER TABLE t1 ADD SPATIAL INDEX (g);
 
 
 
# Cleanup
 
DROP TABLE t1;

On a non-ASAN debug build:

10.4 30ddf961

 
2019-05-15 17:14:56 4 [ERROR] [FATAL] InnoDB: Data field type 0, len 32
 
190515 17:14:56 [ERROR] mysqld got signal 6 ;
 
 
 
#5  0x00007eff0d2c342a in __GI_abort () at abort.c:89
 
#6  0x0000560e5c64e221 in ib::fatal::~fatal (this=0x7efef17f8da0, __in_chrg=<optimized out>) at /data/src/10.4/storage/innobase/ut/ut0ut.cc:765
 
#7  0x0000560e5c6ea5d5 in dfield_check_typed (field=0x7efed4011230) at /data/src/10.4/storage/innobase/data/data0data.cc:198
 
#8  0x0000560e5c6ea64f in dtuple_check_typed (tuple=0x7efed40111e8) at /data/src/10.4/storage/innobase/data/data0data.cc:221
 
#9  0x0000560e5c5b8039 in row_search_index_entry (index=0x7efebc1ffaa8, entry=0x7efed40111e8, mode=2, pcur=0x7efef17f9020, mtr=0x7efef17f92c0) at /data/src/10.4/storage/innobase/row/row0row.cc:1295
 
#10 0x0000560e5c5adf3e in row_purge_remove_sec_if_poss_leaf (node=0x560e5f71a160, index=0x7efebc1ffaa8, entry=0x7efed40111e8) at /data/src/10.4/storage/innobase/row/row0purge.cc:572
 
#11 0x0000560e5c5ae4b0 in row_purge_remove_sec_if_poss (node=0x560e5f71a160, index=0x7efebc1ffaa8, entry=0x7efed40111e8) at /data/src/10.4/storage/innobase/row/row0purge.cc:695
 
#12 0x0000560e5c5ae6d4 in row_purge_del_mark (node=0x560e5f71a160) at /data/src/10.4/storage/innobase/row/row0purge.cc:769
 
#13 0x0000560e5c5afdb6 in row_purge_record_func (node=0x560e5f71a160, undo_rec=0x560e5f71a628 "", thr=0x560e5f71a0a8, updated_extern=false) at /data/src/10.4/storage/innobase/row/row0purge.cc:1187
 
#14 0x0000560e5c5b00c3 in row_purge (node=0x560e5f71a160, undo_rec=0x560e5f71a628 "", thr=0x560e5f71a0a8) at /data/src/10.4/storage/innobase/row/row0purge.cc:1254
 
#15 0x0000560e5c5b02ba in row_purge_step (thr=0x560e5f71a0a8) at /data/src/10.4/storage/innobase/row/row0purge.cc:1313
 
#16 0x0000560e5c5338d0 in que_thr_step (thr=0x560e5f71a0a8) at /data/src/10.4/storage/innobase/que/que0que.cc:1042
 
#17 0x0000560e5c533b04 in que_run_threads_low (thr=0x560e5f71a0a8) at /data/src/10.4/storage/innobase/que/que0que.cc:1104
 
#18 0x0000560e5c533cf6 in que_run_threads (thr=0x560e5f71a0a8) at /data/src/10.4/storage/innobase/que/que0que.cc:1144
 
#19 0x0000560e5c5edcf0 in srv_task_execute () at /data/src/10.4/storage/innobase/srv/srv0srv.cc:2457
 
#20 0x0000560e5c5edea6 in srv_worker_thread (arg=0x0) at /data/src/10.4/storage/innobase/srv/srv0srv.cc:2505
 
#21 0x00007eff0ee2f4a4 in start_thread (arg=0x7efef17fa700) at pthread_create.c:456
 
#22 0x00007eff0d377d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Reproducible on 10.4, including 10.4.4.
Couldn't reproduce on 10.3, including 10.3.14.

On an ASAN build:

10.4 ASAN 30ddf961

 
==8290==ERROR: AddressSanitizer: global-buffer-overflow on address 0x55a617648985 at pc 0x55a615657f3c bp 0x7fa4d3b09380 sp 0x7fa4d3b09378
 
READ of size 4 at 0x55a617648985 thread T19
 
    #0 0x55a615657f3b in rtree_get_geometry_mbr /data/src/10.4/storage/innobase/gis/gis0geo.cc:210
 
    #1 0x55a615658486 in rtree_mbr_from_wkb(unsigned char const*, unsigned int, unsigned int, double*) /data/src/10.4/storage/innobase/gis/gis0geo.cc:302
 
    #2 0x55a6152e22d2 in row_build_spatial_index_key /data/src/10.4/storage/innobase/row/row0row.cc:167
 
    #3 0x55a6152e266d in row_build_index_entry_low(dtuple_t const*, row_ext_t const*, dict_index_t const*, mem_block_info_t*, unsigned long) /data/src/10.4/storage/innobase/row/row0row.cc:223
 
    #4 0x55a6152d4473 in row_purge_del_mark /data/src/10.4/storage/innobase/row/row0purge.cc:768
 
    #5 0x55a6152d7348 in row_purge_record_func /data/src/10.4/storage/innobase/row/row0purge.cc:1187
 
    #6 0x55a6152d7a08 in row_purge /data/src/10.4/storage/innobase/row/row0purge.cc:1254
 
    #7 0x55a6152d7e36 in row_purge_step(que_thr_t*) /data/src/10.4/storage/innobase/row/row0purge.cc:1313
 
    #8 0x55a6151eff3f in que_thr_step /data/src/10.4/storage/innobase/que/que0que.cc:1042
 
    #9 0x55a6151f0341 in que_run_threads_low /data/src/10.4/storage/innobase/que/que0que.cc:1104
 
    #10 0x55a6151f0689 in que_run_threads(que_thr_t*) /data/src/10.4/storage/innobase/que/que0que.cc:1144
 
    #11 0x55a615348f70 in srv_task_execute /data/src/10.4/storage/innobase/srv/srv0srv.cc:2457
 
    #12 0x55a6153491aa in srv_worker_thread /data/src/10.4/storage/innobase/srv/srv0srv.cc:2505
 
    #13 0x7fa4e6e324a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
 
    #14 0x7fa4e537ad0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
 
 
 
0x55a617648985 is located 59 bytes to the left of global variable 'data_mysql_default_charset_coll' defined in '/data/src/10.4/storage/innobase/data/data0type.cc:41:7' (0x55a6176489c0) of size 8
 
0x55a617648985 is located 4 bytes to the right of global variable 'data_error' defined in '/data/src/10.4/storage/innobase/data/data0data.cc:40:1' (0x55a617648980) of size 1
 
  'data_error' is ascii string ''
 
SUMMARY: AddressSanitizer: global-buffer-overflow /data/src/10.4/storage/innobase/gis/gis0geo.cc:210 in rtree_get_geometry_mbr
 
Shadow bytes around the buggy address:
 
  0x0ab542ec10e0: 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
 
  0x0ab542ec10f0: 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
 
  0x0ab542ec1100: 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
 
  0x0ab542ec1110: 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
 
  0x0ab542ec1120: 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
 
=>0x0ab542ec1130:[01]f9 f9 f9 f9 f9 f9 f9 00 f9 f9 f9 f9 f9 f9 f9
 
  0x0ab542ec1140: 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
 
  0x0ab542ec1150: 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
 
  0x0ab542ec1160: 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
 
  0x0ab542ec1170: 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
 
  0x0ab542ec1180: 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
 
Shadow byte legend (one shadow byte represents 8 application bytes):
 
  Addressable:           00
 
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
 
  Heap right redzone:      fb
 
  Freed heap region:       fd
 
  Stack left redzone:      f1
 
  Stack mid redzone:       f2
 
  Stack right redzone:     f3
 
  Stack partial redzone:   f4
 
  Stack after return:      f5
 
  Stack use after scope:   f8
 
  Global redzone:          f9
 
  Global init order:       f6
 
  Poisoned by user:        f7
 
  Container overflow:      fc
 
  Array cookie:            ac
 
  Intra object redzone:    bb
 
  ASan internal:           fe
 
  Left alloca redzone:     ca
 
  Right alloca redzone:    cb
 
Thread T19 created by T0 here:
 
    #0 0x7fa4e7078f59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
 
    #1 0x55a61519f558 in os_thread_create_func(void* (*)(void*), void*, unsigned long*) /data/src/10.4/storage/innobase/os/os0thread.cc:132
 
    #2 0x55a615357213 in srv_start(bool) /data/src/10.4/storage/innobase/srv/srv0start.cc:2309
 
    #3 0x55a614fd245f in innodb_init /data/src/10.4/storage/innobase/handler/ha_innodb.cc:4269
 
    #4 0x55a614ac0ea8 in ha_initialize_handlerton(st_plugin_int*) /data/src/10.4/sql/handler.cc:531
 
    #5 0x55a6143bbce5 in plugin_initialize /data/src/10.4/sql/sql_plugin.cc:1437
 
    #6 0x55a6143bd53f in plugin_init(int*, char**, int) /data/src/10.4/sql/sql_plugin.cc:1719
 
    #7 0x55a6140f1389 in init_server_components /data/src/10.4/sql/mysqld.cc:5181
 
    #8 0x55a6140f318c in mysqld_main(int, char**) /data/src/10.4/sql/mysqld.cc:5704
 
    #9 0x55a6140ddfaf in main /data/src/10.4/sql/main.cc:25
 
    #10 0x7fa4e52b22e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)

Couldn't reproduce on current 10.3. Didn't try 10.4.4 or older 10.3.

I'm not sure whether these two failures are related. If not, please feel free to split the bug report into two.

 Comments   
Comment by Marko Mäkelä [ 2019-05-16 ]

I can repeat the ASAN failure.
The merge of MDEV-19385 into 10.3 touched row_build_spatial_index_key() recently, but it should have been mostly non-functional refactoring.

Comment by Marko Mäkelä [ 2019-05-16 ]

The two errors can be related. This looks like an uninitialized data field:

#10 0x00005578267e628e in rtree_get_geometry_mbr (wkb=0x7fbd361a2580, 
    end=0x557928fdf61f <error: Cannot access memory at address 0x557928fdf61f>, n_dims=<optimized out>, mbr=<optimized out>, top=0)
 
    at /mariadb/10.4/storage/innobase/gis/gis0geo.cc:210
 
(gdb) p *wkb
 
$1 = (const uchar *) 0x557828fdf624 <data_error+4> ""

The data_error is a sentinel byte for debug builds that is now helping AddressSanitizer catch the error. In row_build_spatial_index_key(), we seem to have dptr = data_error coming from here:

	if (!dfield_is_ext(dfield2)) {
 
		dptr = static_cast<const byte*>(dfield_get_data(dfield2));
 
		dlen = dfield_get_len(dfield2);
 
		goto write_mbr;
 
	}

Notably, we have dfield_is_null(dfield2) (even though SPATIAL INDEX should never be allowed on NULL columns) and are yet proceeding to the purge:

(gdb) p *dfield2
 
$3 = {data = 0x557828fdf620 <data_error>, ext = 0, spatial_status = 2, 
  len = 4294967295, type = {prtype = 111, mtype = 0, len = 42405, 
    mbminlen = 5, mbmaxlen = 4}}

Here is a deterministic test case. It fails to repeat the problem for 10.2 for me.

--source include/have_innodb.inc
 
 
 
SET @saved_frequency = @@GLOBAL.innodb_purge_rseg_truncate_frequency;
 
SET GLOBAL innodb_purge_rseg_truncate_frequency = 1;
 
 
 
CREATE TABLE t1 (g MULTIPOINT NOT NULL) ENGINE=InnoDB;
 
INSERT INTO t1 VALUES ('');
 
 
 
connect purge_control,localhost,root;
 
START TRANSACTION WITH CONSISTENT SNAPSHOT;
 
connection default;
 
 
 
DELETE FROM t1;
 
 
 
ALTER TABLE t1 ADD SPATIAL INDEX (g);
 
 
 
disconnect purge_control;
 
--source ../../innodb/include/wait_all_purged.inc
 
DROP TABLE t1;
 
SET GLOBAL innodb_purge_rseg_truncate_frequency = @saved_frequency;

In 10.3, some code was refactored into a new function row_build_spatial_index_key(). The above test will not fail for me on 10.3 either.

Comment by Marko Mäkelä [ 2019-05-16 ]

In purge, in the table row (node->row) over (g,DB_ROW_ID,DB_TRX_ID,DB_ROLL_PTR), the value of the column g is undefined (data=&data_error, len=~0U). The secondary index is empty, just like expected. The clustered index contains the following delete-marking record that is awaiting purge:
(DB_ROW_ID,DB_TRX_ID,DB_ROLL_PTR,g)=(0x200,0x26,(update),'')

The data_error must be there because the data was simply not available to row_purge_parse_undo_rec() in the undo_rec. We still need to figure out how to fix this, and why 10.2 or 10.3 did not crash or report anything.

Comment by Marko Mäkelä [ 2019-05-16 ]

Both incarnations of the problem share a common root cause. The "data field type 0" is the magic value DATA_MISSING, which 10.4 fails to check before the function call row_build_spatial_index_key() due to some code refactoring in row_build_index_entry_low() as part of MDEV-15562.

Generated at Thu Feb 08 08:52:03 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.