Bug #116374 Undo tablespace was created unexpectedly
Submitted: 16 Oct 2024 12:35 Modified: 12 Nov 2024 8:46
Reporter: jie xu Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: InnoDB Plugin storage engine Severity:S3 (Non-critical)
Version:8.0.40 OS:Any
Assigned to: CPU Architecture:Any

[16 Oct 2024 12:35] jie xu
Description:
When an undo tablespace is being truncated and the instance restarts, the instance may end up creating an additional undo tablespace.

For example, before the instance restart, there are only undo_001 and undo_002. At this point, undo_002 might be in the process of truncating. After the instance restarts, there will be three undo tablespaces: undo_001, undo_002, and undo_003.

How to repeat:
Note: The instance needs to run in debug mode.

First, set the following parameters:

SET GLOBAL innodb_undo_log_truncate = 1;
SET GLOBAL innodb_purge_rseg_truncate_frequency = 1;
SET GLOBAL innodb_rollback_segments = 3;
SET GLOBAL innodb_max_undo_log_size = 11534336;
SET GLOBAL log_error_verbosity = 3;
SET GLOBAL innodb_fast_shutdown = 0;

Then, execute the following command:
delimiter $
CREATE PROCEDURE populate_t1()
BEGIN
        DECLARE i INT DEFAULT 1;
        while (i <= 40000) DO
                insert into t1 values (i, 'a', 'b');
                SET i = i + 1;
        END WHILE;
END $
delimiter ;

create table t1
        (keyc int, c1 char(100), c2 char(100),
         primary key(keyc)) engine = innodb;
begin;
call populate_t1();
delete from t1 where keyc < 20000;
update t1 set c1 = 'mysql' where  keyc > 20000;
update t1 set c2 = 'oracle' where  keyc > 20000;
eval set global debug = "+d,ib_undo_trunc_before_dd_update";
commit;

Finally, restart the instance. you will find 3 undo tablespaces:undo_001, undo_002, and undo_003.

Suggested fix:
The reason is that in the srv_undo_tablespace_fixup_num function, during the cleanup process, only the undo files were deleted, while the undo_trunc_log files were not deleted. As a result, the ongoing truncation of the undo was skipped in srv_undo_tablespaces_create. However, due to insufficient undo tablespace, a new undo tablespace was created. Yet, at the end of the instance startup, the logic in srv_undo_tablespace_fixup detected that there was a previously truncating undo tablespace, leading to its reconstruction.

Suggested fix: In the srv_undo_tablespace_fixup_num function, not only should the undo files be deleted, but also the undo_trunc_log files should be removed.
[17 Oct 2024 9:52] jie xu
I found another issue: the metadata for the newly created undo_003 was not written to the DD. The information for the new undo tablespace should be written to the DD in the srv_undo_tablespace_create interface.

mysql> select * from mysql.tablespaces where name like "innodb_undo_%";
+----+-----------------+---------------+--------------------------------------------------------------------------+---------+--------+
| id | name            | options       | se_private_data                                                          | comment | engine |
+----+-----------------+---------------+--------------------------------------------------------------------------+---------+--------+
|  4 | innodb_undo_001 | encryption=N; | flags=0;id=4294967279;server_version=80018;space_version=1;state=active; |         | InnoDB |
|  5 | innodb_undo_002 | encryption=N; | flags=0;id=4294967151;server_version=80018;space_version=1;state=active; |         | InnoDB |
+----+-----------------+---------------+--------------------------------------------------------------------------+---------+--------+
2 rows in set (0.00 sec)
[27 Oct 2024 15:43] MySQL Verification Team
Hello jie xu,

Thank you for the report and test case.
I quickly tried to reproduce in 8.0.40 debug build but not observing 3 undo_00[1-3] created. Is there anything I'm missing here? Also, please share the exact MySQL Server version you that you are using(pls share make options used for the build if it is source build). Thank you.

--
BugNumber=116374
rm -rf $BugNumber/
bin/mysqld --no-defaults --initialize-insecure --basedir=$PWD --datadir=$PWD/$BugNumber --log-error-verbosity=3
bin/mysqld_safe --no-defaults --mysqld-version=debug --basedir=$PWD --datadir=$PWD/$BugNumber --core-file --socket=/tmp/mysql.sock  --port=3306 --log-error=$PWD/$BugNumber/log.err --mysqlx-port=33330 --mysqlx-socket=/tmp/mysql_x_ushastry.sock --log-error-verbosity=3  --secure-file-priv="" --local-infile=1 2>&1 &

bin/mysql -uroot -S/tmp/mysql.sock
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 7
Server version: 8.0.40-debug MySQL Community Server - GPL - Debug

Copyright (c) 2000, 2024, Oracle and/or its affiliates.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> SHOW VARIABLES LIKE '%VERSION%';
+--------------------------+--------------------------------------+
| Variable_name            | Value                                |
+--------------------------+--------------------------------------+
| admin_tls_version        | TLSv1.2,TLSv1.3                      |
| immediate_server_version | 999999                               |
| innodb_version           | 8.0.40                               |
| original_server_version  | 999999                               |
| protocol_version         | 10                                   |
| replica_type_conversions |                                      |
| slave_type_conversions   |                                      |
| tls_version              | TLSv1.2,TLSv1.3                      |
| version                  | 8.0.40-debug                         |
| version_comment          | MySQL Community Server - GPL - Debug |
| version_compile_machine  | x86_64                               |
| version_compile_os       | Linux                                |
| version_compile_zlib     | 1.3.1                                |
+--------------------------+--------------------------------------+
13 rows in set (0.01 sec)

mysql>
mysql> SET GLOBAL innodb_undo_log_truncate = 1;
Query OK, 0 rows affected (0.00 sec)

mysql> SET GLOBAL innodb_purge_rseg_truncate_frequency = 1;
Query OK, 0 rows affected (0.00 sec)

mysql> SET GLOBAL innodb_rollback_segments = 3;
Query OK, 0 rows affected (0.00 sec)

mysql> SET GLOBAL innodb_max_undo_log_size = 11534336;
Query OK, 0 rows affected (0.00 sec)

mysql> SET GLOBAL log_error_verbosity = 3;
Query OK, 0 rows affected (0.00 sec)

mysql> SET GLOBAL innodb_fast_shutdown = 0;
Query OK, 0 rows affected (0.00 sec)

mysql>
mysql> create database if not exists test;
Query OK, 1 row affected (0.00 sec)

mysql> use test;
Database changed
mysql>
mysql> delimiter $
mysql> CREATE PROCEDURE populate_t1()
    -> BEGIN
    ->         DECLARE i INT DEFAULT 1;
    ->         while (i <= 40000) DO
    ->                 insert into t1 values (i, 'a', 'b');
    ->                 SET i = i + 1;
    ->         END WHILE;
    -> END $
Query OK, 0 rows affected (0.02 sec)

mysql> delimiter ;
mysql>
mysql> create table t1
    ->         (keyc int, c1 char(100), c2 char(100),
    ->          primary key(keyc)) engine = innodb;
Query OK, 0 rows affected (0.05 sec)

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> call populate_t1();
Query OK, 1 row affected (10.64 sec)

mysql> delete from t1 where keyc < 20000;
Query OK, 19999 rows affected (2.76 sec)

mysql> update t1 set c1 = 'mysql' where  keyc > 20000;
Query OK, 20000 rows affected (3.06 sec)
Rows matched: 20000  Changed: 20000  Warnings: 0

mysql> update t1 set c2 = 'oracle' where  keyc > 20000;
Query OK, 20000 rows affected (3.03 sec)
Rows matched: 20000  Changed: 20000  Warnings: 0

mysql> set global debug = "+d,ib_undo_trunc_before_dd_update";
Query OK, 0 rows affected (0.00 sec)

mysql> commit;
Query OK, 0 rows affected (0.07 sec)

mysql> bin/mysqld_safe: line 199:  2590 Killed                  env MYSQLD_PARENT_PID=2346 nohup /export/home/tmp/ushastry/mysql-8.0.40/bin/mysqld-debug --no-defaults --basedir=/export/home/tmp/ushastry/mysql-8.0.40 --datadir=/export/home/tmp/ushastry/mysql-8.0.40/116374 --plugin-dir=/export/home/tmp/ushastry/mysql-8.0.40/lib/plugin/debug --core-file --mysqlx-port=33330 --mysqlx-socket=/tmp/mysql_x_ushastry.sock --log-error-verbosity=3 --secure-file-priv= --local-infile=1 --log-error=/export/home/tmp/ushastry/mysql-8.0.40/116374/log.err --pid-file=support-cluster03.pid --socket=/tmp/mysql.sock --port=3306 < /dev/null >> /export/home/tmp/ushastry/mysql-8.0.40/116374/log.err 2>&1
2024-10-27T15:39:00.822320Z mysqld_safe Number of processes running now: 0
2024-10-27T15:39:00.824749Z mysqld_safe mysqld restarted

--
ls -ltr 116374/undo_001 116374/undo_002                                                                                                                                                                   Sun Oct 27 16:42:58 2024

-rw-r----- 1 umshastr common 16777216 Oct 27 16:41 116374/undo_001
-rw-r----- 1 umshastr common 16777216 Oct 27 16:41 116374/undo_002

regards,
Umesh
[28 Oct 2024 11:45] jie xu
My MySQL version is 8.0.18, but I checked the code for the latest version, and this issue still exists.

I see that the final size of your case's undo file is 16,777,216, while the innodb_max_undo_log_size is set to 11,534,336. This indicates that the undo truncate did not occur.
To reproduce this issue, you need to trigger an undo truncate after the transaction is committed, before restarting the instance.
[12 Nov 2024 8:45] MySQL Verification Team
Thank you for the feedback.