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

Assertion `info->end_of_file - (info->append_read_pos-info->write_buffer) == (res= inline_mysql_file_tell(info->file, (myf) (0)))' failed in my_b_append_tell

Details

    • Bug
    • Status: Confirmed (View Workflow)
    • Major
    • Resolution: Unresolved
    • 10.4(EOL), 10.5, 10.6, 10.7(EOL), 10.8(EOL), 10.9(EOL), 10.10(EOL), 10.11
    • 10.5, 10.6, 10.11
    • None
    • None

    Description

      SET NAMES utf8,collation_connection=utf16le_general_ci;
      SET default_master_connection='MASTER1';
      CHANGE MASTER TO master_use_gtid=slave_pos;
      SET default_master_connection='MASTER 2';
      CHANGE MASTER TO master_use_gtid=current_pos;
      FLUSH LOGS;
      FLUSH LOGS;
      

      Leads to:

      10.11.2 922f7ba75c864a9ae4d0e55fa66860dae306136f (Debug)

      mysqld: /test/10.11_dbg/mysys/mf_iocache2.c:115: my_b_append_tell: Assertion `info->end_of_file - (info->append_read_pos-info->write_buffer) == (res= inline_mysql_file_tell(info->file, (myf) (0)))' failed.
      

      10.11.2 922f7ba75c864a9ae4d0e55fa66860dae306136f (Debug)

      Core was generated by `/test/MD071222-mariadb-10.11.2-linux-x86_64-dbg/bin/mysqld --no-defaults --core'.
      Program terminated with signal SIGABRT, Aborted.
      #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      [Current thread is 1 (Thread 0x150a5c155700 (LWP 1600992))]
      (gdb) bt
      #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      #1  0x0000150a748df859 in __GI_abort () at abort.c:79
      #2  0x0000150a748df729 in __assert_fail_base (fmt=0x150a74a75588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5556e43d2650 "info->end_of_file - (info->append_read_pos-info->write_buffer) == (res= inline_mysql_file_tell(info->file, (myf) (0)))", file=0x5556e43d25b8 "/test/10.11_dbg/mysys/mf_iocache2.c", line=115, function=<optimized out>) at assert.c:92
      #3  0x0000150a748f0fd6 in __GI___assert_fail (assertion=assertion@entry=0x5556e43d2650 "info->end_of_file - (info->append_read_pos-info->write_buffer) == (res= inline_mysql_file_tell(info->file, (myf) (0)))", file=file@entry=0x5556e43d25b8 "/test/10.11_dbg/mysys/mf_iocache2.c", line=line@entry=115, function=function@entry=0x5556e43d2740 <__PRETTY_FUNCTION__.18127> "my_b_append_tell") at assert.c:101
      #4  0x00005556e3f65219 in my_b_append_tell (info=0x150a24038738) at /test/10.11_dbg/mysys/mf_iocache2.c:115
      #5  0x00005556e3f65242 in my_b_safe_tell (info=<optimized out>) at /test/10.11_dbg/mysys/mf_iocache2.c:128
      #6  0x00005556e39d823b in Log_event_writer::pos (this=<optimized out>) at /test/10.11_dbg/sql/log_event.h:999
      #7  Log_event::write_header (this=this@entry=0x150a5c1539b0, event_data_length=33) at /test/10.11_dbg/sql/log_event_server.cc:974
      #8  0x00005556e39d9091 in Rotate_log_event::write (this=0x150a5c1539b0) at /test/10.11_dbg/sql/log_event_server.cc:3406
      #9  0x00005556e39a9a60 in Log_event_writer::write (ev=0x150a5c1539b0, this=0x150a5c153900) at /test/10.11_dbg/sql/log_event.h:5831
      #10 MYSQL_BIN_LOG::write_event (this=this@entry=0x150a24038398, ev=ev@entry=0x150a5c1539b0, cache_data=cache_data@entry=0x0, file=file@entry=0x150a24038738) at /test/10.11_dbg/sql/log.cc:5613
      #11 0x00005556e39b9f73 in MYSQL_BIN_LOG::write_event (ev=0x150a5c1539b0, this=0x150a24038398) at /test/10.11_dbg/sql/log.h:833
      #12 MYSQL_BIN_LOG::new_file_impl (this=this@entry=0x150a24038398) at /test/10.11_dbg/sql/log.cc:5485
      #13 0x00005556e39ba71b in MYSQL_BIN_LOG::new_file (this=this@entry=0x150a24038398) at /test/10.11_dbg/sql/log.cc:5404
      #14 0x00005556e34a5e80 in rotate_relay_log (mi=mi@entry=0x150a24035db0) at /test/10.11_dbg/sql/slave.cc:8191
      #15 0x00005556e36cd598 in Master_info_index::flush_all_relay_logs (this=0x5556e6cf0dd0) at /test/10.11_dbg/sql/rpl_mi.cc:2059
      #16 0x00005556e3703896 in reload_acl_and_cache (thd=thd@entry=0x150a24000d48, options=16130, tables=tables@entry=0x0, write_to_binlog=write_to_binlog@entry=0x150a5c153ed0) at /test/10.11_dbg/sql/sql_reload.cc:190
      #17 0x00005556e357f317 in mysql_execute_command (thd=thd@entry=0x150a24000d48, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.11_dbg/sql/sql_parse.cc:5466
      #18 0x00005556e35694aa in mysql_parse (thd=thd@entry=0x150a24000d48, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x150a5c154300) at /test/10.11_dbg/sql/sql_parse.cc:7998
      #19 0x00005556e35769e9 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x150a24000d48, packet=packet@entry=0x150a2400adf9 "FLUSH LOGS", packet_length=packet_length@entry=10, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_class.h:1346
      #20 0x00005556e3578e22 in do_command (thd=0x150a24000d48, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_parse.cc:1407
      #21 0x00005556e36d365f in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5556e6de56e8, put_in_cache=put_in_cache@entry=true) at /test/10.11_dbg/sql/sql_connect.cc:1415
      #22 0x00005556e36d3b2e in handle_one_connection (arg=0x5556e6de56e8) at /test/10.11_dbg/sql/sql_connect.cc:1317
      #23 0x0000150a74df0609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #24 0x0000150a749dc133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Bug confirmed present in:
      MariaDB: 10.4.28 (dbg), 10.5.19 (dbg), 10.6.12 (dbg), 10.7.8 (dbg), 10.8.7 (dbg), 10.9.5 (dbg), 10.10.3 (dbg), 10.11.2 (dbg)

      Bug (or feature/syntax) confirmed not present in:
      MariaDB: 10.3.38 (dbg), 10.3.38 (opt), 10.4.28 (opt), 10.5.19 (opt), 10.6.12 (opt), 10.7.8 (opt), 10.8.7 (opt), 10.9.5 (opt), 10.10.3 (opt), 10.11.2 (opt)

      Attachments

        Issue Links

          Activity

            Elkin Andrei Elkin added a comment - - edited

            bnestere, the problem description can be actually reduced to

            SET NAMES utf8,collation_connection=utf16le_general_ci;
            SET default_master_connection='master1';
            CHANGE MASTER TO master_use_gtid=slave_pos, master_host='master1-dummy-host'; # the last param is needed for sss
            --error ERROR 1617 (HY000): There is no master connection 'master1'
            show slave 'master1' status\G
            

            That is SET NAMES does some weird things to the source name and its files (ls @@datadir/*slave*relay*).

            I think we should limit the source name to the system charset.

            Elkin Andrei Elkin added a comment - - edited bnestere , the problem description can be actually reduced to SET NAMES utf8,collation_connection=utf16le_general_ci; SET default_master_connection= 'master1' ; CHANGE MASTER TO master_use_gtid=slave_pos, master_host= 'master1-dummy-host' ; # the last param is needed for sss --error ERROR 1617 (HY000): There is no master connection 'master1' show slave 'master1' status\G That is SET NAMES does some weird things to the source name and its files ( ls @@datadir/*slave*relay* ). I think we should limit the source name to the system charset.

            The problem is that string value set for default_master_connection ends up being translated into just "M" at parse time for both master connections, which causes the two master connections to invalidly use the same relay log file on disk.

            Note that the parsing problem is fixed starting in 11.3; however, the underlying bug which allows different master connections to use the same name is still present, and should be fixed.

            bnestere Brandon Nesterenko added a comment - The problem is that string value set for default_master_connection ends up being translated into just "M" at parse time for both master connections, which causes the two master connections to invalidly use the same relay log file on disk. Note that the parsing problem is fixed starting in 11.3; however, the underlying bug which allows different master connections to use the same name is still present, and should be fixed.
            Roel Roel Van de Paar added a comment - - edited

            Additional t/c in MDEV-33048 to be checked upon fix (and preferably added to MTR).

            Roel Roel Van de Paar added a comment - - edited Additional t/c in MDEV-33048 to be checked upon fix (and preferably added to MTR).
            bar Alexander Barkov added a comment - - edited

            This shorter script also demonstrates the same problem:

            SET NAMES utf8,collation_connection=utf16le_general_ci;
            SET default_master_connection='MASTER1';
            SHOW VARIABLES LIKE 'default_master_connection';
            

            +---------------------------+----------------+
            | Variable_name             | Value          |
            +---------------------------+----------------+
            | default_master_connection | M ???????????? |
            +---------------------------+----------------+
            

            Checking the 10.6 code revealed that the utf16 string gets directly assigned to the system variable, without conversion to utf8.

            Note, in 11.4 the conversion to utf8 happens as expected, in Sys_var_charptr::do_string_check().

            The patch which likely fixed the problem (in 11.3?) :

            commit 6151bde48c8edac078300af0827c026b7b8d4894
            Author: Yuchen Pei <ycp@mariadb.com>
            Date:   Thu Sep 14 10:32:42 2023 +1000
             
                cleanup: string sys_var types
            

            bar Alexander Barkov added a comment - - edited This shorter script also demonstrates the same problem: SET NAMES utf8,collation_connection=utf16le_general_ci; SET default_master_connection= 'MASTER1' ; SHOW VARIABLES LIKE 'default_master_connection' ; +---------------------------+----------------+ | Variable_name | Value | +---------------------------+----------------+ | default_master_connection | M ???????????? | +---------------------------+----------------+ Checking the 10.6 code revealed that the utf16 string gets directly assigned to the system variable, without conversion to utf8. Note, in 11.4 the conversion to utf8 happens as expected, in Sys_var_charptr::do_string_check(). The patch which likely fixed the problem (in 11.3?) : commit 6151bde48c8edac078300af0827c026b7b8d4894 Author: Yuchen Pei <ycp@mariadb.com> Date: Thu Sep 14 10:32:42 2023 +1000   cleanup: string sys_var types

            People

              bnestere Brandon Nesterenko
              ramesh Ramesh Sivaraman
              Votes:
              0 Vote for this issue
              Watchers:
              6 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.