Bug #116626 Lack of error handling when temp tablespace truncate fails
Submitted: 12 Nov 2024 9:55 Modified: 12 Nov 2024 10:01
Reporter: Zihao Wang (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:8.0.40 OS:Any
Assigned to: CPU Architecture:Any
Tags: Contribution

[12 Nov 2024 9:55] Zihao Wang
Description:
Background:
  InnoDB uses session temporary tablespaces and a global temporary tablespace. When a session disconnects, its temporary tablespaces are truncated and released back to the pool.

Bug description:
  Due to the lack of error handling when temp tablespace truncate fails, an unexpected zero-size ibt file will be put into `m_active` pool. Next session that get this zero-size temp tablespace will end up print tons of error message into master-error.log. 

The content of the errmsg is:
"
2024-10-22T13:58:04.999581+08:00 2968382 [Warning] [MY-012637] [InnoDB] 16384 bytes should have been read. Only 0 bytes read. Retrying for the remaining bytes.
2024-10-22T13:58:04.999585+08:00 2968382 [Warning] [MY-012637] [InnoDB] 16384 bytes should have been read. Only 0 bytes read. Retrying for the remaining bytes.
2024-10-22T13:58:04.999589+08:00 2968382 [Warning] [MY-012638] [InnoDB] Retry attempts for reading partial data failed.
2024-10-22T13:58:04.999592+08:00 2968382 [ERROR] [MY-012642] [InnoDB] Tried to read 16384 bytes at offset 0, but was only able to read 0
2024-10-22T13:58:04.999596+08:00 2968382 [ERROR] [MY-012592] [InnoDB] Operating system error number 11 in a file operation.
2024-10-22T13:58:04.999600+08:00 2968382 [ERROR] [MY-012596] [InnoDB] Error number 11 means 'Resource temporarily unavailable'
2024-10-22T13:58:04.999604+08:00 2968382 [Note] [MY-012597] [InnoDB] Refer to your operating system documentation for operating system error code information.
2024-10-22T13:58:04.999608+08:00 2968382 [Warning] [MY-012637] [InnoDB] 16384 bytes should have been read. Only 0 bytes read. Retrying for the remaining bytes.
"

The place where missing error handling:
"
  if (space->size != FIL_IBT_FILE_INITIAL_SIZE) {
    ts->truncate();
  }
"
`ts->truncate()` could return false! See code here: https://github.com/mysql/mysql-server/blob/61a3a1d8ef15512396b4c2af46e922a19bf2b174/storag...

Scenarios that may cause truncate to fail:
1. `open_file` failed
2. `os_file_truncate` failed
3. `os_file_write` failed
4. `os_file_flush` failed

How to repeat:
Since all the scenarios listed above are related to file system, it is more easier to repeat with dbug-package. Add debug like this:
"
diff --git a/storage/innobase/fil/fil0fil.cc b/storage/innobase/fil/fil0fil.cc
index a8b7ff9c1e4..4fc30ef6bb1 100644
--- a/storage/innobase/fil/fil0fil.cc
+++ b/storage/innobase/fil/fil0fil.cc
@@ -4695,6 +4695,7 @@ bool Fil_shard::space_truncate(space_id_t space_id, page_no_t size_in_pages) {
     os_offset_t size = size_in_pages * UNIV_PAGE_SIZE;
 
     success = os_file_set_size(file.name, file.handle, 0, size, true);
+    DBUG_EXECUTE_IF("os_file_truncate_error", { success = false; });
 
     if (success) {
       space->stop_new_ops = false;
"

=============================

now let me show you how to repeat:

0. connect to MySQL
1. create table foo (a int, b int, c varchar(100), primary key(a));
2. create table bar like foo; 
3. 
DELIMITER $$

CREATE PROCEDURE InsertIntoFoo(IN num_rows INT, IN base_value INT)
BEGIN
    DECLARE i INT DEFAULT 0;
    SET @base = base_value;
    
    START TRANSACTION;
    
    WHILE i < num_rows DO
        INSERT INTO foo (a, b, c) VALUES (@base + i, i * 2, REPEAT('X', 99));
        SET i = i + 1;
    END WHILE;
    
    COMMIT;
END$$

DELIMITER ;
4. call InsertIntoFoo(10000, 1);
5. insert into bar values(1,1,'jjj');
6. set global temptable_use_mmap=OFF;
7. set global temptable_max_ram=2097152;
8. set global debug='d, os_file_truncate_error';
9. (select * from foo) union (select * from bar);
10. exit;

Now check your master-error.log, it is printing tons of log.

Suggested fix:
If truncate failed, then don't put this unexpected ibt file into `m_active` pool. The unexpected ibt file will be recovered when server restart.
[12 Nov 2024 9:56] Zihao Wang
This is my fix patch.

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: bug#116626.patch (application/octet-stream, text), 1.34 KiB.

[12 Nov 2024 10:01] MySQL Verification Team
Hello Zihao Wang,

Thank you for the report and contribution.

regards,
Umesh