MySQL Bugs: #108586: Contribution By Tencent: WL#12527 cause slow startup in Linux

Bug #108586	Contribution By Tencent: WL#12527 cause slow startup in Linux < 3.15
Submitted:	23 Sep 2022 7:51	Modified:	26 Sep 2022 10:32
Reporter:	Lucas Lu (OCA)	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S3 (Non-critical)
Version:	8.0.30	OS:	Linux (below 3.15)
Assigned to:		CPU Architecture:	Any
Tags:	REDO Log

Description:
InnoDB redo log dynamic configuration will re-populate every redo log files during server startup.
In Linux kernel < 3.15 (which has no support of HAVE_FALLOC_FL_ZERO_RANGE), such initialization falls back to physically write the file with zeros.
Writing these files costs lots of time with a relatively big innodb_redo_log_capacity setting (for example, 8GB), and can potientially wear down SSDs pretty quickly.

How to repeat:
In a linux box with kernel < 3.15 (CentOS 7 is a good example), set a big innodb_redo_log_capacity and start the server.
Long startup time (minutes) could be observed.

Suggested fix:
Add an option to preserve #ib_redoX_tmp files to avoid re-creating them on server startup.

Update title with Tencent OCA

Hello  Lucas Lu,

Thank you for the report and feedback.

regards,
Umesh

How about using ftruncate() in legacy kernel to handle unused files?
By analyzing the code, the only call path of os_file_set_size_fast() is setting the whole file to zero.

According to https://linux.die.net/man/2/ftruncate
"If the file previously was larger than this size, the extra data is lost. If the file previously was shorter, it is extended, and the extended part reads as null bytes ('\0')."

So we can firstly make the file shorter(by calling ftruncate(file, 0)) to discard existing data.

Then ,we call ftruncate(file, size) to extend the file and let ftruncate() automatically set those parts to null bytes.
In my environment with a CentOS 7 system and ext4 file system, such implementation seems a lot faster than physically writing the file.

Can confirm that on CentOS 7 I'm seeing extremely long startup times.
For instance: innodb_redo_log_capacity=37580963840 results in approximately 35 minute startup time on a 64-core/64G RAM system in the cloud.

```
2023-03-19T15:40:04.398950Z 1 [Note] [MY-012533] [InnoDB] 80%
2023-03-19T15:40:05.121970Z 1 [Note] [MY-012533] [InnoDB] 90%
2023-03-19T15:40:06.852901Z 1 [Note] [MY-012533] [InnoDB] 100%
2023-03-19T15:40:07.833894Z 1 [Note] [MY-012535] [InnoDB] Apply batch completed!

2023-03-19T16:25:03.709178Z 1 [Note] [MY-013252] [InnoDB] Using undo tablespace './undo_001'.
2023-03-19T16:25:03.710061Z 1 [Note] [MY-013252] [InnoDB] Using undo tablespace './undo_002'.
2023-03-19T16:25:03.712163Z 1 [Note] [MY-012910] [InnoDB] Opened 2 existing undo tablespaces.
2023-03-19T16:25:03.712272Z 1 [Note] [MY-011980] [InnoDB] GTID recovery trx_no: 183969500
2023-03-19T16:25:03.716694Z 1 [Note] [MY-013776] [InnoDB] Parallel initialization of rseg complete
2023-03-19T16:25:03.716777Z 1 [Note] [MY-013777] [InnoDB] Time taken to initialize rseg using 4 thread: 4504 ms.
2023-03-19T16:25:03.717183Z 1 [Note] [MY-013029] [InnoDB] Transaction 183969494 was in the XA prepared state.
2023-03-19T16:25:03.717244Z 1 [Note] [MY-013029] [InnoDB] Transaction 183969496 was in the XA prepared state.
2023-03-19T16:25:03.717282Z 1 [Note] [MY-013029] [InnoDB] Transaction 183969498 was in the XA prepared state.
2023-03-19T16:25:03.717307Z 1 [Note] [MY-013029] [InnoDB] Transaction 183969500 was in the XA prepared state.
2023-03-19T16:25:03.717334Z 1 [Note] [MY-013029] [InnoDB] Transaction 183969495 was in the XA prepared state.
2023-03-19T16:25:03.717358Z 1 [Note] [MY-013029] [InnoDB] Transaction 183969497 was in the XA prepared state.
2023-03-19T16:25:03.717377Z 1 [Note] [MY-013029] [InnoDB] Transaction 183969499 was in the XA prepared state.
2023-03-19T16:25:03.717428Z 1 [Note] [MY-013023] [InnoDB] 8 transaction(s) which must be rolled back or cleaned up in total 3998 row operations to undo
2023-03-19T16:25:03.717449Z 1 [Note] [MY-013024] [InnoDB] Trx id counter is 183969793
2023-03-19T16:25:03.717555Z 1 [Note] [MY-012255] [InnoDB] Removed temporary tablespace data file: "ibtmp1"
2023-03-19T16:25:03.717589Z 1 [Note] [MY-012923] [InnoDB] Creating shared tablespace for temporary tables
```