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

Calling a function from a different database in a slave side trigger crashes

Details

    Description

      Using slave_run_triggers_for_rbr=ON and row based replication a slave side trigger on a table that itself calls a function from a different database than the one the table with the trigger is in makes the slave server crash.

      How to reproduce:

      • on the master have binlog-format=ROW
      • on the slave have slave_run_triggers_for_rbr=1
      • set up replication between master and slave
      • on the master create a table without trigger, e.g. 

        USE db1;
        		 
         
        		 
        CREATE TABLE IF NOT EXISTS `t1` (
        		 
        `i` int(11) NOT NULL,
        		 
        PRIMARY KEY (`i`)
        		 
        );

      • on the slave create a function in a different database, e.g db2 instead of db1

      USE db2;
      		 
        
      DELIMITER //
      		 
       
      		 
      CREATE FUNCTION `get_value`(`id` INT) RETURNS int(2)
      		 
      BEGIN
      		 
        RETURN 0;
      		 
      END//
      		 
       
      		 
      DELIMITER ;

      • on the slave create a trigger on the table originally created on the master, calling the function in the other database:

      USE db1;
      		 
       
      		 
      DELIMITER //
      		 
       
      		 
      CREATE TRIGGER `tr_s1` BEFORE INSERT ON `t1` FOR EACH ROW BEGIN
      		 
      DECLARE id INT;
      		 
      SET id = `db2`.get_value(1);
      		 
      END//
      		 
       
      		 
      DELIMITER ;

      • now back on the master insert a row into the test table:

      USE db1;
      		 
       
      		 
      INSERT INTO `t1` (`i`) VALUES (4);

      This did not cause problems up to MariaDB 10.4, but starting with 10.5 up to 10.10 it crashes the server, and as it tries to replicate the same event again and again after crash recovery as first thing when replication restarts it puts the slave into a crashing loop.

      Error log output from syslog:

      Oct 27 08:25:54 slave-1 mariadbd[1765]: free(): invalid pointer
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: 221027  8:25:54 [ERROR] mysqld got signal 6 ;
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: This could be because you hit a bug. It is also possible that this binary
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: or one of the libraries it was linked against is corrupt, improperly built,
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: or misconfigured. This error can also be caused by malfunctioning hardware.
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: We will try our best to scrape up some info that will hopefully help
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: diagnose the problem, but since we have already crashed,
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: something is definitely wrong and this may fail.
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: Server version: 10.10.1-MariaDB-1:10.10.1+maria~ubu2204
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: key_buffer_size=134217728
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: read_buffer_size=131072
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: max_used_connections=2
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: max_threads=153
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: thread_count=4
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: It is possible that mysqld could use up to
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 468010 K  bytes of memory
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: Hope that's ok; if not, decrease some variables in the equation.
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: Thread pointer: 0x7f89b80015a8
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: Attempting backtrace. You can use the following information to find out
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: where mysqld died. If you see no messages after this, something went
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: terribly wrong...
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: stack_bottom = 0x7f8a000924e0 thread_stack 0x49000
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(my_print_stacktrace)[0x563bad89a3a2]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(handle_fatal_signal)[0x563bad36d1e8]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(__sigaction)[0x7f8a19377520]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(pthread_kill)[0x7f8a193cba7c]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(raise)[0x7f8a19377476]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(abort)[0x7f8a1935d7f3]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(__fsetlocking)[0x7f8a193be6f6]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(timer_settime)[0x7f8a193d5d7c]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(__default_morecore)[0x7f8a193d7ac4]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(free)[0x7f8a193da4d3]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(THD::set_db(st_mysql_const_lex_string const*))[0x563bad0b89fe]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(mysql_change_db(THD*, st_mysql_const_lex_string const*, bool))[0x563bad0c86e8]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(mysql_opt_change_db(THD*, st_mysql_const_lex_string const*, st_mysql_lex_string*, bool, bool*))[0x563bad0c8a10]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(sp_head::execute(THD*, bool))[0x563bad0644c6]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(sp_head::execute_function(THD*, Item**, unsigned int, Field*, sp_rcontext**, Query_arena*))[0x563bad067153]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(Item_sp::execute_impl(THD*, Item**, unsigned int))[0x563bad38f74f]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(Item_sp::execute(THD*, bool*, Item**, unsigned int))[0x563bad38f8e3]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(Item_func_sp::val_int())[0x563bad3fa4d5]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(Item::save_int_in_field(Field*, bool))[0x563bad3950e3]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(Item::save_in_field(Field*, bool))[0x563bad384987]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(Field::sp_prepare_and_store_item(THD*, Item**))[0x563bad34a4f3]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(THD::sp_eval_expr(Field*, Item**))[0x563bad062fbc]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(sp_rcontext::set_variable(THD*, unsigned int, Item**))[0x563bad071948]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(sp_instr_set::exec_core(THD*, unsigned int*))[0x563bad06b65f]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*))[0x563bad06a8a4]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(sp_head::execute(THD*, bool))[0x563bad064c1a]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(sp_head::execute_trigger(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, st_grant_info*))[0x563bad065ccd]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(Table_triggers_list::process_triggers(THD*, trg_event_type, trg_action_time_type, bool))[0x563bad1dce74]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(Rows_log_event::write_row(rpl_group_info*, bool))[0x563bad4b1e01]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(Write_rows_log_event::do_exec_row(rpl_group_info*))[0x563bad4b23c4]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(Rows_log_event::do_apply_event(rpl_group_info*))[0x563bad4a585c]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(Log_event::apply_event(rpl_group_info*))[0x563bad49db01]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(apply_event_and_update_pos(Log_event*, THD*, rpl_group_info*))[0x563bad057bfb]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(handle_slave_sql)[0x563bad0592b2]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(MyCTX_nopad::finish(unsigned char*, unsigned int*))[0x563bad599026]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(pthread_condattr_setpshared)[0x7f8a193c9b43]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: ??:0(__xmknodat)[0x7f8a1945ba00]
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: Trying to get some variables.
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: Some pointers may be invalid and cause the dump to abort.
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: Query (0x0): (null)
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: Connection ID (thread ID): 5
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: Status: NOT_KILLED
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on,not_null_range_scan=off
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: information that should help you find out what is causing the crash.
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: We think the query pointer is invalid, but we will try to print it anyway.
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: Query:
      		 
      Oct 27 08:25:54 slave-1 mariadbd[1765]: Writing a core file...

      Attachments

        Issue Links

          is duplicated by

          Bug - A problem which impairs or prevents the functions of the product. MDEV-29939 free(): invalid pointer st_mysql_lex_stringbPb

          • Major - Major loss of function.
          • Closed

          Activity

            Transition Time In Source Status Execution Times
            Alice Sherepa made transition -
            Open Confirmed
            		6h 26m 1
            Julien Fritsch made transition -
            Confirmed In Progress
            		215d 1h 6m 1
            Brandon Nesterenko made transition -
            In Progress In Review
            		1d 4h 5m 1
            Brandon Nesterenko made transition -
            Stalled In Review
            		6h 12m 1
            Andrei Elkin made transition -
            In Review Stalled
            		20d 6h 2m 2
            Brandon Nesterenko made transition -
            Stalled Closed
            		11h 7m 1

            People

              bnestere Brandon Nesterenko
              hholzgra Hartmut Holzgraefe
              Votes:
              4 Vote for this issue
              Watchers:
              13 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

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