MySQL Bugs: #98864: Improve error logging message

Bug #98864	Improve error logging message
Submitted:	6 Mar 2020 17:47	Modified:	9 Mar 2020 8:37
Reporter:	Simon Mudd (OCA)	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: Logging	Severity:	S4 (Feature request)
Version:	5.7.28	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
Seen in the error log on mysql-community-server-5.7.28 but I think this is probably appropriate in 8.0 for exactly the same reason.

2020-03-06T17:04:38.946624Z 0 [ERROR] /usr/sbin/mysqld: Got an error reading communication packets
2020-03-06T17:04:38.977374Z 0 [ERROR] /usr/sbin/mysqld: Got an error reading communication packets
2020-03-06T17:04:38.982371Z 0 [ERROR] /usr/sbin/mysqld: Got an error reading communication packets
2020-03-06T17:04:38.983008Z 0 [ERROR] /usr/sbin/mysqld: Got an error reading communication packets
2020-03-06T17:04:38.993319Z 0 [ERROR] /usr/sbin/mysqld: Got an error reading communication packets
2020-03-06T17:04:39.005943Z 0 [ERROR] /usr/sbin/mysqld: Got an error reading communication packets
2020-03-06T17:04:48.771384Z 84458065 [Note] Got an error reading communication packets
2020-03-06T17:04:48.771448Z 84458066 [Note] Got an error reading communication packets
2020-03-06T17:04:48.771495Z 84458069 [Note] Got an error reading communication packets
2020-03-06T17:04:48.771572Z 84458070 [Note] Got an error reading communication packets

This is not very helpful error messaging as I can't see:
* which remote ip or socket triggered this message
* what the actual socket error was

So I can not see if this is a problem for more than one host, the same host (with different connections) etc etc.
and therefore have to look at other logs to try to determine exactly what is happening.

How to repeat:
make multiple connections to a mysql server "doing things".
Block the connections using iptables or similar

Look at the logging and you'll probably see something similar.

Suggested fix:

* Record the error message from the socket reported by the OS.
* Report the remote ip address or socket if known.

This would enormously help with debugging.

current 8.0 says

2020-03-06T18:45:17.499892Z 13 [Note] [MY-013417] [Server] The wait_timeout period was exceeded, the idle time since last command was too long.
2020-03-06T18:45:17.500000Z 13 [Note] [MY-010914] [Server] Aborted connection 13 to db: 'unconnected' user: 'root' host: 'localhost' (Got timeout reading communication packets).

and:
2020-03-06T18:46:58.363820Z 16 [Note] [MY-010914] [Server] Aborted connection 16 to db: 'unconnected' user: 'root' host: 'localhost' (Got an error writing communication packets).

Hello Simon,

Thank you for the reasonable feature request!

regards,
Umesh

See:
https://bugs.mysql.com/bug.php?id=93240
Enh 28940167 - WAIT_TIMEOUT ERROR NOT CLEAR AND NOT SENT TO CLIENT BEFORE CLOSING CONNECTION

Hi. I'm aware of bug#93240 and that does seem to address the server side of the problem. I wasn't aware that the host is included in the 8.0 aborted connection messages so that seems clearer though from your message starting "current 8.0 says" I see no way to relate the 2 messages:

2020-03-06T18:45:17.499892Z 13 [Note] [MY-013417] [Server] The wait_timeout period was exceeded, the idle time since last command was too long.
2020-03-06T18:45:17.500000Z 13 [Note] [MY-010914] [Server] Aborted connection 13 to db: 'unconnected' user: 'root' host: 'localhost' (Got timeout reading communication packets)

to the same connection. Adding the connection_id might be helpful here or adding the user/host to the "The wait_timeout period ..." message. If you have a message where several connections are affected this extra information would be useful.

However, I guess my main request does not really make sense if the user/host is shown now in 8.0 logging. It just seem to be missing from that message.

Running mysql80-server-8.0.32_3, the error message still does not indicate which client cause that issue:

2023-07-10T21:59:13.647785Z 2384 [Note] [MY-010914] [Server] Got an error reading communication packets
2023-07-10T21:59:33.106781Z 2385 [Note] [MY-010914] [Server] Got an error reading communication packets
2023-07-10T21:59:53.790776Z 2386 [Note] [MY-010914] [Server] Got an error reading communication packets