[MDEV-31485] SIGSEGV in PROF_MEASUREMENT::~PROF_MEASUREMENT | QUERY_PROFILE::~QUERY_PROFILE Created: 2023-06-16  Updated: 2023-11-28

Status: Stalled
Project: MariaDB Server
Component/s: OTHER
Affects Version/s: 10.4, 10.5, 10.6, 10.9, 10.10, 10.11, 11.0, 11.1
Fix Version/s: 10.4, 10.5, 10.6, 10.11, 11.0, 11.1

Type: Bug Priority: Critical
Reporter: Ramesh Sivaraman Assignee: Oleksandr Byelkin
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Duplicate
duplicates MDEV-17711 Assertion `arena_for_set_stmt== 0' fa... Closed

 Description   

CREATE TABLE t (c INT) ENGINE=MyISAM UNION=(t,t0) INSERT_METHOD=FIRST;
INSERT INTO t VALUES (0);
SET SESSION profiling=ON;
SELECT * INTO outfile 'a' FROM t;
DROP TABLE t;
CREATE TABLE t (a INT GENERATED ALWAYS AS (0) VIRTUAL,KEY(a)) ENGINE=MyISAM;
LOAD DATA INFILE 'a' REPLACE INTO TABLE t;
CREATE TABLE t0 (a INT) ENGINE=MyISAM;
UPDATE t SET a=0;

Leads to:

11.1.0 17127fd91b763ba7c3f8ecb30190689a06bd9485 (Optimized)

Core was generated by `/test/MD060623-mariadb-11.1.0-linux-x86_64-opt/bin/mariadbd --no-defaults --cor'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x000055d910ea7625 in PROF_MEASUREMENT::~PROF_MEASUREMENT (
    this=0x150000000040, __in_chrg=<optimized out>)
    at /test/11.1_opt/sql/sql_profile.cc:184
[Current thread is 1 (Thread 0x151dbc051700 (LWP 1462580))]
(gdb) bt
#0  0x000055d910ea7625 in PROF_MEASUREMENT::~PROF_MEASUREMENT (this=0x150000000040, __in_chrg=<optimized out>) at /test/11.1_opt/sql/sql_profile.cc:184
#1  0x000055d910ea79c8 in QUERY_PROFILE::~QUERY_PROFILE (this=0x151d84067700, __in_chrg=<optimized out>) at /test/11.1_opt/sql/sql_profile.cc:280
#2  0x000055d910ea7cf0 in PROFILING::restart (this=0x151d840047a0) at /test/11.1_opt/sql/sql_profile.cc:348
#3  0x000055d910d2be1f in THD::free_connection (this=<optimized out>) at /test/11.1_opt/sql/sql_class.cc:1609
#4  0x000055d910c79906 in unlink_thd (thd=<optimized out>) at /test/11.1_opt/sql/mysqld.cc:2840
#5  0x000055d910ea4c51 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55d913ad0ee8, put_in_cache=put_in_cache@entry=true) at /test/11.1_opt/sql/sql_connect.cc:1427
#6  0x000055d910ea511d in handle_one_connection (arg=0x55d913ad0ee8) at /test/11.1_opt/sql/sql_connect.cc:1318
#7  0x0000151dd3d1f609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#8  0x0000151dd390b133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

11.1.0 17127fd91b763ba7c3f8ecb30190689a06bd9485 (Debug)

Core was generated by `/test/MD060623-mariadb-11.1.0-linux-x86_64-dbg/bin/mariadbd --no-defaults --cor'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  PROF_MEASUREMENT::~PROF_MEASUREMENT (this=0x1500000000d0, 
    __in_chrg=<optimized out>) at /test/11.1_dbg/sql/sql_profile.cc:184
[Current thread is 1 (Thread 0x1523a4629700 (LWP 1462658))]
(gdb) bt
#0  PROF_MEASUREMENT::~PROF_MEASUREMENT (this=0x1500000000d0, __in_chrg=<optimized out>) at /test/11.1_dbg/sql/sql_profile.cc:184
#1  0x00005587e0d51da0 in QUERY_PROFILE::~QUERY_PROFILE (this=0x15236c024460, __in_chrg=<optimized out>) at /test/11.1_dbg/sql/sql_profile.h:147
#2  0x00005587e0d520e2 in PROFILING::restart (this=this@entry=0x15236c004a48) at /test/11.1_dbg/sql/sql_profile.h:147
#3  0x00005587e0b80bea in THD::free_connection (this=this@entry=0x15236c000d48) at /test/11.1_dbg/sql/sql_class.cc:1609
#4  0x00005587e0abaf1e in unlink_thd (thd=0x15236c000d48) at /test/11.1_dbg/sql/mysqld.cc:2840
#5  0x00005587e0d4dcd3 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5587e497c9c8, put_in_cache=put_in_cache@entry=true) at /test/11.1_dbg/sql/sql_connect.cc:1427
#6  0x00005587e0d4dfd6 in handle_one_connection (arg=0x5587e497c9c8) at /test/11.1_dbg/sql/sql_connect.cc:1318
#7  0x00001523bd2e0609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#8  0x00001523bcecc133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.4.30 (dbg), 10.4.30 (opt), 10.5.21 (dbg), 10.5.21 (opt), 10.6.14 (dbg), 10.6.14 (opt), 10.9.7 (dbg), 10.9.7 (opt), 10.10.5 (dbg), 10.10.5 (opt), 10.11.4 (dbg), 10.11.4 (opt), 11.0.2 (dbg), 11.0.2 (opt), 11.1.0 (dbg), 11.1.0 (opt)



 Comments   
Comment by Oleksandr Byelkin [ 2023-09-25 ]

With UBSAN/ASAN there is other problem (also looks like connected t profiling, i.e. it is not repeatable without it)

mysqltest: At line 9: query 'UPDATE t SET a=0' failed: 2013: Lost connection to MySQL server during query
 
 
Server [mysqld.1 - pid: 90995, winpid: 90995, exit: 0] failed during test run
Server log from this test:
----------SERVER LOG START-----------
$ ddd --command /home/sanja/maria/git/10.4/mysql-test/var/tmp/dddinit.mysqld.1 /home/sanja/maria/git/10.4/sql/mysqld
2023-09-25 11:15:25 0 [Note] Starting MariaDB 10.4.32-MariaDB-debug-log source revision b6773f58196d74e0a0be83b4499fcb82799e1144 as process 91015
2023-09-25 11:15:25 0 [Note] Plugin 'partition' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'SEQUENCE' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'InnoDB' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_LOCKS' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_CMPMEM' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_CMP_PER_INDEX' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_CMP' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_BUFFER_PAGE_LRU' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'FEEDBACK' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'user_variables' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_SYS_FOREIGN_COLS' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_BUFFER_POOL_STATS' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_TRX' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_SYS_FOREIGN' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_SYS_TABLES' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_BUFFER_PAGE' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_METRICS' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_SYS_VIRTUAL' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
2023-09-25 11:15:25 0 [Note] Plugin 'unix_socket' is disabled.
2023-09-25 11:15:25 0 [Warning] /home/sanja/maria/git/10.4/sql/mysqld: unknown option '--loose-pam-debug'
2023-09-25 11:15:25 0 [Warning] /home/sanja/maria/git/10.4/sql/mysqld: unknown option '--loose-aria'
2023-09-25 11:15:25 0 [Note] Server socket created on IP: '127.0.0.1'.
2023-09-25 11:15:25 0 [Note] Reading of all Master_info entries succeeded
2023-09-25 11:15:25 0 [Note] Added new Master_info '' to hash table
2023-09-25 11:15:25 0 [Note] /home/sanja/maria/git/10.4/sql/mysqld: ready for connections.
Version: '10.4.32-MariaDB-debug-log'  socket: '/home/sanja/maria/git/10.4/mysql-test/var/tmp/mysqld.1.sock'  port: 16000  Source distribution
=================================================================
==91015==ERROR: AddressSanitizer: heap-use-after-free on address 0x604000025818 at pc 0x55556077ebbf bp 0x7fffedfa9d50 sp 0x7fffedfa9d40
READ of size 1 at 0x604000025818 thread T5
    #0 0x55556077ebbe in Field::set_notnull(long long) /home/sanja/maria/git/10.4/sql/field.h:1211
    #1 0x55556275004a in save_int_value_in_field /home/sanja/maria/git/10.4/sql/item.cc:6794
    #2 0x555562750588 in Item_int::save_in_field(Field*, bool) /home/sanja/maria/git/10.4/sql/item.cc:6801
    #3 0x5555617d211c in TABLE::update_virtual_fields(handler*, enum_vcol_update_mode) /home/sanja/maria/git/10.4/sql/table.cc:8590
    #4 0x5555625e064e in handler::ha_rnd_next(unsigned char*) /home/sanja/maria/git/10.4/sql/handler.cc:2920
    #5 0x5555634145b5 in rr_sequential(READ_RECORD*) /home/sanja/maria/git/10.4/sql/records.cc:485
    #6 0x555560a141f4 in READ_RECORD::read_record() /home/sanja/maria/git/10.4/sql/records.h:70
    #7 0x5555616a7d5f in mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, bool, unsigned long long*, unsigned long long*) /home/sanja/maria/git/10.4/sql/sql_update.cc:1006
    #8 0x555560f1865b in mysql_execute_command(THD*) /home/sanja/maria/git/10.4/sql/sql_parse.cc:4451
    #9 0x555560f64caf in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /home/sanja/maria/git/10.4/sql/sql_parse.cc:8012
    #10 0x555560ee188e in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /home/sanja/maria/git/10.4/sql/sql_parse.cc:1857
    #11 0x555560ed5a61 in do_command(THD*) /home/sanja/maria/git/10.4/sql/sql_parse.cc:1378
    #12 0x5555619705a6 in do_handle_one_connection(CONNECT*) /home/sanja/maria/git/10.4/sql/sql_connect.cc:1420
    #13 0x55556196f03e in handle_one_connection /home/sanja/maria/git/10.4/sql/sql_connect.cc:1324
    #14 0x555563f4f540 in pfs_spawn_thread /home/sanja/maria/git/10.4/storage/perfschema/pfs.cc:1869
    #15 0x7ffff708f189 in start_thread nptl/pthread_create.c:444
    #16 0x7ffff711dbcf in clone3 ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
 
0x604000025818 is located 8 bytes inside of 40-byte region [0x604000025810,0x604000025838)
freed by thread T5 here:
    #0 0x555560635570 in __interceptor_free.part.0 (/home/sanja/maria/git/10.4/sql/mysqld+0xb0e1570)
    #1 0x5555653bb519 in my_free /home/sanja/maria/git/10.4/mysys/my_malloc.c:222
    #2 0x555565111274 in mi_repair_by_sort /home/sanja/maria/git/10.4/storage/myisam/mi_check.c:2559
    #3 0x5555650bb445 in ha_myisam::repair(THD*, st_handler_check_param&, bool) /home/sanja/maria/git/10.4/storage/myisam/ha_myisam.cc:1344
    #4 0x5555650c3c54 in ha_myisam::enable_indexes(unsigned int) /home/sanja/maria/git/10.4/storage/myisam/ha_myisam.cc:1683
    #5 0x5555650c85c1 in ha_myisam::end_bulk_insert() /home/sanja/maria/git/10.4/storage/myisam/ha_myisam.cc:1878
    #6 0x55556260e032 in handler::ha_end_bulk_insert() /home/sanja/maria/git/10.4/sql/handler.cc:4491
    #7 0x555560e94a57 in mysql_load(THD*, sql_exchange const*, TABLE_LIST*, List<Item>&, List<Item>&, List<Item>&, enum_duplicates, bool, bool) /home/sanja/maria/git/10.4/sql/sql_load.cc:681
    #8 0x555560f27324 in mysql_execute_command(THD*) /home/sanja/maria/git/10.4/sql/sql_parse.cc:5034
    #9 0x555560f64caf in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /home/sanja/maria/git/10.4/sql/sql_parse.cc:8012
    #10 0x555560ee188e in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /home/sanja/maria/git/10.4/sql/sql_parse.cc:1857
    #11 0x555560ed5a61 in do_command(THD*) /home/sanja/maria/git/10.4/sql/sql_parse.cc:1378
    #12 0x5555619705a6 in do_handle_one_connection(CONNECT*) /home/sanja/maria/git/10.4/sql/sql_connect.cc:1420
    #13 0x55556196f03e in handle_one_connection /home/sanja/maria/git/10.4/sql/sql_connect.cc:1324
    #14 0x555563f4f540 in pfs_spawn_thread /home/sanja/maria/git/10.4/storage/perfschema/pfs.cc:1869
    #15 0x7ffff708f189 in start_thread nptl/pthread_create.c:444
 
previously allocated by thread T5 here:
    #0 0x555560636a1f in malloc (/home/sanja/maria/git/10.4/sql/mysqld+0xb0e2a1f)
    #1 0x5555653ba79a in my_malloc /home/sanja/maria/git/10.4/mysys/my_malloc.c:101
    #2 0x5555653bad6e in my_realloc /home/sanja/maria/git/10.4/mysys/my_malloc.c:155
    #3 0x5555651ba188 in mi_alloc_rec_buff /home/sanja/maria/git/10.4/storage/myisam/mi_open.c:762
    #4 0x55556510a96f in mi_repair_by_sort /home/sanja/maria/git/10.4/storage/myisam/mi_check.c:2240
    #5 0x5555650bb445 in ha_myisam::repair(THD*, st_handler_check_param&, bool) /home/sanja/maria/git/10.4/storage/myisam/ha_myisam.cc:1344
    #6 0x5555650c3c54 in ha_myisam::enable_indexes(unsigned int) /home/sanja/maria/git/10.4/storage/myisam/ha_myisam.cc:1683
    #7 0x5555650c85c1 in ha_myisam::end_bulk_insert() /home/sanja/maria/git/10.4/storage/myisam/ha_myisam.cc:1878
    #8 0x55556260e032 in handler::ha_end_bulk_insert() /home/sanja/maria/git/10.4/sql/handler.cc:4491
    #9 0x555560e94a57 in mysql_load(THD*, sql_exchange const*, TABLE_LIST*, List<Item>&, List<Item>&, List<Item>&, enum_duplicates, bool, bool) /home/sanja/maria/git/10.4/sql/sql_load.cc:681
    #10 0x555560f27324 in mysql_execute_command(THD*) /home/sanja/maria/git/10.4/sql/sql_parse.cc:5034
    #11 0x555560f64caf in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /home/sanja/maria/git/10.4/sql/sql_parse.cc:8012
    #12 0x555560ee188e in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /home/sanja/maria/git/10.4/sql/sql_parse.cc:1857
    #13 0x555560ed5a61 in do_command(THD*) /home/sanja/maria/git/10.4/sql/sql_parse.cc:1378
    #14 0x5555619705a6 in do_handle_one_connection(CONNECT*) /home/sanja/maria/git/10.4/sql/sql_connect.cc:1420
    #15 0x55556196f03e in handle_one_connection /home/sanja/maria/git/10.4/sql/sql_connect.cc:1324
    #16 0x555563f4f540 in pfs_spawn_thread /home/sanja/maria/git/10.4/storage/perfschema/pfs.cc:1869
    #17 0x7ffff708f189 in start_thread nptl/pthread_create.c:444
 
Thread T5 created by T0 here:
    #0 0x5555605c20a5 in __interceptor_pthread_create (/home/sanja/maria/git/10.4/sql/mysqld+0xb06e0a5)
    #1 0x555563f4fdc7 in spawn_thread_v1 /home/sanja/maria/git/10.4/storage/perfschema/pfs.cc:1919
    #2 0x555560685348 in inline_mysql_thread_create /home/sanja/maria/git/10.4/include/mysql/psi/mysql_thread.h:1275
    #3 0x5555606aacdc in create_thread_to_handle_connection(CONNECT*) /home/sanja/maria/git/10.4/sql/mysqld.cc:6289
    #4 0x5555606abee4 in create_new_thread(CONNECT*) /home/sanja/maria/git/10.4/sql/mysqld.cc:6359
    #5 0x5555606ac941 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /home/sanja/maria/git/10.4/sql/mysqld.cc:6457
    #6 0x5555606ae22e in handle_connections_sockets() /home/sanja/maria/git/10.4/sql/mysqld.cc:6615
    #7 0x5555606aa094 in mysqld_main(int, char**) /home/sanja/maria/git/10.4/sql/mysqld.cc:5947
    #8 0x555560681cd3 in main /home/sanja/maria/git/10.4/sql/main.cc:25
    #9 0x7ffff7023a8f in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58
 
SUMMARY: AddressSanitizer: heap-use-after-free /home/sanja/maria/git/10.4/sql/field.h:1211 in Field::set_notnull(long long)
Shadow bytes around the buggy address:
  0x0c087fffcab0: fa fa 00 00 00 00 00 00 fa fa 00 00 00 00 00 00
  0x0c087fffcac0: fa fa 00 00 00 00 00 00 fa fa 00 00 00 00 00 fa
  0x0c087fffcad0: fa fa 00 00 00 00 00 fa fa fa 00 00 00 00 00 fa
  0x0c087fffcae0: fa fa 00 00 00 00 00 fa fa fa 00 00 00 00 00 00
  0x0c087fffcaf0: fa fa 00 00 00 00 00 00 fa fa 00 00 00 00 00 00
=>0x0c087fffcb00: fa fa fd[fd]fd fd fd fa fa fa fd fd fd fd fd fa
  0x0c087fffcb10: fa fa 00 00 00 00 00 00 fa fa 00 00 00 00 00 00
  0x0c087fffcb20: fa fa 00 00 00 00 00 00 fa fa 00 00 00 00 00 00
  0x0c087fffcb30: fa fa 00 00 00 00 00 fa fa fa 00 00 00 00 00 00
  0x0c087fffcb40: fa fa 00 00 00 00 00 00 fa fa 00 00 00 00 00 00
  0x0c087fffcb50: fa fa 00 00 00 00 00 00 fa fa 00 00 00 00 00 00
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
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  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
==91015==ABORTING
----------SERVER LOG END-------------
 
 
 - saving '/home/sanja/maria/git/10.4/mysql-test/var/log/main.test/' to '/home/sanja/maria/git/10.4/mysql-test/var/log/main.test/'
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 1595 seconds executing testcases
 

Comment by Oleksandr Byelkin [ 2023-09-25 ]

I can not repeat exactly the same problem:

CREATE TABLE t (c INT) ENGINE=MyISAM UNION=(t,t0) INSERT_METHOD=FIRST;
INSERT INTO t VALUES (0);
SET SESSION profiling=ON;
SELECT * INTO outfile 'a' FROM t;
DROP TABLE t;
CREATE TABLE t (a INT GENERATED ALWAYS AS (0) VIRTUAL,KEY(a)) ENGINE=MyISAM;
LOAD DATA INFILE 'a' REPLACE INTO TABLE t;
CREATE TABLE t0 (a INT) ENGINE=MyISAM;
UPDATE t SET a=0;
main.test                                [ fail ]
        Test ended at 2023-09-25 12:41:56
 
CURRENT_TEST: main.test
mysqltest: At line 9: query 'UPDATE t SET a=0' failed: 1906: The value specified for generated column 'a' in table 't' has been ignored

Comment by Oleksandr Byelkin [ 2023-09-25 ]

It was closed by accident

Comment by Ramesh Sivaraman [ 2023-09-25 ]

sanja As discussed, reproduced the issue on physical box. MTR run also generated coredump.

10.4.32 b6773f58196d74e0a0be83b4499fcb82799e1144

ramesh@ax3-galera1:~/10.4/mariadb-10.4.32-linux-x86_64/mysql-test$ ./mtr mytest
Logging: ./mtr  mytest
VS config:
vardir: /home/ramesh/10.4/mariadb-10.4.32-linux-x86_64/mysql-test/var
Removing old var directory...
Creating var directory '/home/ramesh/10.4/mariadb-10.4.32-linux-x86_64/mysql-test/var'...
Checking supported features...
MariaDB Version 10.4.32-MariaDB-debug
 - SSL connections supported
 - binaries are debug compiled
 - binaries built with wsrep patch
Collecting tests...
Installing system database...
 
==============================================================================
 
TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------
 
worker[01] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
CREATE TABLE t (c INT) ENGINE=MyISAM UNION=(t,t0) INSERT_METHOD=FIRST;
INSERT INTO t VALUES (0);
SET SESSION profiling=ON;
SELECT * INTO outfile 'a' FROM t;
DROP TABLE t;
CREATE TABLE t (a INT GENERATED ALWAYS AS (0) VIRTUAL,KEY(a)) ENGINE=MyISAM;
LOAD DATA INFILE 'a' REPLACE INTO TABLE t;
CREATE TABLE t0 (a INT) ENGINE=MyISAM;
UPDATE t SET a=0;
main.mytest                              [ fail ]
        Test ended at 2023-09-25 12:54:28
 
CURRENT_TEST: main.mytest
mysqltest: At line 9: query 'UPDATE t SET a=0' failed: 1906: The value specified for generated column 'a' in table 't' has been ignored
 
 - found 'core' (0/5)
Core generated by '/home/ramesh/10.4/mariadb-10.4.32-linux-x86_64/bin/mysqld'
Output from gdb follows. The first stack trace is from the failing thread.
The following stack traces are from all threads (so the failing one is
duplicated).
--------------------------
[New LWP 1348486]
[New LWP 1348480]
[New LWP 1348481]
[New LWP 1348482]
[New LWP 1348479]
[New LWP 1348483]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/home/ramesh/10.4/mariadb-10.4.32-linux-x86_64/bin/mysqld --defaults-group-suff'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  __pthread_kill (threadid=<optimized out>, signo=11) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
56	../sysdeps/unix/sysv/linux/pthread_kill.c: No such file or directory.
[Current thread is 1 (Thread 0x7f85c3732700 (LWP 1348486))]
 
Thread 6 (Thread 0x7f85c377d700 (LWP 1348483)):
#0  0x00007f85cd78e1a2 in __GI___sigtimedwait (set=0x7f85c377ccd0, info=0x7f85c377cbf0, timeout=0x0) at ../sysdeps/unix/sysv/linux/sigtimedwait.c:29
#1  0x00005618122f9921 in my_sigwait (set=0x7f85c377ccd0, sig=0x7f85c377cc94, code=0x7f85c377cc98) at /home/ramesh/10.4/include/my_pthread.h:196
#2  0x0000561812300345 in signal_hand (arg=0x0) at /home/ramesh/10.4/sql/mysqld.cc:3254
#3  0x0000561812b4fded in pfs_spawn_thread (arg=0x5618160de4f0) at /home/ramesh/10.4/storage/perfschema/pfs.cc:1869
#4  0x00007f85cdc98609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#5  0x00007f85cd869133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 5 (Thread 0x7f85cd749400 (LWP 1348479)):
#0  0x00007f85cd85efcb in __GI___select (nfds=0, readfds=0x0, writefds=0x0, exceptfds=0x0, timeout=0x7ffd070b3ba0) at ../sysdeps/unix/sysv/linux/select.c:41
#1  0x00005618130b7b37 in my_sleep (m_seconds=20000) at /home/ramesh/10.4/mysys/my_sleep.c:29
#2  0x00005618122fcfec in close_connections () at /home/ramesh/10.4/sql/mysqld.cc:1787
#3  0x0000561812305d46 in mysqld_main (argc=130, argv=0x561815e72860) at /home/ramesh/10.4/sql/mysqld.cc:5970
#4  0x00005618122f974d in main (argc=6, argv=0x7ffd070b3e18) at /home/ramesh/10.4/sql/main.cc:25
 
Thread 4 (Thread 0x7f85c806b700 (LWP 1348482)):
#0  futex_wait_cancelable (private=<optimized out>, expected=0, futex_word=0x561813c8446c <COND_manager+44>) at ../sysdeps/nptl/futex-internal.h:183
#1  __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x561813c843a8 <LOCK_manager+40>, cond=0x561813c84440 <COND_manager>) at pthread_cond_wait.c:508
#2  __pthread_cond_wait (cond=0x561813c84440 <COND_manager>, mutex=0x561813c843a8 <LOCK_manager+40>) at pthread_cond_wait.c:647
#3  0x00005618130c0bd9 in safe_cond_wait (cond=0x561813c84440 <COND_manager>, mp=0x561813c84380 <LOCK_manager>, file=0x5618131bdd80 "/home/ramesh/10.4/include/mysql/psi/mysql_thread.h", line=1174) at /home/ramesh/10.4/mysys/thr_mutex.c:492
#4  0x00005618124409be in inline_mysql_cond_wait (that=0x561813c84440 <COND_manager>, mutex=0x561813c84380 <LOCK_manager>, src_file=0x5618131bdef0 "/home/ramesh/10.4/sql/sql_manager.cc", src_line=102) at /home/ramesh/10.4/include/mysql/psi/mysql_thread.h:1174
#5  0x0000561812440edb in handle_manager (arg=0x0) at /home/ramesh/10.4/sql/sql_manager.cc:102
#6  0x0000561812b4fded in pfs_spawn_thread (arg=0x561816081bc0) at /home/ramesh/10.4/storage/perfschema/pfs.cc:1869
#7  0x00007f85cdc98609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#8  0x00007f85cd869133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 3 (Thread 0x7f85c3f7e700 (LWP 1348481)):
#0  futex_abstimed_wait_cancelable (private=<optimized out>, abstime=0x7f85c3f7dca0, clockid=<optimized out>, expected=0, futex_word=0x5618144b2768 <COND_checkpoint+40>) at ../sysdeps/nptl/futex-internal.h:320
#1  __pthread_cond_wait_common (abstime=0x7f85c3f7dca0, clockid=<optimized out>, mutex=0x5618144b26a8 <LOCK_checkpoint+40>, cond=0x5618144b2740 <COND_checkpoint>) at pthread_cond_wait.c:520
#2  __pthread_cond_timedwait (cond=0x5618144b2740 <COND_checkpoint>, mutex=0x5618144b26a8 <LOCK_checkpoint+40>, abstime=0x7f85c3f7dca0) at pthread_cond_wait.c:665
#3  0x00005618130c0f9b in safe_cond_timedwait (cond=0x5618144b2740 <COND_checkpoint>, mp=0x5618144b2680 <LOCK_checkpoint>, abstime=0x7f85c3f7dca0, file=0x5618133e0040 "/home/ramesh/10.4/include/mysql/psi/mysql_thread.h", line=1211) at /home/ramesh/10.4/mysys/thr_mutex.c:546
#4  0x0000561812a6436a in inline_mysql_cond_timedwait (that=0x5618144b2740 <COND_checkpoint>, mutex=0x5618144b2680 <LOCK_checkpoint>, abstime=0x7f85c3f7dca0, src_file=0x5618133e0078 "/home/ramesh/10.4/storage/maria/ma_servicethread.c", src_line=115) at /home/ramesh/10.4/include/mysql/psi/mysql_thread.h:1211
#5  0x0000561812a648bb in my_service_thread_sleep (control=0x561813aa7760 <checkpoint_control>, sleep_time=29000000000) at /home/ramesh/10.4/storage/maria/ma_servicethread.c:115
#6  0x0000561812a584fb in ma_checkpoint_background (arg=0x1e) at /home/ramesh/10.4/storage/maria/ma_checkpoint.c:707
#7  0x0000561812b4fded in pfs_spawn_thread (arg=0x561816050000) at /home/ramesh/10.4/storage/perfschema/pfs.cc:1869
#8  0x00007f85cdc98609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#9  0x00007f85cd869133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 2 (Thread 0x7f85c9354700 (LWP 1348480)):
#0  futex_abstimed_wait_cancelable (private=<optimized out>, abstime=0x7f85c9353d50, clockid=<optimized out>, expected=0, futex_word=0x5618145192c8 <COND_timer+40>) at ../sysdeps/nptl/futex-internal.h:320
#1  __pthread_cond_wait_common (abstime=0x7f85c9353d50, clockid=<optimized out>, mutex=0x561814519208 <LOCK_timer+40>, cond=0x5618145192a0 <COND_timer>) at pthread_cond_wait.c:520
#2  __pthread_cond_timedwait (cond=0x5618145192a0 <COND_timer>, mutex=0x561814519208 <LOCK_timer+40>, abstime=0x7f85c9353d50) at pthread_cond_wait.c:665
#3  0x00005618130c0f9b in safe_cond_timedwait (cond=0x5618145192a0 <COND_timer>, mp=0x5618145191e0 <LOCK_timer>, abstime=0x7f85c9353d50, file=0x5618135915d0 "/home/ramesh/10.4/include/mysql/psi/mysql_thread.h", line=1211) at /home/ramesh/10.4/mysys/thr_mutex.c:546
#4  0x00005618130c201f in inline_mysql_cond_timedwait (that=0x5618145192a0 <COND_timer>, mutex=0x5618145191e0 <LOCK_timer>, abstime=0x7f85c9353d50, src_file=0x561813591608 "/home/ramesh/10.4/mysys/thr_timer.c", src_line=291) at /home/ramesh/10.4/include/mysql/psi/mysql_thread.h:1211
#5  0x00005618130c2bf9 in timer_handler (arg=0x0) at /home/ramesh/10.4/mysys/thr_timer.c:291
#6  0x0000561812b4fded in pfs_spawn_thread (arg=0x561815f91e00) at /home/ramesh/10.4/storage/perfschema/pfs.cc:1869
#7  0x00007f85cdc98609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#8  0x00007f85cd869133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 1 (Thread 0x7f85c3732700 (LWP 1348486)):
#0  __pthread_kill (threadid=<optimized out>, signo=11) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
#1  0x00005618130bb6ec in my_write_core (sig=11) at /home/ramesh/10.4/mysys/stacktrace.c:386
#2  0x000056181279a4b6 in handle_fatal_signal (sig=11) at /home/ramesh/10.4/sql/signal_handler.cc:372
#3  <signal handler called>
#4  0x00005618125e5a2c in PROF_MEASUREMENT::~PROF_MEASUREMENT (this=0x7f0000000050, __in_chrg=<optimized out>) at /home/ramesh/10.4/sql/sql_profile.cc:186
#5  0x00005618125e5e30 in QUERY_PROFILE::~QUERY_PROFILE (this=0x7f85ac0ce9f0, __in_chrg=<optimized out>) at /home/ramesh/10.4/sql/sql_profile.cc:279
#6  0x00005618125e6184 in PROFILING::restart (this=0x7f85ac004658) at /home/ramesh/10.4/sql/sql_profile.cc:342
#7  0x00005618123d20d1 in THD::free_connection (this=0x7f85ac000d90) at /home/ramesh/10.4/sql/sql_class.cc:1608
#8  0x00005618122ff17f in unlink_thd (thd=0x7f85ac000d90) at /home/ramesh/10.4/sql/mysqld.cc:2646
#9  0x00005618122ff650 in one_thread_per_connection_end (thd=0x7f85ac000d90, put_in_cache=true) at /home/ramesh/10.4/sql/mysqld.cc:2782
#10 0x00005618125e18a7 in do_handle_one_connection (connect=0x56181619d080) at /home/ramesh/10.4/sql/sql_connect.cc:1431
#11 0x00005618125e1581 in handle_one_connection (arg=0x56181619d080) at /home/ramesh/10.4/sql/sql_connect.cc:1324
#12 0x0000561812b4fded in pfs_spawn_thread (arg=0x5618161e37e0) at /home/ramesh/10.4/storage/perfschema/pfs.cc:1869
#13 0x00007f85cdc98609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#14 0x00007f85cd869133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
 - saving '/home/ramesh/10.4/mariadb-10.4.32-linux-x86_64/mysql-test/var/log/main.mytest/' to '/home/ramesh/10.4/mariadb-10.4.32-linux-x86_64/mysql-test/var/log/main.mytest/'
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 15 seconds executing testcases
 
Failure: Failed 1/1 tests, 0.00% were successful.
 
Failing test(s): main.mytest
 
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
 
mysql-test-run: *** ERROR: there were failing test cases
ramesh@ax3-galera1:~/10.4/mariadb-10.4.32-linux-x86_64/mysql-test$

system info

ramesh@ax3-galera1:~/10.4/mariadb-10.4.32-linux-x86_64$ cat /etc/os-release
NAME="Ubuntu"
VERSION="20.04.5 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.5 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal
ramesh@ax3-galera1:~/10.4/mariadb-10.4.32-linux-x86_64$ uname -a
Linux ax3-galera1 5.4.0-84-generic #94-Ubuntu SMP Thu Aug 26 20:27:37 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

Generated at Thu Feb 08 10:24:14 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.