Changing the default value (3) of log_error_verbosity in MySQL/Percona Server for MySQL 5.7 can have a hidden unintended effect! What does log_error_verbosity do exactly? As per the documentation:
“The log_error_verbosity system variable specifies the verbosity for handling events intended for the error log.“
Basically a value of 1 logs only [Errors]; 2 is 1)+[Warnings]; and 3 is 2)+[Notes].
For example, one might be tempted to change the default of log_error_verbosity since the error.log might be bloated with thousands (or millions) of lines with [Notes], such as:
1 2 | 2020-10-08T17:02:56.736179Z 3 [Note] Access denied for user 'root'@'localhost' (using password: NO) 2020-10-08T17:04:48.149038Z 4 [Note] Aborted connection 4 to db: 'unconnected' user: 'root' host: 'localhost' (Got timeout reading communication packets) |
(P.S. you can read more about those Notes on this other Percona blog posts):
Fixing MySQL 1045 Error: Access Denied
MySQL “Got an error reading communication packet”
The problem is, after lowering log_error_verbosity to 1 or 2, no messages about server startup or shutdown would be printed to the log! That can really make troubleshooting really hard in the event of issues or system failure. For completeness, on error.log from 5.7 at startup with default log_error_verbosity, the following should be seen:
1 2 3 4 5 6 7 | 2020-10-08T16:36:07.302168Z 0 [Note] InnoDB: PUNCH HOLE support available 2020-10-08T16:36:07.302188Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins ... 2020-10-08T16:36:07.303998Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M 2020-10-08T16:36:07.307823Z 0 [Note] InnoDB: Completed initialization of buffer pool ... 2020-10-08T16:36:07.497571Z 0 [Note] /usr/sbin/mysqld: ready for connections. |
And on shutdown:
1 2 3 4 5 | 2020-10-08T16:36:10.447002Z 0 [Note] Giving 0 client threads a chance to die gracefully 2020-10-08T16:36:10.447022Z 0 [Note] Shutting down slave threads 2020-10-08T16:36:10.447027Z 0 [Note] Forcefully disconnecting 0 remaining clients … 2020-10-08T16:36:12.104099Z 0 [Note] /usr/sbin/mysqld: Shutdown complete |
With log_error_verbosity =2, there won’t be messages about MySQL startup, but some warnings that are only printed at startup might give a hint of the time of server restart such as:
1 2 3 | 2020-10-08T16:30:21.966844Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2020-10-08T16:30:22.181367Z 0 [Warning] CA certificate ca.pem is self signed. 2020-10-08T16:30:22.221732Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 6000) |
If there is no information about server restart, system logs can be checked for information about restarts:
1 2 3 4 | # cat /var/log/messages ... Oct 8 16:31:25 carlos-tutte-latest57-standalone-1 systemd: Starting MySQL Server... Oct 8 16:31:26 carlos-tutte-latest57-standalone-1 systemd: Started MySQL Server. |
If still no clue when was MySQL last started, checking the “Uptime” status variable can help in calculating the last startup.
The problem does NOT occur on MySQL/Percona Server for MySQL 8.0 since even with log_error_verbosity = 1, the following startup/shutdown lines are printed on the error.log:
1 2 3 4 5 6 | 2020-10-08T16:31:54.532504Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.20-11) starting as process 1052 2020-10-08T16:31:54.540342Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started. 2020-10-08T16:31:55.026815Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended. 2020-10-08T16:31:55.136125Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Socket: '/var/lib/mysql/mysqlx.sock' bind-address: '::' port: 33060 2020-10-08T16:31:55.270669Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.20-11' socket: '/var/lib/mysql/mysql.sock' port: 3306 Percona Server (GPL), Release 11, Revision 5b5a5d2. 2020-10-08T16:32:01.708932Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.20-11) Percona Server (GPL), Release 11, Revision 5b5a5d2. |
In conclusion, if possible, avoid changing the default of log_error_verbosity on MySQL/Percona Server for MySQL 5.7. And if you need to change it, do it online with SET GLOBAL instead of through the config file, since, in the event of a restart, startup messages won’t be logged.
Our solution brief “Get Up and Running with Percona Server for MySQL” outlines setting up a MySQL® database on-premises using Percona Server for MySQL. It includes failover and basic business continuity components.
