Danger of Changing Default of log_error_verbosity on MySQL/Percona Server for MySQL 5.7

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:

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:

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:

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:

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:

# 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:

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.

by Carlos Tutte via Percona Database Performance Blog