Bug #111448 MySQL Server encounters Assertion Failure when executing query
Submitted: 15 Jun 2023 20:37 Modified: 16 Jun 2023 5:47
Reporter: Yu Liang Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Replication Severity:S6 (Debug Builds)
Version:8.0.33 OS:Ubuntu (20.04 LTS)
Assigned to: CPU Architecture:x86 (Intel(R) Core(TM) i7-10700 CPU)

[15 Jun 2023 20:37] Yu Liang
Description:
The latest version of the MySQL Server (version 8.0.33 debug build) (git commit hash: ea7087d8850) crashes with Assertion Failure when executing the following query:

Config from "/etc/mysql/conf.d/mysql.cnf":

```
[mysqld]
sql_mode = "NO_ENGINE_SUBSTITUTION"
```

```sql
STOP SLAVE ;
RESET SLAVE , SLAVE , SLAVE ALL , MASTER TO 100 ;
CHANGE MASTER TO MASTER_HOST = 'abc' , RELAY_LOG_POS = 100 FOR CHANNEL 'abc' ;
START SLAVE UNTIL SQL_AFTER_MTS_GAPS FOR CHANNEL 'abc' ;
```

In the debug build, the server crashes with the following stack trace: 

```
mysql> START SLAVE UNTIL SQL_AFTER_MTS_GAPS FOR CHANNEL 'abc' ;
2023-06-15T20:34:17.494122Z 9 [Warning] [MY-010897] [Repl] Storing MySQL user name or password information in the connection metadata repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START REPLICA; see the 'START REPLICA Syntax' in the MySQL Manual for more information.
2023-06-15T20:34:17.494280Z 9 [ERROR] [MY-013117] [Repl] Replica I/O for channel 'abc': Fatal error: Invalid (empty) username when attempting to connect to the source server. Connection attempt terminated. Error_code: MY-013117
mysqld: /home/mysql/mysql-server/sql/rpl_applier_reader.cc:532: void Rpl_applier_reader::debug_print_next_event_positions(): Assertion `m_relaylog_file_reader.position() == m_rli->get_event_relay_log_pos() || (m_rli->is_parallel_exec() || (m_rli->info_thd != nullptr && m_rli->info_thd->variables.binlog_trx_compression))' failed.
2023-06-15T20:34:17Z UTC - mysqld got signal 6 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
BuildID[sha1]=1d55d4671b7469352fc317efb0121b604c26443d
Thread pointer: 0xfffedc000be0
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...
Query OK, 0 rows affected, 1 warning (0.02 sec)

stack_bottom = ffff7c1832e8 thread_stack 0x100000
mysql> /home/mysql/mysql-server/bld/runtime_output_directory/mysqld(my_print_stacktrace(unsigned char const*, unsigned long)+0x60) [0x4e6bc30]
/home/mysql/mysql-server/bld/runtime_output_directory/mysqld(print_fatal_signal(int)+0x340) [0x1a89320]
/home/mysql/mysql-server/bld/runtime_output_directory/mysqld(handle_fatal_signal+0x16c) [0x1a896dc]
linux-vdso.so.1(__kernel_rt_sigreturn+0) [0xffff801277a0]
/lib/aarch64-linux-gnu/libc.so.6(gsignal+0xe0) [0xffff7f79bd78]
/lib/aarch64-linux-gnu/libc.so.6(abort+0x114) [0xffff7f788aac]
/lib/aarch64-linux-gnu/libc.so.6(+0x2d490) [0xffff7f795490]
/lib/aarch64-linux-gnu/libc.so.6(+0x2d4f4) [0xffff7f7954f4]
/home/mysql/mysql-server/bld/runtime_output_directory/mysqld(Rpl_applier_reader::debug_print_next_event_positions()+0x334) [0x448a494]
/home/mysql/mysql-server/bld/runtime_output_directory/mysqld(Rpl_applier_reader::open(char const**)+0x910) [0x4489e68]
/home/mysql/mysql-server/bld/runtime_output_directory/mysqld(handle_slave_sql+0x5d78) [0x4433674]
/home/mysql/mysql-server/bld/runtime_output_directory/mysqld() [0x655c1a0]
/lib/aarch64-linux-gnu/libpthread.so.0(+0x7624) [0xffff800cd624]
/lib/aarch64-linux-gnu/libc.so.6(+0xd149c) [0xffff7f83949c]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0): Connection ID (thread ID): 10
Status: NOT_KILLED
```

How to repeat:
Steps to repeat the Assertion Failure:
1. Download the MySQL Server source code from the official github repo: `https://github.com/mysql/mysql-server`
2. Checkout to the latest mysql released version: 8.0.33 (hash: `ea7087d8850`)
3. Compile MySQL using the command: 

```
mkdir -p bld
cd bld
cmake .. -DDOWNLOAD_BOOST=1 -DWITH_BOOST=../boost -DWITH_UNIT_TESTS=OFF -DWITH_DEBUG=1
make
```

4. Run the MySQL Server with command: 

```
./bin/mysqld --basedir=$(pwd) --datadir=$(pwd)/data_all/ori_data --port=7000  --socket=/tmp/mysql_0.sock --mysqlx=OFF --performance_schema=OFF
```

5. Setup the MySQL Server config in the path: "/etc/mysql/conf.d/mysql.cnf"

```
[mysqld]
sql_mode = "NO_ENGINE_SUBSTITUTION"
```

6. Run the MySQL Client with the PoC:

```
./bin/mysql --port=7000 --user=root --socket=/tmp/mysql_0.sock < poc_0.sql
```

where `poc_0.sql` is:

```sql
STOP SLAVE ;
RESET SLAVE , SLAVE , SLAVE ALL , MASTER TO 100 ;
CHANGE MASTER TO MASTER_HOST = 'abc' , RELAY_LOG_POS = 100 FOR CHANNEL 'abc' ;
START SLAVE UNTIL SQL_AFTER_MTS_GAPS FOR CHANNEL 'abc' ;
```

Suggested fix:
The server should continue running instead of crashing by Assertion Failure.
[16 Jun 2023 5:47] MySQL Verification Team
Hello Yu Liang,

Thank you for the report and test case.
Observed that 8.0.33 debug build is affected.

regards,
Umesh
[16 Jun 2023 5:50] MySQL Verification Team
-- release build - not affected

 ./mtr bug111448 --nocheck-testcases
Logging: ./mtr  bug111448 --nocheck-testcases
MySQL Version 8.0.33
Checking supported features
Using 'all' suites
Collecting tests
Checking leftover processes
Removing old var directory
 - WARNING: Using the 'mysql-test/var' symlink
Creating var directory '/export/home/tmp/ushastry/mysql-8.0.33/mysql-test/var'
Installing system database
Using parallel: 1

==============================================================================
                  TEST NAME                       RESULT  TIME (ms) COMMENT
------------------------------------------------------------------------------
STOP SLAVE ;
Warnings:
Warning 1287    'STOP SLAVE' is deprecated and will be removed in a future release. Please use STOP REPLICA instead
Note    3084    Replication thread(s) for channel '' are already stopped.
RESET SLAVE , SLAVE , SLAVE ALL , MASTER TO 100 ;
Warnings:
Warning 1287    'RESET SLAVE' is deprecated and will be removed in a future release. Please use RESET REPLICA instead
Warning 1287    'RESET SLAVE' is deprecated and will be removed in a future release. Please use RESET REPLICA instead
Warning 1287    'RESET SLAVE' is deprecated and will be removed in a future release. Please use RESET REPLICA instead
CHANGE MASTER TO MASTER_HOST = 'abc' , RELAY_LOG_POS = 100 FOR CHANNEL 'abc' ;
Warnings:
Warning 1287    'CHANGE MASTER' is deprecated and will be removed in a future release. Please use CHANGE REPLICATION SOURCE instead
Warning 1287    'MASTER_HOST' is deprecated and will be removed in a future release. Please use SOURCE_HOST instead
START SLAVE UNTIL SQL_AFTER_MTS_GAPS FOR CHANNEL 'abc' ;
Warnings:
Warning 1287    'START SLAVE' is deprecated and will be removed in a future release. Please use START REPLICA instead
[ 50%] main.bug111448                            [ fail ]  Found warnings/errors in error log file!
        Test ended at 2023-06-16 07:45:55
include/load_error_log.inc
line
2023-06-16T05:45:55.564627Z 9 [ERROR] [MY-013117] [Repl] Replica I/O for channel 'abc': Fatal error: Invalid (empty) username when attempting to connect to the source server. Connection attempt terminated. Error_code: MY-013117
^ Found warnings in /export/home/tmp/ushastry/mysql-8.0.33/mysql-test/var/log/mysqld.1.err
ok

 - the logfile can be found in '/export/home/tmp/ushastry/mysql-8.0.33/mysql-test/var/log/main.bug111448/bug111448.log'

[100%] shutdown_report                           [ pass ]

-- debug build - affected

./mtr bug111448 --nocheck-testcases --debug-server
Logging: ./mtr  bug111448 --nocheck-testcases --debug-server
MySQL Version 8.0.33
Checking supported features
 - Binaries are debug compiled
Using 'all' suites
Collecting tests
Checking leftover processes
Removing old var directory
 - WARNING: Using the 'mysql-test/var' symlink
Creating var directory '/export/home/tmp/ushastry/mysql-8.0.33/mysql-test/var'
Installing system database
Using parallel: 1

==============================================================================
                  TEST NAME                       RESULT  TIME (ms) COMMENT
------------------------------------------------------------------------------
STOP SLAVE ;
Warnings:
Warning 1287    'STOP SLAVE' is deprecated and will be removed in a future release. Please use STOP REPLICA instead
Note    3084    Replication thread(s) for channel '' are already stopped.
RESET SLAVE , SLAVE , SLAVE ALL , MASTER TO 100 ;
Warnings:
Warning 1287    'RESET SLAVE' is deprecated and will be removed in a future release. Please use RESET REPLICA instead
Warning 1287    'RESET SLAVE' is deprecated and will be removed in a future release. Please use RESET REPLICA instead
Warning 1287    'RESET SLAVE' is deprecated and will be removed in a future release. Please use RESET REPLICA instead
CHANGE MASTER TO MASTER_HOST = 'abc' , RELAY_LOG_POS = 100 FOR CHANNEL 'abc' ;
Warnings:
Warning 1287    'CHANGE MASTER' is deprecated and will be removed in a future release. Please use CHANGE REPLICATION SOURCE instead
Warning 1287    'MASTER_HOST' is deprecated and will be removed in a future release. Please use SOURCE_HOST instead
START SLAVE UNTIL SQL_AFTER_MTS_GAPS FOR CHANNEL 'abc' ;
Warnings:
Warning 1287    'START SLAVE' is deprecated and will be removed in a future release. Please use START REPLICA instead
[ 50%] main.bug111448                            [ fail ]

-bt

#0  0x00007f4b48b0d644 in __io_getevents_0_4 () from /lib64/libaio.so.1
#1  0x00000000040f9f50 in LinuxAIOHandler::collect() ()
#2  0x00000000040fa3e6 in LinuxAIOHandler::poll(fil_node_t**, void**, IORequest*) ()
#3  0x00000000040fa4be in os_aio_linux_handler(unsigned long, fil_node_t**, void**, IORequest*) ()
#4  0x00000000040fc972 in os_aio_handler(unsigned long, fil_node_t**, void**, IORequest*) ()
#5  0x00000000043a8119 in fil_aio_wait(unsigned long) ()
#6  0x00000000040f9d89 in io_handler_thread(unsigned long) ()
#7  0x000000000410053e in void std::__invoke_impl<void, void (*&)(unsigned long), unsigned long&>(std::__invoke_other, void (*&)(unsigned long), unsigned long&) ()
#8  0x000000000410056b in std::__invoke_result<void (*&)(unsigned long), unsigned long&>::type std::__invoke<void (*&)(unsigned long), unsigned long&>(void (*&)(unsigned long), unsigned long&) ()
#9  0x000000000410109e in void std::_Bind<void (*(unsigned long))(unsigned long)>::__call<void, , 0ul>(std::tuple<>&&, std::_Index_tuple<0ul>) ()
#10 0x00000000041010b9 in void std::_Bind<void (*(unsigned long))(unsigned long)>::operator()<, void>() ()
#11 0x0000000004101148 in void Detached_thread::operator()<void (*)(unsigned long), unsigned long>(void (*&&)(unsigned long), unsigned long&&) ()
#12 0x00000000041011be in void std::__invoke_impl<void, Detached_thread, void (*)(unsigned long), unsigned long>(std::__invoke_other, Detached_thread&&, void (*&&)(unsigned long), unsigned long&&) ()
#13 0x0000000004101208 in std::__invoke_result<Detached_thread, void (*)(unsigned long), unsigned long>::type std::__invoke<Detached_thread, void (*)(unsigned long), unsigned long>(Detached_thread&&, void (*&&)(unsigned long), unsigned long&&) ()
#14 0x000000000410177b in decltype (__invoke((_S_declval<0ul>)(), (_S_declval<1ul>)(), (_S_declval<2ul>)())) std::thread::_Invoker<std::tuple<Detached_thread, void (*)(unsigned long), unsigned long> >::_M_invoke<0ul, 1ul, 2ul>(std::_Index_tuple<0ul, 1ul, 2ul>) ()
#15 0x000000000410178f in std::thread::_Invoker<std::tuple<Detached_thread, void (*)(unsigned long), unsigned long> >::operator()() ()
#16 0x000000000410179f in std::thread::_State_impl<std::thread::_Invoker<std::tuple<Detached_thread, void (*)(unsigned long), unsigned long> > >::_M_run() ()
#17 0x0000000004a944bf in execute_native_thread_routine ()
#18 0x00007f4b49906ea5 in start_thread () from /lib64/libpthread.so.0
#19 0x00007f4b47c0db2d in clone () from /lib64/libc.so.6

Thread 1 (Thread 0x7f4b041f5700 (LWP 4527)):
#0  0x00007f4b4990baa1 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000003f9296e in my_write_core(int) ()
#2  0x00000000032365f5 in handle_fatal_signal ()
#3  <signal handler called>
#4  0x00007f4b47b45387 in raise () from /lib64/libc.so.6
#5  0x00007f4b47b46a78 in abort () from /lib64/libc.so.6
#6  0x00007f4b47b3e1a6 in __assert_fail_base () from /lib64/libc.so.6
#7  0x00007f4b47b3e252 in __assert_fail () from /lib64/libc.so.6
#8  0x0000000003d80d97 in Rpl_applier_reader::debug_print_next_event_positions() ()
#9  0x0000000003d810c8 in Rpl_applier_reader::open(char const**) ()
#10 0x0000000003d7006b in handle_slave_sql ()
#11 0x0000000004743af9 in pfs_spawn_thread ()
#12 0x00007f4b49906ea5 in start_thread () from /lib64/libpthread.so.0
#13 0x00007f4b47c0db2d in clone () from /lib64/libc.so.6