MySQL Bugs: #116619: Startup without Signs of Progress with Many Tables (1M+).

Bug #116619	Startup without Signs of Progress with Many Tables (1M+).
Submitted:	11 Nov 20:52	Modified:	12 Nov 5:32
Reporter:	Jean-François Gagné	Email Updates:
Status:	Analyzing	Impact on me:	None
Category:	MySQL Server: Logging	Severity:	S2 (Serious)
Version:	8.0.39, 8.0.40, 8.4.3, 9.1.0	OS:	Any
Assigned to:	MySQL Verification Team	CPU Architecture:	Any

Description:
Hi,

when starting MySQL with many tables and default log verbosity, there are long gaps in the error logs.  See How to repeat for details (gaps of 6 and 1 minutes).

I would expect long startup operations to regularly output a log message to reassure the operator that things are not blocked.  This is what is done with log_error_verbosity of 3, but the default is 2, and I would expect regular signs of progress with the default value.

Filing this as a S2 / Serious, because such usability issues are not minor.  I do not think this is a S5 / Performance issue as this is not about making things faster.  There might be an argument to be made that this is a feature request, but I think such issues should be considered bugs.

I reported this for 8.0.39 because the logs I have in How to repeat are for this version (sorry, opening this bug is pending on my side for some time), but I think 8.0.40, 8.4.3 and 9.1.0 are also affected.

I might eventually submit a patch for this.

Many thanks for looking into this,

Jean-François Gagné

How to repeat:
See Bug#115988 for a script to create many tables.

Start MySQL with default log verbosity and many tables (1M+), the output should look similar to below.  Log message MY-013576 is at 2024-08-26T02:12:58, with the next line 6 minutes later, which is too long a gap.  Also, MY-013577 is at 2024-08-26T02:19:00, with the next line 1 minute later, which is also too long a gap.

2024-08-26T02:12:54.209842Z mysqld_safe Logging to '/home/jgagne/sandboxes/msb_mysql_8_0_39/data/msandbox.err'.
2024-08-26T02:12:54.282572Z mysqld_safe Starting mysqld daemon with databases from /home/jgagne/sandboxes/msb_mysql_8_0_39/data
2024-08-26T02:12:57.668709Z 0 [System] [MY-010116] [Server] /home/jgagne/opt/mysql/mysql_8.0.39/bin/mysqld (mysqld 8.0.39) starting as process 66873
2024-08-26T02:12:58.409124Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2024-08-26T02:19:00.014759Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2024-08-26T02:20:03.386016Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2024-08-26T02:20:03.386062Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2024-08-26T02:20:03.545458Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 18039, socket: /tmp/mysqlx-18039.sock
2024-08-26T02:20:03.545591Z 0 [System] [MY-010931] [Server] /home/jgagne/opt/mysql/mysql_8.0.39/bin/mysqld: ready for connections. Version: '8.0.39'  socket: '/tmp/mysql_sandbox8039.sock'  port: 8039  MySQL Community Server - GPL.