Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-23895

Server crash, ASAN heap-buffer-overflow or Valgrind Invalid write in Item_func_rpad::val_str

    XMLWordPrintable

Details

    Description

      CREATE TABLE t1 (a CHAR(8));
      INSERT INTO t1 VALUES ('foo'),('bar');
      SET collation_connection= ucs2_danish_ci;
       
      SELECT * FROM t1 WHERE RPAD(a, 50, LAST_INSERT_ID());
       
      # Cleanup
      DROP TABLE t1;
      

      10.2 01ffccd6 ASAN

      ==1770837==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x60f00001490c at pc 0x7f6d6007a57d bp 0x7f6d5518ea00 sp 0x7f6d5518e1a8
      WRITE of size 2 at 0x60f00001490c thread T5
          #0 0x7f6d6007a57c  (/lib/x86_64-linux-gnu/libasan.so.5+0x9b57c)
          #1 0x5567f278aa46 in Item_func_rpad::val_str(String*) /data/src/10.2/sql/item_strfunc.cc:3251
          #2 0x5567f276db68 in Item_str_func::val_int() /data/src/10.2/sql/item_strfunc.cc:138
          #3 0x5567f20ba295 in evaluate_join_record /data/src/10.2/sql/sql_select.cc:18951
          #4 0x5567f20b957c in sub_select(JOIN*, st_join_table*, bool) /data/src/10.2/sql/sql_select.cc:18856
          #5 0x5567f20b76d1 in do_select /data/src/10.2/sql/sql_select.cc:18400
          #6 0x5567f2051ba4 in JOIN::exec_inner() /data/src/10.2/sql/sql_select.cc:3638
          #7 0x5567f204f6bb in JOIN::exec() /data/src/10.2/sql/sql_select.cc:3433
          #8 0x5567f2052e9d in mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) /data/src/10.2/sql/sql_select.cc:3833
          #9 0x5567f202faa1 in handle_select(THD*, LEX*, select_result*, unsigned long) /data/src/10.2/sql/sql_select.cc:361
          #10 0x5567f1fa7caf in execute_sqlcom_select /data/src/10.2/sql/sql_parse.cc:6218
          #11 0x5567f1f94ab7 in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:3524
          #12 0x5567f1fb1165 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:7733
          #13 0x5567f1f8a460 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1823
          #14 0x5567f1f8723c in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1377
          #15 0x5567f230ae99 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1336
          #16 0x5567f230a75c in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
          #17 0x5567f368a0d7 in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1869
          #18 0x7f6d5feee608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477
          #19 0x7f6d5faca292 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122292)
       
      0x60f00001490c is located 0 bytes to the right of 172-byte region [0x60f000014860,0x60f00001490c)
      allocated by thread T5 here:
          #0 0x7f6d600ecbc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
          #1 0x5567f386d27e in sf_malloc /data/src/10.2/mysys/safemalloc.c:118
          #2 0x5567f3839633 in my_malloc /data/src/10.2/mysys/my_malloc.c:101
          #3 0x5567f2189bc4 in String::real_alloc(unsigned long) /data/src/10.2/sql/sql_string.cc:45
          #4 0x5567f1d7c09d in String::alloc(unsigned long) /data/src/10.2/sql/sql_string.h:361
          #5 0x5567f27a4a8e in alloc_buffer(String*, String*, String*, unsigned long) /data/src/10.2/sql/item_strfunc.cc:2913
          #6 0x5567f278a9d7 in Item_func_rpad::val_str(String*) /data/src/10.2/sql/item_strfunc.cc:3242
          #7 0x5567f276db68 in Item_str_func::val_int() /data/src/10.2/sql/item_strfunc.cc:138
          #8 0x5567f20ba295 in evaluate_join_record /data/src/10.2/sql/sql_select.cc:18951
          #9 0x5567f20b957c in sub_select(JOIN*, st_join_table*, bool) /data/src/10.2/sql/sql_select.cc:18856
          #10 0x5567f20b76d1 in do_select /data/src/10.2/sql/sql_select.cc:18400
          #11 0x5567f2051ba4 in JOIN::exec_inner() /data/src/10.2/sql/sql_select.cc:3638
          #12 0x5567f204f6bb in JOIN::exec() /data/src/10.2/sql/sql_select.cc:3433
          #13 0x5567f2052e9d in mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) /data/src/10.2/sql/sql_select.cc:3833
          #14 0x5567f202faa1 in handle_select(THD*, LEX*, select_result*, unsigned long) /data/src/10.2/sql/sql_select.cc:361
          #15 0x5567f1fa7caf in execute_sqlcom_select /data/src/10.2/sql/sql_parse.cc:6218
          #16 0x5567f1f94ab7 in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:3524
          #17 0x5567f1fb1165 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:7733
          #18 0x5567f1f8a460 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1823
          #19 0x5567f1f8723c in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1377
          #20 0x5567f230ae99 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1336
          #21 0x5567f230a75c in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
          #22 0x5567f368a0d7 in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1869
          #23 0x7f6d5feee608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477
       
      Thread T5 created by T0 here:
          #0 0x7f6d60019805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
          #1 0x5567f368a4c8 in spawn_thread_v1 /data/src/10.2/storage/perfschema/pfs.cc:1919
          #2 0x5567f1d2f177 in inline_mysql_thread_create /data/src/10.2/include/mysql/psi/mysql_thread.h:1246
          #3 0x5567f1d46b07 in create_thread_to_handle_connection(CONNECT*) /data/src/10.2/sql/mysqld.cc:6518
          #4 0x5567f1d47298 in create_new_thread /data/src/10.2/sql/mysqld.cc:6588
          #5 0x5567f1d48423 in handle_connections_sockets() /data/src/10.2/sql/mysqld.cc:6846
          #6 0x5567f1d45e79 in mysqld_main(int, char**) /data/src/10.2/sql/mysqld.cc:6137
          #7 0x5567f1d2da5c in main /data/src/10.2/sql/main.cc:25
          #8 0x7f6d5f9cf0b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
       
      SUMMARY: AddressSanitizer: heap-buffer-overflow (/lib/x86_64-linux-gnu/libasan.so.5+0x9b57c) 
      Shadow bytes around the buggy address:
        0x0c1e7fffa8d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
        0x0c1e7fffa8e0: 00 00 00 00 00 04 fa fa fa fa fa fa fa fa 00 00
        0x0c1e7fffa8f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
        0x0c1e7fffa900: 00 00 04 fa fa fa fa fa fa fa fa fa 00 00 00 00
        0x0c1e7fffa910: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
      =>0x0c1e7fffa920: 00[04]fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c1e7fffa930: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c1e7fffa940: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c1e7fffa950: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c1e7fffa960: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c1e7fffa970: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
      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
        Shadow gap:              cc
      ==1770837==ABORTING
      

      10.2 01ffccd6 Valgrind

      ==1771016== Thread 6:
      ==1771016== Invalid write of size 1
      ==1771016==    at 0x4842B63: memmove (in /usr/lib/x86_64-linux-gnu/valgrind/vgpreload_memcheck-amd64-linux.so)
      ==1771016==    by 0xA49F05: Item_func_rpad::val_str(String*) (item_strfunc.cc:3251)
      ==1771016==    by 0xA3E4D3: Item_str_func::val_int() (item_strfunc.cc:138)
      ==1771016==    by 0x773225: evaluate_join_record(JOIN*, st_join_table*, int) (sql_select.cc:18951)
      ==1771016==    by 0x772E48: sub_select(JOIN*, st_join_table*, bool) (sql_select.cc:18856)
      ==1771016==    by 0x7723B3: do_select(JOIN*, Procedure*) (sql_select.cc:18400)
      ==1771016==    by 0x74BE45: JOIN::exec_inner() (sql_select.cc:3638)
      ==1771016==    by 0x74B2E9: JOIN::exec() (sql_select.cc:3433)
      ==1771016==    by 0x74C4AF: mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) (sql_select.cc:3833)
      ==1771016==    by 0x7404F5: handle_select(THD*, LEX*, select_result*, unsigned long) (sql_select.cc:361)
      ==1771016==    by 0x70A7C1: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:6218)
      ==1771016==    by 0x701081: mysql_execute_command(THD*) (sql_parse.cc:3524)
      ==1771016==    by 0x70E550: mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) (sql_parse.cc:7733)
      ==1771016==    by 0x6FC85F: dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) (sql_parse.cc:1823)
      ==1771016==    by 0x6FB35A: do_command(THD*) (sql_parse.cc:1377)
      ==1771016==    by 0x85AA12: do_handle_one_connection(CONNECT*) (sql_connect.cc:1336)
      ==1771016==  Address 0xb975ae0 is 0 bytes after a block of size 64 alloc'd
      ==1771016==    at 0x483B7F3: malloc (in /usr/lib/x86_64-linux-gnu/valgrind/vgpreload_memcheck-amd64-linux.so)
      ==1771016==    by 0x11801A0: my_malloc (my_malloc.c:101)
      ==1771016==    by 0x7C1345: String::real_alloc(unsigned long) (sql_string.cc:45)
      ==1771016==    by 0x62119C: String::alloc(unsigned long) (sql_string.h:361)
      ==1771016==    by 0xA53F3E: alloc_buffer(String*, String*, String*, unsigned long) (item_strfunc.cc:2913)
      ==1771016==    by 0xA49E96: Item_func_rpad::val_str(String*) (item_strfunc.cc:3242)
      ==1771016==    by 0xA3E4D3: Item_str_func::val_int() (item_strfunc.cc:138)
      ==1771016==    by 0x773225: evaluate_join_record(JOIN*, st_join_table*, int) (sql_select.cc:18951)
      ==1771016==    by 0x772E48: sub_select(JOIN*, st_join_table*, bool) (sql_select.cc:18856)
      ==1771016==    by 0x7723B3: do_select(JOIN*, Procedure*) (sql_select.cc:18400)
      ==1771016==    by 0x74BE45: JOIN::exec_inner() (sql_select.cc:3638)
      ==1771016==    by 0x74B2E9: JOIN::exec() (sql_select.cc:3433)
      ==1771016==    by 0x74C4AF: mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) (sql_select.cc:3833)
      ==1771016==    by 0x7404F5: handle_select(THD*, LEX*, select_result*, unsigned long) (sql_select.cc:361)
      ==1771016==    by 0x70A7C1: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:6218)
      ==1771016==    by 0x701081: mysql_execute_command(THD*) (sql_parse.cc:3524)
      ==1771016== 
       
      valgrind: m_mallocfree.c:305 (get_bszB_as_is): Assertion 'bszB_lo == bszB_hi' failed.
      valgrind: Heap block lo/hi size mismatch: lo = 128, hi = 13511005043687472.
      This is probably caused by your program erroneously writing past the
      end of a heap block and corrupting heap metadata.  If you fix any
      invalid writes reported by Memcheck, this assertion failure will
      probably go away.  Please try that before reporting this as a bug.
       
       
      host stacktrace:
      ==1771016==    at 0x58046FFA: ??? (in /usr/lib/x86_64-linux-gnu/valgrind/memcheck-amd64-linux)
      ==1771016==    by 0x58047127: ??? (in /usr/lib/x86_64-linux-gnu/valgrind/memcheck-amd64-linux)
      ==1771016==    by 0x580472CB: ??? (in /usr/lib/x86_64-linux-gnu/valgrind/memcheck-amd64-linux)
      ==1771016==    by 0x580514B4: ??? (in /usr/lib/x86_64-linux-gnu/valgrind/memcheck-amd64-linux)
      ==1771016==    by 0x5803DE9A: ??? (in /usr/lib/x86_64-linux-gnu/valgrind/memcheck-amd64-linux)
      ==1771016==    by 0x5803CD9F: ??? (in /usr/lib/x86_64-linux-gnu/valgrind/memcheck-amd64-linux)
      ==1771016==    by 0x58041F04: ??? (in /usr/lib/x86_64-linux-gnu/valgrind/memcheck-amd64-linux)
      ==1771016==    by 0x5803C1D8: ??? (in /usr/lib/x86_64-linux-gnu/valgrind/memcheck-amd64-linux)
      ==1771016==    by 0x10058BF28C: ???
      ==1771016==    by 0x1008CD5F1F: ???
      ==1771016==    by 0x1008CD5F07: ???
      ==1771016==    by 0x1008CD5F1F: ???
      ==1771016==    by 0x1008CD5F2F: ???
      ==1771016==    by 0x5: ???
      ==1771016==    by 0x4BFE9: ???
      ==1771016==    by 0x592C9C07: ???
      ==1771016==    by 0x1008D2FFFF: ???
      ==1771016==    by 0x11DD4: ???
       
      sched status:
        running_tid=6
       
      Thread 1: status = VgTs_WaitSys syscall 7 (lwpid 1771016)
      ==1771016==    at 0x4DBBAFF: poll (poll.c:29)
      ==1771016==    by 0x60AE2A: handle_connections_sockets() (mysqld.cc:6669)
      ==1771016==    by 0x60A0EF: mysqld_main(int, char**) (mysqld.cc:6137)
      ==1771016==    by 0x5FE3DC: main (main.cc:25)
      client stack range: [0x1FFEFF5000 0x1FFF000FFF] client SP: 0x1FFEFFD340
      valgrind stack range: [0x1003BF7000 0x1003CF6FFF] top usage: 9480 of 1048576
       
      Thread 2: status = VgTs_WaitSys syscall 202 (lwpid 1771018)
      ==1771016==    at 0x49487B1: futex_abstimed_wait_cancelable (futex-internal.h:320)
      ==1771016==    by 0x49487B1: __pthread_cond_wait_common (pthread_cond_wait.c:520)
      ==1771016==    by 0x49487B1: pthread_cond_timedwait@@GLIBC_2.3.2 (pthread_cond_wait.c:656)
      ==1771016==    by 0x118FB7C: safe_cond_timedwait (thr_mutex.c:545)
      ==1771016==    by 0x1190F75: inline_mysql_cond_timedwait (mysql_thread.h:1182)
      ==1771016==    by 0x1191AA8: timer_handler (thr_timer.c:292)
      ==1771016==    by 0x10CD6C7: pfs_spawn_thread (pfs.cc:1869)
      ==1771016==    by 0x4941608: start_thread (pthread_create.c:477)
      ==1771016==    by 0x4DC8292: clone (clone.S:95)
      client stack range: [0x9760000 0x9F5EFFF] client SP: 0x9F5EBD0
      valgrind stack range: [0x1008043000 0x1008142FFF] top usage: 3400 of 1048576
       
      Thread 3: status = VgTs_WaitSys syscall 202 (lwpid 1771019)
      ==1771016==    at 0x49487B1: futex_abstimed_wait_cancelable (futex-internal.h:320)
      ==1771016==    by 0x49487B1: __pthread_cond_wait_common (pthread_cond_wait.c:520)
      ==1771016==    by 0x49487B1: pthread_cond_timedwait@@GLIBC_2.3.2 (pthread_cond_wait.c:656)
      ==1771016==    by 0x118FB7C: safe_cond_timedwait (thr_mutex.c:545)
      ==1771016==    by 0xF9100D: inline_mysql_cond_timedwait (mysql_thread.h:1182)
      ==1771016==    by 0xF9151B: my_service_thread_sleep (ma_servicethread.c:115)
      ==1771016==    by 0xF852CE: ma_checkpoint_background (ma_checkpoint.c:709)
      ==1771016==    by 0x10CD6C7: pfs_spawn_thread (pfs.cc:1869)
      ==1771016==    by 0x4941608: start_thread (pthread_create.c:477)
      ==1771016==    by 0x4DC8292: clone (clone.S:95)
      client stack range: [0xAB06000 0xB304FFF] client SP: 0xB304B40
      valgrind stack range: [0x100841E000 0x100851DFFF] top usage: 3000 of 1048576
       
      Thread 4: status = VgTs_WaitSys syscall 128 (lwpid 1771020)
      ==1771016==    at 0x4CED322: sigtimedwait (sigtimedwait.c:29)
      ==1771016==    by 0x494CF6B: sigwait (sigwait.c:28)
      ==1771016==    by 0x604FE7: signal_hand (mysqld.cc:3510)
      ==1771016==    by 0x10CD6C7: pfs_spawn_thread (pfs.cc:1869)
      ==1771016==    by 0x4941608: start_thread (pthread_create.c:477)
      ==1771016==    by 0x4DC8292: clone (clone.S:95)
      client stack range: [0xB307000 0xB34FFFF] client SP: 0xB34FCF0
      valgrind stack range: [0x1008542000 0x1008641FFF] top usage: 3400 of 1048576
       
      Thread 5: status = VgTs_WaitSys syscall 202 (lwpid 1771023)
      ==1771016==    at 0x4948376: futex_wait_cancelable (futex-internal.h:183)
      ==1771016==    by 0x4948376: __pthread_cond_wait_common (pthread_cond_wait.c:508)
      ==1771016==    by 0x4948376: pthread_cond_wait@@GLIBC_2.3.2 (pthread_cond_wait.c:638)
      ==1771016==    by 0x118F7BA: safe_cond_wait (thr_mutex.c:491)
      ==1771016==    by 0x630780: inline_mysql_cond_wait (mysql_thread.h:1145)
      ==1771016==    by 0x6313A2: handle_slave_background (slave.cc:337)
      ==1771016==    by 0x10CD6C7: pfs_spawn_thread (pfs.cc:1869)
      ==1771016==    by 0x4941608: start_thread (pthread_create.c:477)
      ==1771016==    by 0x4DC8292: clone (clone.S:95)
      client stack range: [0xB352000 0xB39AFFF] client SP: 0xB39ABE0
      valgrind stack range: [0x1008AA2000 0x1008BA1FFF] top usage: 3000 of 1048576
       
      Thread 6: status = VgTs_Runnable (lwpid 1771024)
      ==1771016==    at 0x4842B63: memmove (in /usr/lib/x86_64-linux-gnu/valgrind/vgpreload_memcheck-amd64-linux.so)
      ==1771016==    by 0xA49F50: Item_func_rpad::val_str(String*) (item_strfunc.cc:3257)
      ==1771016==    by 0xA3E4D3: Item_str_func::val_int() (item_strfunc.cc:138)
      ==1771016==    by 0x773225: evaluate_join_record(JOIN*, st_join_table*, int) (sql_select.cc:18951)
      ==1771016==    by 0x772E48: sub_select(JOIN*, st_join_table*, bool) (sql_select.cc:18856)
      ==1771016==    by 0x7723B3: do_select(JOIN*, Procedure*) (sql_select.cc:18400)
      ==1771016==    by 0x74BE45: JOIN::exec_inner() (sql_select.cc:3638)
      ==1771016==    by 0x74B2E9: JOIN::exec() (sql_select.cc:3433)
      ==1771016==    by 0x74C4AF: mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) (sql_select.cc:3833)
      ==1771016==    by 0x7404F5: handle_select(THD*, LEX*, select_result*, unsigned long) (sql_select.cc:361)
      ==1771016==    by 0x70A7C1: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:6218)
      ==1771016==    by 0x701081: mysql_execute_command(THD*) (sql_parse.cc:3524)
      ==1771016==    by 0x70E550: mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) (sql_parse.cc:7733)
      ==1771016==    by 0x6FC85F: dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) (sql_parse.cc:1823)
      ==1771016==    by 0x6FB35A: do_command(THD*) (sql_parse.cc:1377)
      ==1771016==    by 0x85AA12: do_handle_one_connection(CONNECT*) (sql_connect.cc:1336)
      ==1771016==    by 0x85A777: handle_one_connection (sql_connect.cc:1241)
      ==1771016==    by 0x10CD6C7: pfs_spawn_thread (pfs.cc:1869)
      ==1771016==    by 0x4941608: start_thread (pthread_create.c:477)
      ==1771016==    by 0x4DC8292: clone (clone.S:95)
      client stack range: [0xB39D000 0xB3E5FFF] client SP: 0xB3E4028
      valgrind stack range: [0x1008BD6000 0x1008CD5FFF] top usage: 9240 of 1048576
      

      Non-ASAN non-Valgrind debug build tries to crash in safemalloc and hangs in the process, seemingly forever, with non-detectable CPU usage. The stack trace from the not-completely-dead server is

      10.2 01ffccd6

      malloc(): invalid size (unsorted)
      201006 13:49:09 [ERROR] mysqld got signal 6 ;
      

      #8  <signal handler called>
      #9  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      #10 0x00007f13a5256859 in __GI_abort () at abort.c:79
      #11 0x00007f13a52c13ee in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7f13a53eb285 "%s\n") at ../sysdeps/posix/libc_fatal.c:155
      #12 0x00007f13a52c947c in malloc_printerr (str=str@entry=0x7f13a53eda50 "malloc(): invalid size (unsorted)") at malloc.c:5347
      #13 0x00007f13a52cc234 in _int_malloc (av=av@entry=0x7f1384000020, bytes=bytes@entry=2124) at malloc.c:3736
      #14 0x00007f13a52ce419 in __GI___libc_malloc (bytes=2124) at malloc.c:3066
      #15 0x0000556d9578b40a in sf_malloc (size=2008, my_flags=69648) at /data/src/10.2/mysys/safemalloc.c:118
      #16 0x0000556d957784bd in my_malloc (size=2008, my_flags=69648) at /data/src/10.2/mysys/my_malloc.c:101
      #17 0x0000556d9576b7cf in alloc_root (mem_root=0x7f1384006170, length=400) at /data/src/10.2/mysys/my_alloc.c:243
      #18 0x0000556d94c6a95b in Sql_alloc::operator new (size=400, mem_root=0x7f1384006170) at /data/src/10.2/sql/sql_list.h:45
      #19 0x0000556d94d2a3c0 in Warning_info::push_warning (this=0x7f1384006170, thd=0x7f1384000d90, sql_errno=1292, sqlstate=0x556d958287d7 "22007", level=Sql_condition::WARN_LEVEL_WARN, msg=0x7f13a0366ac0 "Truncated incorrect INTEGER value: 'foo'") at /data/src/10.2/sql/sql_error.cc:709
      #20 0x0000556d94d1a892 in Diagnostics_area::push_warning (this=0x7f1384005f40, thd=0x7f1384000d90, sql_errno_arg=1292, sqlstate=0x556d958287d7 "22007", level=Sql_condition::WARN_LEVEL_WARN, msg=0x7f13a0366ac0 "Truncated incorrect INTEGER value: 'foo'") at /data/src/10.2/sql/sql_error.h:849
      #21 0x0000556d94d0a5b9 in THD::raise_condition (this=0x7f1384000d90, sql_errno=1292, sqlstate=0x556d958287d7 "22007", level=Sql_condition::WARN_LEVEL_WARN, msg=0x7f13a0366ac0 "Truncated incorrect INTEGER value: 'foo'") at /data/src/10.2/sql/sql_class.cc:1068
      #22 0x0000556d94d2a5d4 in push_warning (thd=0x7f1384000d90, level=Sql_condition::WARN_LEVEL_WARN, code=1292, msg=0x7f13a0366ac0 "Truncated incorrect INTEGER value: 'foo'") at /data/src/10.2/sql/sql_error.cc:765
      #23 0x0000556d94d2a7bb in push_warning_printf (thd=0x7f1384000d90, level=Sql_condition::WARN_LEVEL_WARN, code=1292, format=0x556d958d0780 "Truncated incorrect %-.32T value: '%-.128T'") at /data/src/10.2/sql/sql_error.cc:800
      #24 0x0000556d94fa57fe in Value_source::Converter_string_to_number::check_edom_and_truncation (this=0x7f13a03670b0, thd=0x7f1384000d90, filter=..., type=0x556d957f5f50 "INTEGER", cs=0x556d95fe4bc0 <my_charset_latin1>, str=0x7f138406f840 "foo", length=97) at /data/src/10.2/sql/field.cc:1581
      #25 0x0000556d94c87dc6 in Value_source::Converter_strtoll10_with_warn::Converter_strtoll10_with_warn (this=0x7f13a03670b0, thd=0x7f1384000d90, filter=..., cs=0x556d95fe4bc0 <my_charset_latin1>, str=0x7f138406f840 "foo", length=97) at /data/src/10.2/sql/field.h:255
      #26 0x0000556d94c87e34 in Value_source::longlong_from_string_with_check (this=0x7f1384013250, cs=0x556d95fe4bc0 <my_charset_latin1>, cptr=0x7f138406f840 "foo", end=0x7f138406f8a1 "") at /data/src/10.2/sql/field.h:291
      #27 0x0000556d9500d8bc in Value_source::longlong_from_string_with_check (this=0x7f1384013250, str=0x7f1384013310) at /data/src/10.2/sql/field.h:324
      #28 0x0000556d9508497c in Item_str_func::val_int (this=0x7f1384013250) at /data/src/10.2/sql/item_strfunc.cc:139
      #29 0x0000556d94dc7d16 in evaluate_join_record (join=0x7f1384013450, join_tab=0x7f1384014d50, error=0) at /data/src/10.2/sql/sql_select.cc:18951
      #30 0x0000556d94dc7939 in sub_select (join=0x7f1384013450, join_tab=0x7f1384014d50, end_of_records=false) at /data/src/10.2/sql/sql_select.cc:18856
      #31 0x0000556d94dc6eae in do_select (join=0x7f1384013450, procedure=0x0) at /data/src/10.2/sql/sql_select.cc:18400
      #32 0x0000556d94da0b0b in JOIN::exec_inner (this=0x7f1384013450) at /data/src/10.2/sql/sql_select.cc:3638
      #33 0x0000556d94d9ffb2 in JOIN::exec (this=0x7f1384013450) at /data/src/10.2/sql/sql_select.cc:3433
      #34 0x0000556d94da1174 in mysql_select (thd=0x7f1384000d90, tables=0x7f1384012920, wild_num=1, fields=..., conds=0x7f1384013250, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7f1384013430, unit=0x7f1384004988, select_lex=0x7f13840050c8) at /data/src/10.2/sql/sql_select.cc:3833
      #35 0x0000556d94d9531a in handle_select (thd=0x7f1384000d90, lex=0x7f13840048c8, result=0x7f1384013430, setup_tables_done_option=0) at /data/src/10.2/sql/sql_select.cc:361
      #36 0x0000556d94d5feb8 in execute_sqlcom_select (thd=0x7f1384000d90, all_tables=0x7f1384012920) at /data/src/10.2/sql/sql_parse.cc:6218
      #37 0x0000556d94d5677a in mysql_execute_command (thd=0x7f1384000d90) at /data/src/10.2/sql/sql_parse.cc:3524
      #38 0x0000556d94d63c47 in mysql_parse (thd=0x7f1384000d90, rawbuf=0x7f13840126f8 "SELECT * FROM t1 WHERE RPAD(a, 50, LAST_INSERT_ID())", length=52, parser_state=0x7f13a03685f0, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7733
      #39 0x0000556d94d51f56 in dispatch_command (command=COM_QUERY, thd=0x7f1384000d90, packet=0x7f1384008b51 "", packet_length=52, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1823
      #40 0x0000556d94d50a51 in do_command (thd=0x7f1384000d90) at /data/src/10.2/sql/sql_parse.cc:1377
      #41 0x0000556d94eaa695 in do_handle_one_connection (connect=0x556d97e46aa0) at /data/src/10.2/sql/sql_connect.cc:1336
      #42 0x0000556d94eaa3fa in handle_one_connection (arg=0x556d97e46aa0) at /data/src/10.2/sql/sql_connect.cc:1241
      #43 0x0000556d956ce2f2 in pfs_spawn_thread (arg=0x556d97e4f770) at /data/src/10.2/storage/perfschema/pfs.cc:1869
      #44 0x00007f13a5779609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #45 0x00007f13a5353293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Non-debug server also hangs or crashes, at least when the test is executed via MTR; but this crash looks different and it happens later, upon MTR's post-checks. Apparently it is a delayed aftermath of the initial problem detected by instrumented builds. The crash is sporadic and when it does crash, it can be in different places with different stack traces. Still, I'll put here the ones I've got for the record.

      10.2 non-debug 01ffccd6 via MTR

      #3  <signal handler called>
      #4  l_find (head=0x7f5510061d48, head@entry=0x55df423140b8, cs=<optimized out>, hashnr=<optimized out>, key=key@entry=0x7f552c1ab438 "\002mysql", keylen=keylen@entry=12, cursor=cursor@entry=0x7f552c1aa300, pins=<optimized out>, callback=0x0) at /data/src/10.2/mysys/lf_hash.c:112
      #5  0x000055df4076dc0b in l_search (pins=0x55df4230c100, keylen=12, key=0x7f552c1ab438 "\002mysql", hashnr=<optimized out>, cs=<optimized out>, head=0x55df423140b8) at /data/src/10.2/mysys/lf_hash.c:286
      #6  lf_hash_search_using_hash_value (hash=hash@entry=0x55df40e6fec0 <mdl_locks>, pins=pins@entry=0x55df4230c100, hashnr=171613907, key=key@entry=0x7f552c1ab438, keylen=12) at /data/src/10.2/mysys/lf_hash.c:488
      #7  0x000055df4076df1f in lf_hash_search (hash=hash@entry=0x55df40e6fec0 <mdl_locks>, pins=pins@entry=0x55df4230c100, key=key@entry=0x7f552c1ab438, keylen=<optimized out>) at /data/src/10.2/mysys/lf_hash.c:528
      #8  0x000055df401449af in MDL_map::find_or_insert (mdl_key=<optimized out>, pins=<optimized out>, this=<optimized out>) at /data/src/10.2/sql/mdl.h:310
      #9  MDL_map::find_or_insert (this=0x55df40e6fec0 <mdl_locks>, pins=0x55df4230c100, mdl_key=0x7f552c1ab430) at /data/src/10.2/sql/mdl.cc:729
      #10 0x000055df401465c6 in MDL_context::try_acquire_lock_impl (this=this@entry=0x7f5510000d68, mdl_request=mdl_request@entry=0x7f552c1ab410, out_ticket=out_ticket@entry=0x7f552c1aa478) at /data/src/10.2/sql/mdl.cc:1915
      #11 0x000055df40146c69 in MDL_context::acquire_lock (this=this@entry=0x7f5510000d68, mdl_request=mdl_request@entry=0x7f552c1ab410, lock_wait_timeout=31536000) at /data/src/10.2/sql/mdl.cc:2067
      #12 0x000055df4000c15c in open_table_get_mdl_lock (thd=thd@entry=0x7f5510000c48, ot_ctx=ot_ctx@entry=0x7f552c1aadc0, mdl_request=mdl_request@entry=0x7f552c1ab410, flags=flags@entry=2050, mdl_ticket=mdl_ticket@entry=0x7f552c1aa778) at /data/src/10.2/sql/sql_base.h:557
      #13 0x000055df4000fcef in open_table (thd=0x7f5510000c48, table_list=0x7f552c1aafc0, ot_ctx=0x7f552c1aadc0) at /data/src/10.2/sql/sql_base.cc:1760
      #14 0x000055df400138a2 in open_and_process_table (ot_ctx=0x7f552c1aadc0, has_prelocking_list=false, prelocking_strategy=0x7f552c1aaeb8, flags=2050, counter=0x7f552c1aae5c, tables=0x7f552c1aafc0, thd=0x7f5510000c48) at /data/src/10.2/sql/sql_base.cc:3609
      #15 open_tables (thd=thd@entry=0x7f5510000c48, options=..., start=start@entry=0x7f552c1aae48, counter=counter@entry=0x7f552c1aae5c, flags=flags@entry=2050, prelocking_strategy=prelocking_strategy@entry=0x7f552c1aaeb8) at /data/src/10.2/sql/sql_base.cc:4076
      #16 0x000055df40013dc7 in open_and_lock_tables (thd=thd@entry=0x7f5510000c48, options=..., tables=<optimized out>, tables@entry=0x7f552c1aafc0, derived=derived@entry=false, flags=flags@entry=2050, prelocking_strategy=prelocking_strategy@entry=0x7f552c1aaeb8) at /data/src/10.2/sql/sql_base.cc:4845
      #17 0x000055df40018652 in open_and_lock_tables (flags=2050, derived=false, tables=0x7f552c1aafc0, thd=0x7f5510000c48) at /data/src/10.2/sql/sql_base.h:507
      #18 open_system_tables_for_read (thd=thd@entry=0x7f5510000c48, table_list=table_list@entry=0x7f552c1aafc0, backup=backup@entry=0x7f552c1ab6d0) at /data/src/10.2/sql/sql_base.cc:8588
      #19 0x000055df40336a7a in open_proc_table_for_read (thd=thd@entry=0x7f5510000c48, backup=backup@entry=0x7f552c1ab6d0) at /data/src/10.2/sql/sp.cc:410
      #20 0x000055df40339427 in db_find_routine (thd=0x7f5510000c48, type=TYPE_ENUM_PROCEDURE, name=0x7f552c1abba0, sphp=0x7f552c1abe18) at /data/src/10.2/sql/sp.cc:555
      #21 0x000055df403398c7 in sp_cache_routine (thd=thd@entry=0x7f5510000c48, type=TYPE_ENUM_PROCEDURE, name=name@entry=0x7f552c1abba0, lookup_only=lookup_only@entry=false, sp=sp@entry=0x7f552c1abe18) at /data/src/10.2/sql/sp.cc:2152
      #22 0x000055df40339b6c in sp_cache_routine (thd=thd@entry=0x7f5510000c48, rt=rt@entry=0x7f551000f470, lookup_only=lookup_only@entry=false, sp=sp@entry=0x7f552c1abe18) at /data/src/10.2/sql/sp.cc:2105
      #23 0x000055df400136c0 in open_and_process_routine (routine_modifies_data=<synthetic pointer>, need_prelocking=0x7f552c1abe17, ot_ctx=0x7f552c1abe40, has_prelocking_list=false, prelocking_strategy=0x7f552c1ac050, rt=0x7f551000f470, prelocking_ctx=0x7f55100045c8, thd=0x7f5510000c48) at /data/src/10.2/sql/sql_base.cc:3276
      #24 open_tables (thd=thd@entry=0x7f5510000c48, options=..., start=start@entry=0x7f552c1abec8, counter=counter@entry=0x7f552c1abedc, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x7f552c1ac050) at /data/src/10.2/sql/sql_base.cc:4148
      #25 0x000055df40013dc7 in open_and_lock_tables (thd=thd@entry=0x7f5510000c48, options=..., tables=<optimized out>, derived=derived@entry=true, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x7f552c1ac050) at /data/src/10.2/sql/sql_base.cc:4845
      #26 0x000055df4005bbe3 in open_and_lock_tables (flags=0, derived=true, tables=<optimized out>, thd=0x7f5510000c48) at /data/src/10.2/sql/sql_base.h:507
      #27 mysql_execute_command (thd=0x7f5510000c48) at /data/src/10.2/sql/sql_parse.cc:5531
      #28 0x000055df4006104b in mysql_parse (thd=thd@entry=0x7f5510000c48, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f552c1ad5b0, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.2/sql/sql_parse.cc:7733
      #29 0x000055df400642fd in dispatch_command (command=COM_QUERY, thd=0x7f5510000c48, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.2/sql/sql_class.h:1095
      #30 0x000055df40065487 in do_command (thd=0x7f5510000c48) at /data/src/10.2/sql/sql_parse.cc:1377
      #31 0x000055df4013d7d6 in do_handle_one_connection (connect=connect@entry=0x55df423df258) at /data/src/10.2/sql/sql_connect.cc:1336
      #32 0x000055df4013d94f in handle_one_connection (arg=arg@entry=0x55df423df258) at /data/src/10.2/sql/sql_connect.cc:1241
      #33 0x000055df406d5066 in pfs_spawn_thread (arg=0x55df423f00d8) at /data/src/10.2/storage/perfschema/pfs.cc:1869
      #34 0x00007f55315bb609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #35 0x00007f55311b0293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      10.5 861cd4ce non-debug

      2020-10-06 13:59:30 0 [Note] /data/bld/10.5-rel-nightly/bin/mariadbd (initiated by: root[root] @ localhost [127.0.0.1]): Normal shutdown
      2020-10-06 13:59:30 0 [Note] Event Scheduler: Purging the queue. 0 events
      free(): invalid next size (fast)
      201006 13:59:30 [ERROR] mysqld got signal 6 ;
      

      Version: '10.5.6-MariaDB-log'  socket: '/data/bld/10.5-rel-nightly/mysql-test/var/tmp/mysqld.1.sock'  port: 16000  MariaDB Server
      free(): invalid next size (fast)
      201006 14:00:58 [ERROR] 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.
       
      To report this bug, see https://mariadb.com/kb/en/reporting-bugs
       
      We will try our best to scrape up some info that will hopefully help
      diagnose the problem, but since we have already crashed, 
      something is definitely wrong and this may fail.
       
      Server version: 10.5.6-MariaDB-log
      key_buffer_size=1048576
      read_buffer_size=131072
      max_used_connections=1
      max_threads=153
      thread_count=2
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63636 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x7f7570000c58
      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 = 0x7f7580c53dd8 thread_stack 0x49000
      2020-10-06 14:00:58 0 [Note] /data/bld/10.5-rel-nightly/bin/mariadbd (initiated by: root[root] @ localhost [127.0.0.1]): Normal shutdown
      2020-10-06 14:00:58 0 [Note] Event Scheduler: Purging the queue. 0 events
      /data/bld/10.5-rel-nightly/bin/mariadbd(my_print_stacktrace+0x32)[0x5637d04fb5a2]
      mysys/stacktrace.c:213(my_print_stacktrace)[0x5637cff1d7a5]
      sigaction.c:0(__restore_rt)[0x7f75867ba3c0]
      ??:0(gsignal)[0x7f75862c118b]
      ??:0(abort)[0x7f75862a0859]
      ??:0(__fsetlocking)[0x7f758630b3ee]
      ??:0(pthread_attr_setschedparam)[0x7f758631347c]
      ??:0(pthread_attr_setschedparam)[0x7f7586314d2c]
      /data/bld/10.5-rel-nightly/bin/mariadbd(delete_dynamic+0x23)[0x5637d04d6443]
      mysys/array.c:307(delete_dynamic)[0x5637cfc76750]
      sql/sql_array.h:272(Dynamic_array<sp_variable*>::~Dynamic_array())[0x5637cfc766e5]
      sql/sql_alloc.h:40(Sql_alloc::operator delete(void*, unsigned long))[0x5637cfc6b91e]
      sql/sp_head.cc:884(sp_head::~sp_head())[0x5637cfc6b89b]
      sql/sp_head.cc:521(sp_head::destroy(sp_head*))[0x5637d04da99e]
      mysys/hash.c:135(my_hash_free_elements)[0x5637cfc689bd]
      sql/sp_cache.cc:299(sp_cache::~sp_cache())[0x5637cfc689de]
      sql/sp_cache.cc:133(sp_cache_clear(sp_cache**))[0x5637cfcbc267]
      sql/sql_class.cc:1587(THD::cleanup())[0x5637cfc3e23b]
      psi/mysql_thread.h:738(unlink_thd(THD*))[0x5637cfe157df]
      sql/sql_connect.cc:1422(do_handle_one_connection(CONNECT*, bool))[0x5637cfe15efd]
      sql/sql_connect.cc:1318(handle_one_connection)[0x5637d019d336]
      nptl/pthread_create.c:478(start_thread)[0x7f75867ae609]
      ??:0(clone)[0x7f758639d293]
       
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x0): (null)
      Connection ID (thread ID): 6
      Status: KILL_SERVER
      

      Attachments

        Activity

          People

            sanja Oleksandr Byelkin
            elenst Elena Stepanova
            Votes:
            1 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:

              Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.