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

SIGSEGV's in __memmove_avx_unaligned_erms, Event_queue::drop_matching_events, my_scan_weight_utf8_general_ci, main_arena(), Event_db_repository::load_named_event, and Event_queue::get_top_for_execution_if_time | SIGABRT in Diagnostics_area::set_ok_status

    XMLWordPrintable

    Details

      Description

      Testcase is lightly sporadic. 1-3 Runs at CLI should suffice regularly and even often, though at times many more may be needed. A slight delay before the last query may help with sporadicity. Testcase, when repeated and not crashing, may (to be confirmed) cause hangs and/or memory hogging. MDEV-22648 may be [remotely] connected. Issue hits quite a few different stacks, though does not look to be stack smashing (repetitive consistent results). Issue may be significant. Setting to critical, but feel free to adjust as needed.

      CREATE EVENT e ON SCHEDULE EVERY 5 HOUR DO SELECT 2;
      SET timestamp=100000000;
      CREATE EVENT root8 ON SCHEDULE EVERY '2:5' YEAR_MONTH DO SELECT 1;
      CREATE EVENT EVENT1 ON SCHEDULE EVERY 15 MINUTE STARTS NOW() ENDS DATE_ADD(NOW(), INTERVAL 5 HOUR) DO BEGIN END;
      SET GLOBAL event_scheduler=TRUE;
      ALTER EVENT e ON SCHEDULE EVERY 1 HOUR STARTS '1999-01-01 00:00:00';
      DROP PROCEDURE not_there;
      DROP EVENT IF EXISTS non_existing;
      

      Leads to:

      10.6.0 9118fd360a3da0bba521caf2a35c424968235ac4 (Optimized)

      Core was generated by `/test/MD010121-mariadb-10.6.0-linux-x86_64-opt/bin/mysqld --no-defaults --core-'.
      Program terminated with signal SIGSEGV, Segmentation fault.
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=11)
          at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      [Current thread is 1 (Thread 0x14ed5c0d0700 (LWP 2361337))]
      (gdb) bt
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=11) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      #1  0x000056215f4e766f in my_write_core (sig=sig@entry=11) at /test/10.6_opt/mysys/stacktrace.c:424
      #2  0x000056215ef5cd20 in handle_fatal_signal (sig=11) at /test/10.6_opt/sql/signal_handler.cc:330
      #3  <signal handler called>
      #4  0x000056215f0ebdec in Event_queue::drop_matching_events (this=this@entry=0x5621624ed890, thd=thd@entry=0x14ed10000c58, pattern=pattern@entry=0x14ed5c0ce5c0, comparator=0x56215ee38930 <event_basic_db_equal(st_mysql_const_lex_string const*, Event_basic*)>) at /test/10.6_opt/sql/event_queue.cc:358
      #5  0x000056215f0ec421 in Event_queue::drop_schema_events (this=0x5621624ed890, thd=thd@entry=0x14ed10000c58, schema=schema@entry=0x14ed5c0ce5c0) at /test/10.6_opt/sql/event_queue.cc:394
      #6  0x000056215ee39ef1 in Events::drop_schema_events (thd=thd@entry=0x14ed10000c58, db=db@entry=0x14ed10010470 "test") at /test/10.6_opt/sql/events.cc:664
      #7  0x000056215ed0789f in mysql_rm_db_internal (thd=0x14ed10000c58, db=<optimized out>, if_exists=<optimized out>, silent=<optimized out>) at /test/10.6_opt/sql/sql_db.cc:1089
      #8  0x000056215ed5488c in mysql_execute_command (thd=0x14ed10000c58) at /test/10.6_opt/sql/structs.h:559
      #9  0x000056215ed421df in mysql_parse (thd=0x14ed10000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.6_opt/sql/sql_parse.cc:7881
      #10 0x000056215ed4db27 in dispatch_command (command=COM_QUERY, thd=0x14ed10000c58, packet=0x14ed10008049 "DROP DATABASE test", packet_length=<optimized out>) at /test/10.6_opt/sql/sql_class.h:1293
      #11 0x000056215ed4ff42 in do_command (thd=0x14ed10000c58) at /test/10.6_opt/sql/sql_parse.cc:1348
      #12 0x000056215ee54e81 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5621624cca98, put_in_cache=put_in_cache@entry=true) at /test/10.6_opt/sql/sql_connect.cc:1410
      #13 0x000056215ee552fd in handle_one_connection (arg=arg@entry=0x5621624cca98) at /test/10.6_opt/sql/sql_connect.cc:1312
      #14 0x000056215f1dad76 in pfs_spawn_thread (arg=0x562162470fe8) at /test/10.6_opt/storage/perfschema/pfs.cc:2201
      #15 0x000014ed5d607609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #16 0x000014ed5d1f6293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      10.6.0 9118fd360a3da0bba521caf2a35c424968235ac4 (Debug)

      Core was generated by `/test/MD010121-mariadb-10.6.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
      Program terminated with signal SIGSEGV, Segmentation fault.
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=11)
          at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      [Current thread is 1 (Thread 0x152fa0382700 (LWP 1940722))]
      (gdb) bt
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=11) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      #1  0x00005603f71670d7 in my_write_core (sig=sig@entry=11) at /test/10.6_dbg/mysys/stacktrace.c:424
      #2  0x00005603f68fbab1 in handle_fatal_signal (sig=11) at /test/10.6_dbg/sql/signal_handler.cc:330
      #3  <signal handler called>
      #4  my_scan_weight_utf8mb3_general_ci (end=0x152f00000203 <error: Cannot access memory at address 0x152f00000203>, str=0x152f00000200 <error: Cannot access memory at address 0x152f00000200>, weight=<synthetic pointer>) at /test/10.6_dbg/strings/strcoll.ic:99
      #5  my_strnncollsp_utf8mb3_general_ci (cs=<optimized out>, a=0x152f5c012768 "non_existing", a_length=<optimized out>, b=0x152f00000200 <error: Cannot access memory at address 0x152f00000200>, b_length=<optimized out>) at /test/10.6_dbg/strings/strcoll.ic:256
      #6  0x00005603f6767c25 in charset_info_st::strnncollsp (blen=<optimized out>, b=<optimized out>, alen=<optimized out>, a=<optimized out>, this=<optimized out>) at /test/10.6_dbg/include/m_ctype.h:787
      #7  sortcmp_lex_string (s=s@entry=0x152f5c012790, t=t@entry=0x5603fa208cd8, cs=<optimized out>) at /test/10.6_dbg/sql/events.cc:107
      #8  0x00005603f67677b7 in event_basic_identifier_equal (db=db@entry=0x152f5c012780, name=name@entry=0x152f5c012790, b=b@entry=0x5603fa208c80) at /test/10.6_dbg/sql/event_data_objects.cc:1613
      #9  0x00005603f6b24e86 in Event_queue::find_n_remove_event (this=this@entry=0x5603fa2578c0, db=db@entry=0x152f5c012780, name=name@entry=0x152f5c012790) at /test/10.6_dbg/sql/event_queue.cc:427
      #10 0x00005603f6b25951 in Event_queue::drop_event (this=0x5603fa2578c0, thd=thd@entry=0x152f5c000db8, dbname=dbname@entry=0x152f5c012780, name=name@entry=0x152f5c012790) at /test/10.6_dbg/sql/event_queue.cc:301
      #11 0x00005603f67692f1 in Events::drop_event (thd=thd@entry=0x152f5c000db8, dbname=0x152f5c012780, name=0x152f5c012790, if_exists=<optimized out>) at /test/10.6_dbg/sql/events.cc:620
      #12 0x00005603f663a684 in mysql_execute_command (thd=thd@entry=0x152f5c000db8) at /test/10.6_dbg/sql/structs.h:559
      #13 0x00005603f6623072 in mysql_parse (thd=thd@entry=0x152f5c000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x152fa03813d0) at /test/10.6_dbg/sql/sql_parse.cc:7881
      #14 0x00005603f66311ec in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x152f5c000db8, packet=packet@entry=0x152f5c008d39 "DROP EVENT IF EXISTS non_existing", packet_length=packet_length@entry=33) at /test/10.6_dbg/sql/sql_class.h:1293
      #15 0x00005603f663452d in do_command (thd=0x152f5c000db8) at /test/10.6_dbg/sql/sql_parse.cc:1348
      #16 0x00005603f67907fc in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5603fa208d08, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
      #17 0x00005603f6790f03 in handle_one_connection (arg=arg@entry=0x5603fa208d08) at /test/10.6_dbg/sql/sql_connect.cc:1312
      #18 0x00005603f6c4688f in pfs_spawn_thread (arg=0x5603fa130898) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
      #19 0x0000152faacf5609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #20 0x0000152faa8e4293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      10.4.18 3454b5cf35a61e8f6cfab376638520dee4a50609 (Debug)

      Core was generated by `/test/MD010121-mariadb-10.4.18-linux-x86_64-dbg/bin/mysqld --no-defaults --core'.
      Program terminated with signal SIGSEGV, Segmentation fault.
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=11)
          at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      [Current thread is 1 (Thread 0x150ab0137700 (LWP 1620566))]
      (gdb) bt
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=11) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      #1  0x000055cbc4eb0ebd in my_write_core (sig=sig@entry=11) at /test/10.4_dbg/mysys/stacktrace.c:386
      #2  0x000055cbc45c7abf in handle_fatal_signal (sig=11) at /test/10.4_dbg/sql/signal_handler.cc:343
      #3  <signal handler called>
      #4  my_scan_weight_utf8_general_ci (end=0x8f8f8f8f142352ab <error: Cannot access memory at address 0x8f8f8f8f142352ab>, str=0x15 <error: Cannot access memory at address 0x15>, weight=<synthetic pointer>) at /test/10.4_dbg/strings/strcoll.ic:98
      #5  my_strnncollsp_utf8_general_ci (cs=<optimized out>, a=0x150a5c011f98 "non_existing", a_length=<optimized out>, b=0x15 <error: Cannot access memory at address 0x15>, b_length=<optimized out>) at /test/10.4_dbg/strings/strcoll.ic:255
      #6  0x000055cbc4418fd9 in sortcmp_lex_string (s=s@entry=0x150a5c011fc0, t=t@entry=0x150a5c00bdb0, cs=<optimized out>) at /test/10.4_dbg/sql/events.cc:106
      #7  0x000055cbc4418b69 in event_basic_identifier_equal (db=db@entry=0x150a5c011fb0, name=name@entry=0x150a5c011fc0, b=b@entry=0x150a5c00bd50) at /test/10.4_dbg/sql/event_data_objects.cc:1590
      #8  0x000055cbc47de464 in Event_queue::find_n_remove_event (this=this@entry=0x55cbc7973910, db=db@entry=0x150a5c011fb0, name=name@entry=0x150a5c011fc0) at /test/10.4_dbg/sql/event_queue.cc:423
      #9  0x000055cbc47def73 in Event_queue::drop_event (this=0x55cbc7973910, thd=thd@entry=0x150a5c000d90, dbname=dbname@entry=0x150a5c011fb0, name=name@entry=0x150a5c011fc0) at /test/10.4_dbg/sql/event_queue.cc:300
      #10 0x000055cbc441a683 in Events::drop_event (thd=thd@entry=0x150a5c000d90, dbname=0x150a5c011fb0, name=0x150a5c011fc0, if_exists=<optimized out>) at /test/10.4_dbg/sql/events.cc:619
      #11 0x000055cbc42f8b6f in mysql_execute_command (thd=thd@entry=0x150a5c000d90) at /test/10.4_dbg/sql/structs.h:558
      #12 0x000055cbc42fe0d4 in mysql_parse (thd=thd@entry=0x150a5c000d90, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x150ab0136490, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.4_dbg/sql/sql_parse.cc:7958
      #13 0x000055cbc4300972 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x150a5c000d90, packet=packet@entry=0x150a5c01a271 "DROP EVENT IF EXISTS non_existing", packet_length=packet_length@entry=33, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.4_dbg/sql/sql_class.h:1170
      #14 0x000055cbc430412b in do_command (thd=0x150a5c000d90) at /test/10.4_dbg/sql/sql_parse.cc:1373
      #15 0x000055cbc443de4f in do_handle_one_connection (connect=connect@entry=0x55cbc799bac0) at /test/10.4_dbg/sql/sql_connect.cc:1412
      #16 0x000055cbc443df6e in handle_one_connection (arg=0x55cbc799bac0) at /test/10.4_dbg/sql/sql_connect.cc:1316
      #17 0x0000150ac679e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #18 0x0000150ac62de293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      10.2.37 (Debug)

      Core was generated by `/test/MD010121-mariadb-10.2.37-linux-x86_64-dbg/bin/mysqld --no-defaults --core'.
      Program terminated with signal SIGSEGV, Segmentation fault.
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=11)
          at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      [Current thread is 1 (Thread 0x14ea68539700 (LWP 3107261))]
      (gdb) bt
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=11) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      #1  0x000056261377fc2a in my_write_core (sig=sig@entry=11) at /test/10.2_dbg/mysys/stacktrace.c:382
      #2  0x000056261307282b in handle_fatal_signal (sig=11) at /test/10.2_dbg/sql/signal_handler.cc:343
      #3  <signal handler called>
      #4  0x000014ea540008d0 in ?? ()
      #5  0x0000562613229421 in Event_queue::get_top_for_execution_if_time (this=0x5626170bc720, thd=thd@entry=0x14ea54033990, event_name=event_name@entry=0x14ea68538dc8) at /test/10.2_dbg/sql/event_queue.cc:664
      #6  0x0000562613227259 in Event_scheduler::run (this=this@entry=0x5626170af7c0, thd=0x14ea54033990) at /test/10.2_dbg/sql/event_scheduler.cc:480
      #7  0x00005626132274c2 in event_scheduler_thread (arg=0x14ea54012850) at /test/10.2_dbg/sql/event_scheduler.cc:235
      #8  0x000014eabf643609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #9  0x000014eabf23a293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      I have also seen the issue crash in this query: "CREATE EVENT root8 ..." with this stack:

      10.6.0 9118fd360a3da0bba521caf2a35c424968235ac4 (Debug)

      Core was generated by `/test/MD010121-mariadb-10.6.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
      Program terminated with signal SIGABRT, Aborted.
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
          at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      [Current thread is 1 (Thread 0x1503d411a700 (LWP 975789))]
      (gdb) bt
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      #1  0x000055efa02ce0d7 in my_write_core (sig=sig@entry=6) at /test/10.6_dbg/mysys/stacktrace.c:424
      #2  0x000055ef9fa62ab1 in handle_fatal_signal (sig=6) at /test/10.6_dbg/sql/signal_handler.cc:330
      #3  <signal handler called>
      #4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      #5  0x00001503d5eda859 in __GI_abort () at abort.c:79
      #6  0x00001503d5eda729 in __assert_fail_base (fmt=0x1503d6070588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55efa042edf0 "!is_set() || (m_status == DA_OK_BULK && is_bulk_op())", file=0x55efa042ecd0 "/test/10.6_dbg/sql/sql_error.cc", line=334, function=<optimized out>) at assert.c:92
      #7  0x00001503d5eebf36 in __GI___assert_fail (assertion=assertion@entry=0x55efa042edf0 "!is_set() || (m_status == DA_OK_BULK && is_bulk_op())", file=file@entry=0x55efa042ecd0 "/test/10.6_dbg/sql/sql_error.cc", line=line@entry=334, function=function@entry=0x55efa042ee28 "void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*)") at assert.c:101
      #8  0x000055ef9f742c0b in Diagnostics_area::set_ok_status (this=0x150390006a68, affected_rows=affected_rows@entry=0, last_insert_id=last_insert_id@entry=0, message=message@entry=0x0) at /test/10.6_dbg/sql/sql_error.h:1017
      #9  0x000055ef9f7a15b5 in my_ok (message=0x0, id=0, affected_rows_arg=0, thd=0x150390000db8) at /test/10.6_dbg/sql/sql_class.h:5294
      #10 mysql_execute_command (thd=thd@entry=0x150390000db8) at /test/10.6_dbg/sql/sql_parse.cc:5141
      #11 0x000055ef9f78a072 in mysql_parse (thd=thd@entry=0x150390000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1503d41193d0) at /test/10.6_dbg/sql/sql_parse.cc:7881
      #12 0x000055ef9f7981ec in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x150390000db8, packet=packet@entry=0x150390008d39 "CREATE EVENT root8 ON SCHEDULE EVERY '2:5' YEAR_MONTH DO SELECT 1", packet_length=packet_length@entry=65) at /test/10.6_dbg/sql/sql_class.h:1293
      #13 0x000055ef9f79b52d in do_command (thd=0x150390000db8) at /test/10.6_dbg/sql/sql_parse.cc:1348
      #14 0x000055ef9f8f77fc in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55efa3acb9c8, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
      #15 0x000055ef9f8f7f03 in handle_one_connection (arg=arg@entry=0x55efa3acb9c8) at /test/10.6_dbg/sql/sql_connect.cc:1312
      #16 0x000055ef9fdad88f in pfs_spawn_thread (arg=0x55efa39f38b8) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
      #17 0x00001503d63e8609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #18 0x00001503d5fd7293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      The SIGABRT issue only may be an unrelated issue. I think I have seen it from time to time on very varied replays. If you can see the cause for it, please do fix it or let me know how to prevent it, as this particular one seems very sporadic, and does seem to have any specific testcase that triggers it, it just rather happens randomly. I can log a separate bug for this if needed. See also MDEV-24672 (same assert).

      Bug confirmed present (in one way or another, i.e. different outcomes at different times) in:
      MariaDB: 10.2.37 (dbg), 10.3.28 (dbg), 10.4.18 (dbg), 10.4.18 (opt), 10.5.9 (dbg), 10.5.9 (opt), 10.6.0 (dbg), 10.6.0 (opt)

      Bug (or feature/syntax) confirmed not present in:
      MariaDB: 10.2.37 (opt), 10.3.28 (opt)
      MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.50 (dbg), 5.6.50 (opt), 5.7.32 (dbg), 5.7.32 (opt), 8.0.22 (dbg), 8.0.22 (opt)

      For some unknown reason 10.3.28 (opt) is not affected it seems, however 10.3.28 (dbg) is. 10.3 (opt)

      Unique ID's seen so far:

      SIGABRT|Diagnostics_area::set_ok_status|my_ok|mysql_rm_table|mysql_execute_command
      SIGSEGV|Event_db_repository::load_named_event|Events::create_event|mysql_execute_command|mysql_parse
      SIGSEGV|Event_queue::drop_matching_events|Event_queue::drop_schema_events|Events::drop_schema_events|mysql_rm_db_internal
      SIGSEGV|Event_queue::empty_queue|Event_queue::deinit_queue|Event_queue::~Event_queue|Events::deinit
      SIGSEGV|Event_queue::find_n_remove_event|Event_queue::update_event|Events::update_event|mysql_execute_command
      SIGSEGV|Event_queue::get_top_for_execution_if_time|Event_scheduler::run|event_scheduler_thread|pfs_spawn_thread
      SIGSEGV|Event_queue::get_top_for_execution_if_time|Event_scheduler::run|event_scheduler_thread|start_thread
      SIGSEGV|main_arena () from|Event_queue::empty_queue|Event_queue::deinit_queue|Event_queue::~Event_queue
      SIGSEGV|my_scan_weight_utf8_general_ci|my_scan_weight_utf8_general_ci|my_strnncollsp_utf8_general_ci|event_basic_db_equal
      SIGSEGV|my_scan_weight_utf8_general_ci|my_scan_weight_utf8_general_ci|my_strnncollsp_utf8_general_ci|event_basic_identifier_equal
      SIGSEGV|my_scan_weight_utf8_general_ci|my_strnncollsp_utf8_general_ci|sortcmp_lex_string|event_basic_identifier_equal
      SIGSEGV|my_scan_weight_utf8mb3_general_ci|my_strnncollsp_utf8mb3_general_ci|charset_info_st::strnncollsp|sortcmp_lex_string
      SIGSEGV|my_strndup|Event_queue_element_for_exec::init|Event_queue::get_top_for_execution_if_time|Event_scheduler::run
      

        Attachments

          Activity

            People

            Assignee:
            rucha174 Rucha Deodhar
            Reporter:
            Roel Roel Van de Paar
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Dates

              Created:
              Updated: