MySQL Bugs: #90809: connection error counter not getting reset after successful connection

Bug #90809	connection error counter not getting reset after successful connection
Submitted:	9 May 2018 17:53	Modified:	10 Jan 2019 23:33
Reporter:	Alfredo Kojima	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Router	Severity:	S3 (Non-critical)
Version:	8.0.11	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
The connection error counter that blocks clients after a certain number of connection errors is supposed to reset after a successful connection, as the server does, but the router doesn't.

See https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_max_connect_er...

How to repeat:
Trying with router:

kojima@Kenjis-iMac delme$ for i in `seq 1 99`; do echo 1 |nc localhost 6446 > /dev/null; done
kojima@Kenjis-iMac delme$ mysql -uroot -h0 -p -e "select 1"
Enter password: 
+---+
| 1 |
+---+
| 1 |
+---+
kojima@Kenjis-iMac delme$ nc localhost 6446
U
8.0.11-commercial
                 %{	8c????? * oIcaching_sha2_password^C
kojima@Kenjis-iMac delme$ nc localhost 6446
,?iToo many connection errors from 127.0.0.1

Trying with server:

kojima@Kenjis-iMac delme$ for i in `seq 1 99`; do echo 1 |nc localhost 3000 > /dev/null; done
kojima@Kenjis-iMac delme$ mysql -uroot -h0 -p -e "select 1"
Enter password: 
+---+
| 1 |
+---+
| 1 |
+---+
kojima@Kenjis-iMac delme$ nc localhost 3000
U
8.0.11-commercial}	,x
                          #
1J?????0tJN__"DWG	caching_sha2_password^C
kojima@Kenjis-iMac delme$ nc localhost 3000
U
8.0.11-commercialdnP22{r?????/h?bn%,9])"Ncaching_sha2_password^C
kojima@Kenjis-iMac delme$ nc localhost 3000
U
8.0.11-commercial?QJFx3C?????![/[1
 %caching_sha2_password^C

Suggested fix:
Reset per host connection error counter on a successful connection.

Alternatively:
- considering error counter in the router exists so that the router itself won't get blocked by the server
- considering the router error counter doesn't really work, since multiple source hosts causing errors could still block the router at the server
- making the router perform a successful connection using metadata account whenever it's needed, in order to reset the server's error counter, could be a better approach

Posted by developer:
 
If router is placed behind a load-balancer, the load-balancers health-check will
open a TCP connection to the router's port and close the connection again.

The router will treat this an broken client and increment the error-count.

As the error-count is never reset automatically, after 100 health-checks the load-balancer
will be locked out until router is restarted.

Posted by developer:
 
Strictly speaking the bug seems not in a state that requires QA action, however, since you asked I checked the change and can confirm that QA approves the change. I've reviewed the code change including the component tests added and we have done a peer session doing a manual test - all fine. 

Some aside findings:

 * Doc bug [likely, no regression]: max_connect_error value range documentation seems wrong, Bug#28643283
 * Feature request: allow resetting error counters to unblock hosts, Bug#28643474
 
Neither of the two bugs is related to this very bug.

I further recommend that ask the documentation team to copy the comment added by Jan on July 25th regarding the use of load balancers to the manual. It seems to be a very valuable best practice hint resp. explain an important limitation.

Posted by developer:
 
Also added to the docs:

A successful connection resets the error counter.

Thanks Pawel for following up.

I had the same problem in this case with a rapid7 vulnerability scan I have mysql-router-community/unknown,now 8.0.30-1ubuntu20.04 amd64 these are the logs
2022-09-12 18:06:35 routing INFO [7fe78c617700] [routing:bootstrap_rw] iprapid7:55064 closed connection before finishing handshake
2022-09-12 18:06:35 routing INFO [7fe78c617700] [routing:bootstrap_rw] incrementing error counter for host of iprapid7:55064 (now 1)
2022-09-12 18:06:35 routing INFO [7fe78c617700] [routing:bootstrap_ro] iprapid7:50732 closed connection before finishing handshake
2022-09-12 18:06:35 routing INFO [7fe78c617700] [routing:bootstrap_ro] incrementing error counter for host of iprapid7:50732 (now 1)
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_rw] iprapid7:55066 closed connection before finishing handshake
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_rw] incrementing error counter for host of iprapid7:55066 (now 2)
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_ro] iprapid7:50734 closed connection before finishing handshake
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_ro] incrementing error counter for host of iprapid7:50734 (now 2)
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_rw] iprapid7:55070 closed connection before finishing handshake
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_rw] incrementing error counter for host of iprapid7:55070 (now 3)
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_rw] iprapid7:55072 closed connection before finishing handshake
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_rw] incrementing error counter for host of iprapid7:55072 (now 4)
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_ro] iprapid7:50738 closed connection before finishing handshake
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_ro] incrementing error counter for host of iprapid7:50738 (now 3)
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_rw] iprapid7:55074 closed connection before finishing handshake
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_rw] incrementing error counter for host of iprapid7:55074 (now 5)
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_ro] iprapid7:50740 closed connection before finishing handshake
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_ro] incrementing error counter for host of iprapid7:50740 (now 4)
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_rw] iprapid7:55076 closed connection before finishing handshake
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_rw] incrementing error counter for host of iprapid7:55076 (now 6)
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_rw] iprapid7:55078 closed connection before finishing handshake
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_rw] incrementing error counter for host of iprapid7:55078 (now 7)
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_ro] iprapid7:50742 closed connection before finishing handshake
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_ro] incrementing error counter for host of iprapid7:50742 (now 5)
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_ro] iprapid7:50744 closed connection before finishing handshake
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_ro] incrementing error counter for host of iprapid7:50744 (now 6)
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_ro] iprapid7:50746 closed connection before finishing handshake
2022-09-12 18:06:36 routing INFO [7fe78c617700] [routing:bootstrap_ro] incrementing error counter for host of iprapid7:50746 (now 7)
2022-09-12 18:06:41 routing INFO [7fe78c617700] [routing:bootstrap_rw] iprapid7:55080 closed connection before finishing handshake
2022-09-12 18:06:41 routing INFO [7fe78c617700] [routing:bootstrap_rw] incrementing error counter for host of iprapid7:55080 (now 8)
2022-09-12 18:06:41 routing INFO [7fe78c617700] [routing:bootstrap_rw] iprapid7:43174 closed connection before finishing handshake
2022-09-12 18:06:41 routing INFO [7fe78c617700] [routing:bootstrap_rw] incrementing error counter for host of iprapid7:43174 (now 9)
2022-09-12 18:06:41 routing INFO [7fe78c617700] [routing:bootstrap_rw] iprapid7:55068 closed connection before finishing handshake
2022-09-12 18:06:41 routing INFO [7fe78c617700] [routing:bootstrap_rw] incrementing error counter for host of iprapid7:55068 (now 10)
2022-09-12 18:06:41 routing INFO [7fe78c617700] [routing:bootstrap_ro] iprapid7:50748 closed connection before finishing handshake
2022-09-12 18:06:41 routing INFO [7fe78c617700] [routing:bootstrap_ro] incrementing error counter for host of iprapid7:50748 (now 8)
2022-09-12 18:06:41 routing INFO [7fe78c617700] [routing:bootstrap_ro] iprapid7:41454 closed connection before finishing handshake
2022-09-12 18:06:41 routing INFO [7fe78c617700] [routing:bootstrap_ro] incrementing error counter for host of iprapid7:41454 (now 9)
2022-09-12 18:06:41 routing INFO [7fe78c617700] [routing:bootstrap_ro] iprapid7:50736 closed connection before finishing handshake
2022-09-12 18:06:41 routing INFO [7fe78c617700] [routing:bootstrap_ro] incrementing error counter for host of iprapid7:50736 (now 10)
2022-09-12 18:07:35 routing INFO [7fe78c617700] [routing:bootstrap_ro] iprapid7:46140 closed connection before finishing handshake
2022-09-12 18:07:35 routing INFO [7fe78c617700] [routing:bootstrap_ro] incrementing error counter for host of iprapid7:46140 (now 11)
2022-09-12 18:07:35 routing INFO [7fe78c617700] [routing:bootstrap_rw] iprapid7:59638 closed connection before finishing handshake
2022-09-12 18:07:35 routing INFO [7fe78c617700] [routing:bootstrap_rw] incrementing error counter for host of iprapid7:59638 (now 11

this event close all session

Having exact same issue. I have cluster with 3 routers behind load balancer. I can't disable load balancer health check. I always receive "Too many connection errors from [LB_HOST]" message.