[MDEV-22551] Server crashes in skip_trailing_space upon ANALYZE on table with long unique, or Assertion `marked_for_read()' fails Created: 2020-05-13  Updated: 2022-02-22

Status: Stalled
Project: MariaDB Server
Component/s: Admin statements, Character Sets, Optimizer, Server
Affects Version/s: 10.4, 10.5
Fix Version/s: 10.4, 10.5

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergei Golubchik
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-21804 Assertion `marked_for_read()' failed ... Closed

 Description   

Note: Technically there are no virtual columns in the scenario, so it's blamed upon the next component in line (unique blobs), but given the existing marked_for_read bugs with virtual columns, this one may end up there as well.

--source include/have_innodb.inc
 
CREATE TABLE t1 (id INT, f TEXT UNIQUE, d DATE, PRIMARY KEY (id)) ENGINE=InnoDB;
INSERT INTO t1 VALUES
    (1,NULL,'2001-11-16'),(2,NULL,'2007-07-01'),(3,NULL,'2020-02-03'),
    (4,NULL,'1971-05-24'),(5,NULL,'1971-05-24'),(6,NULL,'1985-02-07');
 
ANALYZE TABLE t1 PERSISTENT FOR ALL;
 
# Cleanup
DROP TABLE t1;

On a non-debug build, the SIGSEGV is sporadic, run with --repeat. Alternatively, a build with RelWithDebInfo and ASAN can be used. It fails with SEGV the same way, but seemingly deterministically.

10.4 f544a712 RelWithDebInfo (normal build, without ASAN)

#3  <signal handler called>
#4  0x000055f366a6ff19 in skip_trailing_space (len=<optimized out>, ptr=0x7f8cf8 <error: Cannot access memory at address 0x7f8cf8>) at /data/src/10.5/strings/strings_def.h:95
#5  my_hash_sort_simple (cs=0x55f367498dc0 <my_charset_latin1>, key=0x7f8cf8 <error: Cannot access memory at address 0x7f8cf8>, len=<optimized out>, nr1=0x7f8d2814c650, nr2=0x7f8d2814c658) at /data/src/10.5/strings/ctype-simple.c:367
#6  0x000055f36653dc82 in charset_info_st::hash_sort (nr2=0x7f8d2814c658, nr1=0x7f8d2814c650, len=<optimized out>, key=<optimized out>, this=<optimized out>) at /data/src/10.5/include/m_ctype.h:834
#7  calc_hash_for_unique (str=0x7f8cf8ab2078, nr2=@0x7f8d2814c658: 16, nr1=@0x7f8d2814c650: 10044593846) at /data/src/10.5/sql/item_func.cc:1745
#8  Item_func_hash::val_int (this=0x7f8cf8aa3668) at /data/src/10.5/sql/item_func.cc:1762
#9  0x000055f366509026 in Item::save_int_in_field (this=0x7f8cf8aa3668, field=0x7f8cf8aa33b0, no_conversions=<optimized out>) at /data/src/10.5/sql/item.cc:6559
#10 0x000055f3664fc54c in Item::save_in_field (this=0x7f8cf8aa3668, field=0x7f8cf8aa33b0, no_conversions=<optimized out>) at /data/src/10.5/sql/item.cc:6569
#11 0x000055f3663c0ccc in TABLE::update_virtual_fields (this=0x7f8cf806c998, h=h@entry=0x7f8cf80e8ed0, update_mode=update_mode@entry=VCOL_UPDATE_FOR_READ) at /data/src/10.5/sql/table.cc:8489
#12 0x000055f3664ecd76 in handler::ha_rnd_next (this=this@entry=0x7f8cf80e8ed0, buf=0x7f8cf8aa2fb8 "\004\006") at /data/src/10.5/sql/handler.cc:3006
#13 0x000055f36637df63 in collect_statistics_for_table (thd=thd@entry=0x7f8cf80009b8, table=0x7f8cf806c998) at /data/src/10.5/sql/sql_statistics.cc:2761
#14 0x000055f3663f7ad0 in mysql_admin_table (thd=thd@entry=0x7f8cf80009b8, tables=tables@entry=0x7f8cf80103e8, check_opt=check_opt@entry=0x7f8cf8005aa0, operator_name=operator_name@entry=0x55f366af37f2 "analyze", lock_type=lock_type@entry=TL_READ_NO_INSERT, org_open_for_modify=org_open_for_modify@entry=true, repair_table_use_frm=false, extra_open_options=0, prepare_func=0x0, operator_func=<optimized out>, view_operator_func=0x0) at /data/src/10.5/sql/sql_admin.cc:886
#15 0x000055f3663f80ed in Sql_cmd_analyze_table::execute (this=<optimized out>, thd=0x7f8cf80009b8) at /data/src/10.5/sql/sql_admin.cc:1316
#16 0x000055f366308238 in mysql_execute_command (thd=thd@entry=0x7f8cf80009b8) at /data/src/10.5/sql/sql_parse.cc:5912
#17 0x000055f36630f1cb in mysql_parse (thd=thd@entry=0x7f8cf80009b8, rawbuf=<optimized out>, length=35, parser_state=parser_state@entry=0x7f8d2814d550, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.5/sql/sql_parse.cc:7957
#18 0x000055f366304d9d in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f8cf80009b8, packet=packet@entry=0x7f8cf8007c69 "", packet_length=packet_length@entry=35, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.5/sql/sql_parse.cc:1840
#19 0x000055f3663031f1 in do_command (thd=0x7f8cf80009b8) at /data/src/10.5/sql/sql_parse.cc:1359
#20 0x000055f3663ead84 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55f36a30ff38, put_in_cache=put_in_cache@entry=true) at /data/src/10.5/sql/sql_connect.cc:1422
#21 0x000055f3663eb083 in handle_one_connection (arg=arg@entry=0x55f36a30ff38) at /data/src/10.5/sql/sql_connect.cc:1319
#22 0x000055f366705454 in pfs_spawn_thread (arg=0x55f36a2cf5e8) at /data/src/10.5/storage/perfschema/pfs.cc:2201
#23 0x00007f8d2e5ae4a4 in start_thread (arg=0x7f8d2814e700) at pthread_create.c:456
#24 0x00007f8d2c6e2d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

10.5 debug build currently fails every time for me on the assertion:

10.5 0186b0a0

mariadbd: /data/src/10.5/sql/field.cc:8434: virtual String* Field_blob::val_str(String*, String*): Assertion `marked_for_read()' failed.
200513 21:20:55 [ERROR] mysqld got signal 6 ;
 
#6  0x00007efc71df3e67 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x55e56b7ba168 "marked_for_read()", file=file@entry=0x55e56b7b9fa3 "/data/src/10.5/sql/field.cc", line=line@entry=8434, function=function@entry=0x55e56b7bf5c0 <Field_blob::val_str(String*, String*)::__PRETTY_FUNCTION__> "virtual String* Field_blob::val_str(String*, String*)") at assert.c:92
#7  0x00007efc71df3f12 in __GI___assert_fail (assertion=0x55e56b7ba168 "marked_for_read()", file=0x55e56b7b9fa3 "/data/src/10.5/sql/field.cc", line=8434, function=0x55e56b7bf5c0 <Field_blob::val_str(String*, String*)::__PRETTY_FUNCTION__> "virtual String* Field_blob::val_str(String*, String*)") at assert.c:101
#8  0x000055e56ab744d1 in Field_blob::val_str (this=0x7efc3c009b38, val_buffer=0x7efc3c21db88, val_ptr=0x7efc3c21db88) at /data/src/10.5/sql/field.cc:8434
#9  0x000055e56abbee0e in Item_field::val_str (this=0x7efc3c21db50, str=0x7efc3c21db88) at /data/src/10.5/sql/item.cc:3187
#10 0x000055e56a8dc9ae in Item::val_str (this=0x7efc3c21db50) at /data/src/10.5/sql/item.h:914
#11 0x000055e56ac22143 in Item_func_hash::val_int (this=0x7efc3c00a488) at /data/src/10.5/sql/item_func.cc:1756
#12 0x000055e56abc9324 in Item::save_int_in_field (this=0x7efc3c00a488, field=0x7efc3c00a1d0, no_conversions=false) at /data/src/10.5/sql/item.cc:6559
#13 0x000055e56aa808d6 in Type_handler_int_result::Item_save_in_field (this=0x55e56c3e19e0 <type_handler_slong>, item=0x7efc3c00a488, field=0x7efc3c00a1d0, no_conversions=false) at /data/src/10.5/sql/sql_type.cc:4205
#14 0x000055e56abc93d1 in Item::save_in_field (this=0x7efc3c00a488, field=0x7efc3c00a1d0, no_conversions=false) at /data/src/10.5/sql/item.cc:6569
#15 0x000055e56a98efe9 in TABLE::update_virtual_fields (this=0x7efc3c0fa688, h=0x7efc3c0fb500, update_mode=VCOL_UPDATE_FOR_READ) at /data/src/10.5/sql/table.cc:8489
#16 0x000055e56ab9d28e in handler::ha_rnd_next (this=0x7efc3c0fb500, buf=0x7efc3c0099f8 ",\006") at /data/src/10.5/sql/handler.cc:3006
#17 0x000055e56a919b82 in collect_statistics_for_table (thd=0x7efc3c000b18, table=0x7efc3c0fa688) at /data/src/10.5/sql/sql_statistics.cc:2761
#18 0x000055e56a9f5816 in mysql_admin_table(THD *, TABLE_LIST *, HA_CHECK_OPT *, const char *, thr_lock_type, bool, bool, uint, int (*)(THD *, TABLE_LIST *, HA_CHECK_OPT *), struct {...}, int (*)(THD *, TABLE_LIST *, HA_CHECK_OPT *)) (thd=0x7efc3c000b18, tables=0x7efc3c013a38, check_opt=0x7efc3c005dc0, operator_name=0x55e56b647237 "analyze", lock_type=TL_READ_NO_INSERT, org_open_for_modify=true, repair_table_use_frm=false, extra_open_options=0, prepare_func=0x0, operator_func=(int (handler::*)(handler * const, THD *, HA_CHECK_OPT *)) 0x55e56aba32ae <handler::ha_analyze(THD*, st_ha_check_opt*)>, view_operator_func=0x0) at /data/src/10.5/sql/sql_admin.cc:886
#19 0x000055e56a9f7218 in Sql_cmd_analyze_table::execute (this=0x7efc3c014110, thd=0x7efc3c000b18) at /data/src/10.5/sql/sql_admin.cc:1316
#20 0x000055e56a84a56e in mysql_execute_command (thd=0x7efc3c000b18) at /data/src/10.5/sql/sql_parse.cc:5912
#21 0x000055e56a8508f2 in mysql_parse (thd=0x7efc3c000b18, rawbuf=0x7efc3c013950 "ANALYZE TABLE t1 PERSISTENT FOR ALL", length=35, parser_state=0x7efc6c37b520, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:7957
#22 0x000055e56a83cbfa in dispatch_command (command=COM_QUERY, thd=0x7efc3c000b18, packet=0x7efc3c1b14b9 "", packet_length=35, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1840
#23 0x000055e56a83b38c in do_command (thd=0x7efc3c000b18) at /data/src/10.5/sql/sql_parse.cc:1359
#24 0x000055e56a9de915 in do_handle_one_connection (connect=0x55e56e3a6608, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1411
#25 0x000055e56a9de67d in handle_one_connection (arg=0x55e56e3a6608) at /data/src/10.5/sql/sql_connect.cc:1313
#26 0x000055e56af140ba in pfs_spawn_thread (arg=0x55e56e32f618) at /data/src/10.5/storage/perfschema/pfs.cc:2201
#27 0x00007efc73d7c4a4 in start_thread (arg=0x7efc6c37c700) at pthread_create.c:456
#28 0x00007efc71eb0d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

However, it may be just luck, because 10.4 debug (which also almost always fails) happened to pass a few times.

The test case is not applicable to 10.3 due to the unique blob.

Note: We have several open bugs for the failing marked_for_read assertion, but none of them has a non-debug version of the failure, and those that I re-checked on a non-debug ASAN build didn't fail there either.



 Comments   
Comment by Sachin Setiya (Inactive) [ 2020-05-25 ]

Patch Branch bb-10.4-sachin2

Comment by Roel Van de Paar [ 2020-06-13 ]

sachin.setiya.007 Did this fix make it into the tree? Thanks

Comment by Sachin Setiya (Inactive) [ 2021-02-20 ]

Hi Roel I recieved Serg review , I need to change the patch.

Comment by Sachin Setiya (Inactive) [ 2021-02-26 ]

This also fails

--source include/have_innodb.inc
 
CREATE TABLE t1 (id INT, f TEXT UNIQUE, d DATE, PRIMARY KEY (id)) ENGINE=myisam;
INSERT INTO t1 VALUES
    (1,"d",'2001-11-16'),(2,"e",'2007-07-01'),(3,"f",'2020-02-03'),
    (4,"c",'1971-05-24'),(5,"b",'1971-05-24'),(6,"a",'1985-02-07');
ANALYZE TABLE t1 PERSISTENT FOR ALL;
 
# Cleanup
DROP TABLE t1;
 

So for the case where it passes
Field_blob(f)->is_null() is true

and where it fails
Field_blob(f)->is_null() is false so then

│   3243        String *Item_field::val_str(String *str)                                                                      │
│   3244        {                                                                                                             │
│   3245          DBUG_ASSERT(fixed == 1);                                                                                    │
│   3246          if ((null_value=field->is_null()))                                                                          │
│   3247            return 0;                                                                                                 │
│   3248          str->set_charset(str_value.charset());                                                                      │
│  >3249          return field->val_str(str,&str_value);                                                                      │
│   3250        }

so field->val_str() is called on field without table->read_set being set
(it is not set because it is blob field )
in mysql_admin_table

          for (uint fields= 0; *field_ptr; field_ptr++, fields++)
          {
            enum enum_field_types type= (*field_ptr)->type();
            if (type < MYSQL_TYPE_MEDIUM_BLOB ||
                type > MYSQL_TYPE_BLOB)
              bitmap_set_bit(tab->read_set, fields);

Generated at Thu Feb 08 09:15:35 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.