|
First of all this is not a bug report, but just a report, useful to share to everyone.
There are 4 small installations, which were recently upgraded to zabbix v5.0 and as a requirement, MariaDB instances were also upgraded from 5.5 to 10.5.8 or 10.3.27
Some details:
All zabbix processes are almost flat near 0% busy level. I assume that a little busy level of processes, where many of them are sleeping most of the time, increases probability that some particular processes did not need to contact DB server for time, longer than mysql's wait_timeout.
We started to spot errors in mysql's error.log file time to time:
Aborted connection 48 to db: 'zabbix' user: 'zabbix' host: 'localhost' (Got timeout reading communication packets)
(note - here host: should be IP of remote side host. In my case 'localhost' is because of local connection)
In the same time we don't see any errors in zabbix_server.log.
Long troubleshooting showed something what makes sense to share here.
There was a change in mysql's core for logging level, defined by "log_warnings" parameter (log_error_verbosity in MySQL 8.0, with nuances).
Default was 1 before MySQL 5.7.2, 2 as of 5.7.2, which became 2 by default which caused the errors logging.
https://dev.mysql.com/doc/refman/5.7/en/server-system-variables.html#sysvar_log_warnings
The same thing happened for MariaDB, for versions 10.2
https://mariadb.com/kb/en/upgrading-from-mariadb-101-to-mariadb-102/
As for MySQL v8.0, it dropped support of "log_warnings", and replaced it by "log_error_verbosity" setting default to 2:
https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_log_error_verbosity
while in version 5.7.2 it was already supported with another default value - 3 which with following logic:
In MySQL 5.7.2 and higher, use of log_warnings is still permitted but maps onto use of log_error_verbosity as follows:
Setting log_warnings=0 is equivalent to log_error_verbosity=1 (errors only).
Setting log_warnings=1 is equivalent to log_error_verbosity=2 (errors, warnings).
Setting log_warnings=2 (or higher) is equivalent to log_error_verbosity=3 (errors, warnings, notes)
So, that's a mess with conditions, when the errors may appear in mysql error log.
But it's strange thing why zabbix does not log any errors in own log, right?
And here an interesting difference observed between MariaDB v10.3.25 and MySQL v8.0:
To play with the parameters you can use these commands:
set global log_warnings=2;
set global wait_timeout=30;
show global variables like 'log_warnings';
show global variables like 'wait_timeout';
(for mysql v8.0 log_error_verbosity instead*=3* of log_warnings=2 and other values)
MariaDB:
After wait_timeout it sends single RST packet (use tcpdump to see it) and logs this in errors log:
2021-01-21 18:40:39 16 [Warning] Aborted connection 16 to db: '5.2' user: 'root' host: 'localhost' (Got timeout reading communication packets)
zabbix log is silent and zabbix daemon, when needed, recreates a new connection and then sends query:
while MySQL sends FIN packet and with increased log_error_verbosity=3 logs these messages:
2021-01-21T14:14:30.966485Z 140 [Note] [MY-013417] [Server] The wait_timeout period was exceeded, the idle time since last command was too long.
2021-01-21T14:14:30.966521Z 140 [Note] [MY-010914] [Server] Aborted connection 140 to db: '5.2' user: 'root' host: 'localhost' (Got timeout reading communication packets).
and in this case zabbix tries to send query to the same TCP connection, which was closed already, it receives RST and only then recreates a new connection and resend the query:
and in this case zabbix logs an error as well:
3746025:20210121:192540.063 [Z3005] query failed: [2013] Lost connection to MySQL server during query [select clock,ns,value from history where itemid=32634 and clock>1611249940]
Zabbix_server is compiled with MariaDB client library and used it during operations, so it may cause difference how client is threading such network communication.
But as zabbix packages are compiled with MariaDB and zabbix users may used different DB servers, that's an interesting result to describe here.
TCP dumps (manually filtered for 2 session of one zabbix process) attached as well, just in case.
I did test for MySQL v8.0 only, I do not exclude that MySQL v5.x may have different behavior.
|
mariadb-wait_timeout-reached.png
zabbix-mariadb-zab_is_silent-ses35_38-pid_3744104.pcapng
Team C
