MySQL Blog Archive
For the latest blogs go to blogs.oracle.com/mysql
Enhancing systemd notifications in MySQL

1. Preface

This blog begins by introducing the current state of systemd notifications in MySQL. It then delves into how systemd notifications can be used and how they differ from other MySQL monitoring utilities like Error log, General log, etc. This blog then discusses new granular notifications added in server initialization, startup and shutdown flows, followed by a brief discussion about logging systemd notifications to Error Log.

2. Introduction

MySQL utilizes the systemd notify service on Linux to emit status updates, termed "systemd notifications" or simply "notifications," which can be externally retrieved from the OS shell using the systemctl utility. Prior to MySQL 8.2, systemd notifications were only available during server startup, upgrade, and shutdown workflows, and were absent during server initialization (i.e., when a server is started with the --initialize option). These workflows can occasionally take a long time due to delays in intermediate stages; for instance, InnoDB crash recovery can significantly prolong server startup. Due to the absence of granular progress notifications, users only receive the generic "Server startup in progress" notification, which can give the impression that the server is unresponsive.

Automated database management tools can initiate MySQL Server initialization, startup, or shutdown processes, and typically have defined timeouts for each workflow, which may be insufficient in certain cases. Access to granular progress notifications would be beneficial for these tools, enabling them to implement conditional logic based on the server's current execution stage.

3. About Systemd

MySQL has monitoring infrastructure like Error log, General Query log, Slow query log, and Systemd notifications to inform users about its activities. They differ in how they're used and the type of information they convey. While Error log, General query log, and Slow query log are designed to "keep a record" of the activities the server is doing, Systemd notifications can be thought of as the "instantaneous status" or "state" of a server, i.e. what exactly the server is doing "now" (Please have a look at "Status" field in below figure). To understand how to configure MySQL to work with systemd and start getting systemd notifications, please follow Managing MySQL Server with systemd. Below is how we can query systemd notifications: 

$ systemctl status mysqld
mysqld.service - MySQL Server
   Loaded: loaded (/etc/systemd/system/mysqld.service; enabled; vendor preset: disabled)
   Active: active (running) since Tue 2023-11-07 05:35:39 UTC; 1h 48min ago
   Docs: man:mysqld(8)
             http://dev.mysql.com/doc/refman/en/using-systemd.html
   Main PID: 9624 (mysqld)
   Status: "Server is operational"
   CGroup: /system.slice/mysqld.service
           └─9624 /usr/sbin/mysqld --port=3306 --mysqlx-port=33060 --admin-port=7306..

4. What's New?

4.1. Newly added systemd notifications

As part of this release, we identified important steps in the server initialization, startup and shutdown flows and added systemd notifications to present users with more granular progress information. Below are some scenarios in which newly added notifications might help users understand the server's status better:  

4.1.1. During server Initialization

Before MySQL 8.2, there were no systemd notifications for server initialization flow. Below is the list of newly added notifications in the relative order they're supposed to appear: 

  1. "Server Initialization in progress" - represents the start of server initialization. 
  2. "InnoDB Initialization in progress" and "InnoDB Initialization [unsuccessful/successful]" - represent the start and end, respectively, of the InnoDB (default storage engine of MySQL) initialization step. 
  3. "Initialization of MySQL system tables in progress" and "Initialization of MySQL system tables [unsuccessful/successful]" - represent the start and end, respectively, of the step where MySQL Server creates and populates MySQL system tables. 
  4. "Execution of SQL Commands from Init-file in progress" and "Execution of SQL Commands from Init-file [unsucccessful/successful]" - represent the start and end, respectively, of the step where MySQL Server runs SQL commands from init-file. Transmitted only when the server is started with the --init-file option.  
  5. "Server Initialization complete (with return value = [1/0])" - represents the end of server initialization. 

4.1.2. During server Startup 

Before MySQL 8.2, there were only a limited number of systemd notifications during server startup, like "Server startup in progress", "Server upgrade in progress" (visible only when upgrade takes place), "Server upgrade complete", and "Server is operational". Below is the list of newly added notifications in the order they are supposed to appear: 

  1. "InnoDB Initialization in progress" and "InnoDB Initialization [unsuccessful/successful]" - represent the start and end, respectively, of the InnoDB initialization step. 
  2. "InnoDB crash recovery in progress" and "InnoDB crash recovery [unsuccessful/successful]" - represent the InnoDB crash recovery step. This step can potentially take a long time, depending on the size of the data to be recovered. 
  3. "Initialization of dynamic plugins in progress" and "Initialization of dynamic plugins [unsuccessful/successful]" - represent the start and end, respectively, of the step where MySQL Server initializes dynamic (i.e. externally loaded) plugins. The time taken during this step depends on the number of external plugins being loaded and the time each plugin takes to get initialized. 
  4. "Components initialization in progress" and "Components initialization [unsuccessful/successful]" - represent the start and end, respectively, of the step where MySQL Server initializes the components

4.1.3. During server shutdown

Before MySQL 8.2, the only notifications conveyed to the systemd during server shutdown were: "Server shutdown in progress" at the very beginning of shutdown and "Server shutdown complete" when server shutdown is complete. Below is the list of the newly added notifications in the order they are supposed to appear: 

  1. "Graceful shutdown of connections in progress", "Shutdown of replica threads in progress", and "Forceful shutdown of connections in progress" - represent the graceful shutdown of connection threads, shutdown of replica threads and forceful shutdown of connection threads, respectively. This step can take a long time, depending on the number of connections and replica threads. We also added "Connection shutdown complete", representing the end of connection shutdown step. 
  2. "Shutdown of plugins in progress" and "Shutdown of plugins complete" - represent the start and end, respectively, of the step where MySQL Server shuts down plugins.  
  3. "Shutdown of components in progress" and "Shutdown of components complete" - represent the start and end, respectively, of the step where MySQL Server shuts down the components. 

4.2. Relative order of the systemd notifications 

To comprehend the relative order in which newly added as well as already present notifications are delivered, please consult the attached diagram.

4.3. Logging systemd notifications to Error Log

Starting from MySQL 8.2, every systemd notification will be logged to an Error log. It can then be found in a specified log file, or it can be queried from performance schema's error_log table like below: 

mysql> SELECT DATA FROM performance_schema.error_log WHERE ERROR_CODE="MY-013930" LIMIT 10\G
*************************** 1. row ***************************
DATA: systemd notify: STATUS=Server startup in progress
*************************** 2. row ***************************
DATA: systemd notify: STATUS=InnoDB initialization in progress
*************************** 3. row ***************************
DATA: systemd notify: STATUS=InnoDB initialization successful
*************************** 4. row ***************************
DATA: systemd notify: STATUS=InnoDB crash recovery in progress
*************************** 5. row ***************************
DATA: systemd notify: STATUS=InnoDB crash recovery successful
*************************** 6. row ***************************
DATA: systemd notify: STATUS=Initialization of dynamic plugins in progress
*************************** 7. row ***************************
DATA: systemd notify: STATUS=Initialization of dynamic plugins successful
*************************** 8. row ***************************
DATA: systemd notify: STATUS=Components initialization in progress
*************************** 9. row ***************************
DATA: systemd notify: STATUS=Components initialization successful
*************************** 10. row ***************************
DATA: systemd notify: READY=1 STATUS=Server is operational MAIN_PID=6891
10 rows in set (0.00 sec)

5. Conclusion

Prior to MySQL 8.2, troubleshooting a slow-running MySQL server required DBAs to manually sift through server logs to identify the specific stage at which the server was encountering performance bottlenecks. This process was not only time-consuming but also error-prone, as it relied heavily on the DBA's ability to interpret and analyze vast amounts of log data. With this feature, DBAs can now leverage the systemd status to gather detailed insights into the server's operational state. This enhancement streamlines the troubleshooting process by providing readily available information about the server's current execution context, enabling DBAs to pinpoint the source of performance bottlenecks with greater efficiency and accuracy.

Do let us know about what do you think about this feature! 

Thanks for using MySQL!